August 24, 2009

Configure Log4J DailyRollingFileAppender with custom PatternLayout

For some time I haven been planning to learn the mystic configuration of the org.apache.log4j.PatternLayout for Log4j and finally I have taken the time to do so.
  • c - The calling class name, if giving without precision is the fully qualified name returned.
  • C - The fully qualified class name.
  • d - The date of the logging request, can be formatted with java.text.SimpleDateFormat, i.e. %d{yyyy-MM-dd}
  • F - The name of the calling File.
  • l - The location information, same as %C%M(%F:%L). This can be slow.
  • L - The calling class line number
  • m - The logging message.
  • M - The calling class method.
  • n - The platform dependent line separator.
  • p - The logging Level.
  • r - The relative date in millisecond since application start.
  • t - The invoking thread.
  • [x|X] - the Message Diagnostic (MDC) information.

Now for some example. To be compliant with large open-source project such as Hibernate Annotation we use SLF4J as Logger interface. To use SLF4J, simply add the following to your Maven pom.xml





And if we run 'mvn dependency:tree', we see that the artifact also contains the log4j.jar implementation.
[INFO] Scanning for projects...

[INFO] Searching repository for plugin with prefix: 'dependency'.

[INFO] ------------------------------------------------------------------------

[INFO] Building Log4J Test

[INFO]    task-segment: [dependency:tree]

[INFO] ------------------------------------------------------------------------

[INFO] [dependency:tree]

[INFO] se.msc.development:log4j-test:jar:1.0-SNAPSHOT

[INFO] +- org.slf4j:slf4j-log4j12:jar:1.4.2:compile

[INFO] |  +- org.slf4j:slf4j-api:jar:1.4.2:compile

[INFO] |  \- log4j:log4j:jar:1.2.13:compile

[INFO] +- javax.mail:mail:jar:1.4.1:compile

[INFO] |  \- javax.activation:activation:jar:1.1.1:compile

[INFO] \- junit:junit:jar:4.5:test

[INFO] ------------------------------------------------------------------------


[INFO] ------------------------------------------------------------------------

[INFO] Total time: 4 seconds

[INFO] Finished at: Mon Aug 24 03:05:27 CEST 2009

[INFO] Final Memory: 12M/144M

[INFO] ------------------------------------------------------------------------

And here follows an example of how to use SLF4J in your code.
package se.msc.log4j;

import org.junit.Test;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Log4JTest {
//import org.slf4j.Logger;
//import org.slf4j.LoggerFactory;
private static final Logger log = LoggerFactory.getLogger(Log4JTest.class);

//import org.apache.log4j.Logger;
//private static final Logger log = Logger.getLogger(Log4JTest.class);

public void testFoo() throws Exception {"Info log message.");
log.error("Fatal log message.", new NullPointerException("Null pointer exceptopn."));


An the log4j configuration file
# configure the root logger
log4j.rootLogger=INFO, STDOUT, DAILY

# configure the console appender
log4j.appender.STDOUT.layout.conversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%p] %c:%L - %m%n

# configure the daily rolling file appender
log4j.appender.DAILY.layout.conversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%p] %c:%L - %m%n

and when running the JUnit test:
2009-08-24 03:00:47.775 [INFO] se.msc.log4j.Log4JTest:18 - Info log message.
2009-08-24 03:00:47.783 [ERROR] se.msc.log4j.Log4JTest:19 - Fatal log message.
java.lang.NullPointerException: Null pointer exceptopn.
at se.msc.log4j.Log4JTest.testFoo(
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(
at sun.reflect.DelegatingMethodAccessorImpl.invoke(
at java.lang.reflect.Method.invoke(
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(
at org.junit.runners.model.FrameworkMethod.invokeExplosively(
at org.junit.internal.runners.statements.InvokeMethod.evaluate(
at org.junit.internal.runners.statements.RunBefores.evaluate(
at org.junit.internal.runners.statements.RunAfters.evaluate(
at org.junit.runners.BlockJUnit4ClassRunner.runChild(
at org.junit.runners.BlockJUnit4ClassRunner.runChild(
at org.junit.runners.ParentRunner.runChildren(
at org.junit.runners.ParentRunner.access$000(
at org.junit.runners.ParentRunner$1.evaluate(
at org.junit.internal.runners.statements.RunBefores.evaluate(
at org.junit.internal.runners.statements.RunAfters.evaluate(
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(

And now I final word about the DatePattern for the org.apache.log4j.DailyRollingFileAppender:

Rolls over at midnight each day, as is the expected behaviour of a rolling log.

1 comment:

Drew Noakes said...

According to the documentation on the class, the date pattern "'.'yyyy-MM-dd-a" rolls over at midday, not midnight. Drop the trailing "-a" for midnight rollovers.