Wednesday, March 4, 2015

Better Logging



http://perf4j.codehaus.org/devguide.html
http://pramod-musings.blogspot.com/2012/06/using-perf4j-to-time-methods.html
http://www.infoq.com/articles/perf4j
http://heshans.blogspot.com/2014/01/aspect-oriented-programming-with-java.html

http://www.nurkiewicz.com/2010/05/clean-code-clean-logs-use-appropriate.html
http://vasir.net/blog/development/how-logging-made-me-a-better-developer
Visibility into code helps manage complexity.
Communication

http://www.javacodegeeks.com/2011/01/10-tips-proper-application-logging.html
SLF4J is the best logging API available, mostly because of a great pattern substitution support
log.debug("Found {} records matching filter: '{}'", records, filter);
SLF4J is just a façade. As an implementation I would recommend the Logback framework.
Perf4J

3) Do you know what you are logging?
read your logs often to spot incorrectly formatted messages.
avoid NPE
logging collections
log.debug("Returning users: {}", users);
It is a much better idea to log, for example, only ids of domain objects (or even only size of the collection).
in Java we can emulate it using the Commons Beanutils library:
    return CollectionUtils.collect(collection, new BeanToPropertyValueTransformer(propertyName));
the 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.

Avoid side effects

5) Be concise and descriptive
log.debug("Message with id '{}' processed", message.getJMSMessageID());
Don't log passwords and any personal information

6) Tune your pattern
logging date when your logs roll every hour is pointless as the date is already included in the log file name. On the contrary, without logging the thread name you would be unable to track any process using logs when two threads work concurrently – the logs will overlap.
current time (without date, milliseconds precision), logging level, name of the thread, simple logger name (not fully qualified) and the message.
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} %-5level [%thread][%logger{0}] %m%n</pattern>
    </encoder>
</appender>
You should never include file name, class name and line number, although it’s very tempting.
Besides, logging class name, method name and/or line number has a serious performance impact.

7) Log method arguments and return values
You can even use a simple AOP aspect to log a wide range of methods in your code. This reduces code duplication, but be careful, since it may lead to enormous amount of huge logs.

8) Watch out for external systems

9) Log exceptions properly
Avoid logging exceptions, let your framework or container (whatever it is) do it for you.
Log, or wrap and throw back (which is preferable), never both, otherwise your logs will be confusing.
log.error("Error reading configuration file", e);        //L

10) Logs easy to read, easy to parse
avoid formatting of numbers, use patterns that can be easily recognized by regular expressions, etc. If it is not possible, print the data in two formats:
log.debug("Request TTL set to: {} ({})", new Date(ttl), ttl);
final String duration = DurationFormatUtils.formatDurationWords(durationMillis, true, true);
log.info("Importing took: {}ms ({})", durationMillis, duration);

Log4j MDC(Mapped Diagnostic Context)
http://veerasundar.com/blog/2009/10/log4j-mdc-mapped-diagnostic-context-what-and-why/
http://veerasundar.com/blog/2009/11/log4j-mdc-mapped-diagnostic-context-example-code/
http://logging.apache.org/log4j/2.x/manual/thread-context.html
ThreadContext.push(UUID.randomUUID().toString()); // Add the fishtag;
ThreadContext.pop();
ThreadContext.put("id", UUID.randomUUID().toString(); // Add the fishtag;
ThreadContext.clear();
A Filter to put the user name in MDC for every request call
import org.apache.log4j.MDC;
MDC.put("userName", "veera");
MDC.remove("userName");
log4j.appender.consoleAppender.layout.ConversionPattern = %-4r [%t] %5p %c %x - %m - %X{userName}%n
https://lizdouglass.wordpress.com/tag/log4j-ndc/
NDC is an object that Log4j manages per thread as a stack of contextual information.

No comments:

Post a Comment