I'm trying to save some logs from Apache James to specific appender.
Apache James by default uses Apache Commons Logging with added Logback. Logback.xml configuration looks like:
<contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
<resetJUL>true</resetJUL>
</contextListener>
<!-- Appenders for console and logs -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} %highlight([%-5level]) %thread %logger{15}:%line - %msg%n%rEx</pattern>
<immediateFlush>false</immediateFlush>
</encoder>
</appender>
<appender name="JAMES" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>./logs/james.log</file>
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%-5level] %thread %logger{15}:%line - %msg%n%rEx</pattern>
<immediateFlush>false</immediateFlush>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>./logs/james.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
<appender name="JAMES-SERVER" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>./logs/james-server.log</file>
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%-5level] %thread %logger{15}:%line - %msg%n%rEx</pattern>
<immediateFlush>false</immediateFlush>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>./logs/james-server.log.%d{yyyy-MM-dd}</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
<logger name="org.domain.mypackage" level="DEBUG">
<appender-ref ref="JAMES-SERVER" />
</logger>
<root level="INFO">
<appender-ref ref="CONSOLE" />
<appender-ref ref="JAMES"/>
</root>
Apache James starting as
java -classpath "james-server-jpa-guice.jar:james-server-jpa-guice.lib/*:james-server-jpa-guice.lib" -javaagent:james-server-jpa-guice.lib/openjpa-3.0.0.jar -Dlogback.configurationFile=./conf/logback.xml -Dworking.directory=. org.apache.james.JPAJamesServerMain >> ./logs/james.log
All logs fine to james.log but specific package above org.domain.mypackage is not logged to james-server.log but appears to be in james.log
Any thoughts on that?
Your setup might need 2 fixes, remove immediateFlush tags at least for testing and add JAMES-APPENDERto root logger. immediateFlush=false should be set when heavy logging activity is expected, for testing purposes, set it to true.
<root level="DEBUG">
<appender-ref ref="CONSOLE" />
<appender-ref ref="JAMES" />
<appender-ref ref="JAMES-SERVER" />
</root>
Logback setup can be conveniently tested using logback-examples package as follows:
export LOGBACK_CP="/home/luis.munoz/.m2/repository/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar:/home/luis.munoz/.m2/repository/ch/qos/logback/logback-core/1.1.3/logback-core-1.1.3.jar:logback-examples-1.1.3.jar:/home/luis.munoz/.m2/repository/ch/qos/logback/logback-classic/1.1.3/logback-classic-1.1.3.jar"
java -cp "$LOGBACK_CP" chapters.appenders.ConfigurationTester ~/tmp/logback.xml
The following messages will be written to console and any configured files
12:37:45.336 [DEBUG] main c.a.ConfigurationTester:50 - **Hello test 123
12:37:45.338 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 0
12:37:45.439 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 1
12:37:45.540 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 2
12:37:45.640 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 3
12:37:45.742 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 4
12:37:45.843 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 5
12:37:45.943 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 6
12:37:46.044 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 7
12:37:46.145 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 8
12:37:46.246 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 9
12:37:46.355 [ERROR] main c.a.s.s.Bar:32 - error-level request
java.lang.Exception: test exception
at chapters.appenders.sub.sample.Bar.subMethodToCreateRequest(Bar.java:32) [logback-examples-1.1.3.jar:na]
at chapters.appenders.sub.sample.Bar.createLoggingRequest(Bar.java:27) [logback-examples-1.1.3.jar:na]
at chapters.appenders.ConfigurationTester.main(ConfigurationTester.java:58) [logback-examples-1.1.3.jar:na]
On console, several log records useful for debugging a configuration are written
...
12:37:45,333 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT]
12:37:45,333 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [JAMES] to Logger[ROOT]
12:37:45,333 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [JAMES-SERVER] to Logger[ROOT]
...
Also, this example package allows to "play" with the configuration and check the result. For example:
<logger name="chapters.appenders.ConfigurationTester" level="DEBUG" additivity="false">
<appender-ref ref="JAMES" />
</logger>
<logger name="chapters.appenders.sub.sample" level="DEBUG" additivity="false">
<appender-ref ref="JAMES-SERVER" />
</logger>
<root level="DEBUG">
<appender-ref ref="CONSOLE" />
</root>
Will log this to james.log
16:04:44.487 [DEBUG] main c.a.ConfigurationTester:50 - **Hello test 123
16:04:44.490 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 0
16:04:44.590 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 1
16:04:44.691 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 2
16:04:44.792 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 3
16:04:44.892 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 4
16:04:44.993 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 5
16:04:45.093 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 6
16:04:45.194 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 7
16:04:45.295 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 8
16:04:45.395 [DEBUG] main c.a.ConfigurationTester:54 - logging statement 9
And this to james-server.log
16:04:45.502 [ERROR] main c.a.s.s.Bar:32 - error-level request
java.lang.Exception: test exception
at chapters.appenders.sub.sample.Bar.subMethodToCreateRequest(Bar.java:32) [logback-examples-1.1.3.jar:na]
at chapters.appenders.sub.sample.Bar.createLoggingRequest(Bar.java:27) [logback-examples-1.1.3.jar:na]
at chapters.appenders.ConfigurationTester.main(ConfigurationTester.java:58) [logback-examples-1.1.3.jar:na]