Around IT in 256 seconds

Clean code, clean logs: do you know what you are logging? (3/10)

May 05, 2010 | 2 Minute Read

Every time you issue a logging statement, take a moment and have a look what exactly will land in your log file. Read your logs afterwards and spot malformed sentences. First of all, avoid NPEs like this:

log.debug("Processing request with id: {}", request.getId());


Are you absolutely sure that request is not null here? Another pitfall is logging collections. If you fetched collection of domain objects from the database using Hibernate and carelessly log them like here:

log.debug("Returning users: {}", users);


SLF4J will call toString() only when the statement is actually printed, which is quite nice. But if it does... Out of memory error, N+1 select problem, thread starvation (logging is synchronous!), lazy initialization exception, logs storage filled completely – each of these might occur.

It is a much better idea to log, for example, only ids of domain objects (or even only size of the collection). But making a collection of ids when having a collection of objects having getId() method is unbelievably difficult and cumbersome in Java. Groovy has a great spread operator (users*.id), in Java we can emulate it using Commons Beanutils library:

log.debug("Returning user ids: {}", collect(users, "id"));


Where collect() method can be implemented as follows:

public static Collection collect(Collection collection, String propertyName) {
return CollectionUtils.collect(collection, new BeanToPropertyValueTransformer(propertyName));
}


Unfortunately the method above is not yet part of Commons Beanutils framework, but I have already filed up the request to make our lives easier (BEANUTILS-375).

The last thing is improper implementation or usage of toString(). First, create toString() for each class that appears anywhere in logging statements, preferably using ToStringBuilder (but not its reflective counterpart). Secondly, watch out for arrays and non-typical collections. Arrays and some strange collections might not have toString() implemented calling toString() of each item. Use Arrays #deepToString JDK utility method. And read your logs often to spot incorrectly formatted messages.


Tags: commons, logging, slf4j

Be the first to listen to new episodes!

To get exclusive content: