[logback-user] Logback and tomcat

Fri Apr 23 09:41:03 CEST 2010

Hello Daniel,

The following two error messages gathered from the logback output you
provided indicate that you are using an older version of logback, at
least older than 0.9.19 where encoders were introduced.

ERROR in c.q.lb.co.joran.spi.Interpreter - no applicable action for 
[encoder]...
ERROR in c.q.lb.co.rolling.RollingFileAppender[FILE] - No layout set for 
the appender named "FILE".

HTH,

On 23/04/2010 2:45 AM, Daniel Proud wrote:
> Hi guys,
>
> I am attempting to get logback working with my tomcat webapp and have
> run into a few issues.
>
> I have got various log messages in my client code and they seem to work
> when run seperate from the web app (eg junit testing in eclipse uses the
> default configuration and the log messages appear in the console.)
>
> When I run this code embedded in a webapp on my local tomcat5.5 install
> (from within eclipse again) I can see logback internal messages in the
> eclipse console view:
>
> 23/04/2010 10:15:19 AM org.apache.catalina.core.AprLifecycleListener
> lifecycleEvent
> INFO: The Apache Tomcat Native library which allows optimal performance
> in production environments was not found on the java.library.path:
> C:\Program
> Files\Java\jdk1.6.0_16\bin;.;C:\WINDOWS\Sun\Java\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\Program
> Files (x86)\CollabNet Subversion
> Client;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files
> (x86)\ATI Technologies\ATI.ACE\Core-Static;c:\Program Files
> (x86)\Microsoft SQL
> Server\90\Tools\binn\;C:\msys\1.0\bin;C:\mingw\bin;C:\cygwin\bin;C:\Program
> Files (x86)\TortoiseHg;C:\Program Files (x86)\Mercurial\;C:\Program
> Files (x86)\CVSNT\
> 23/04/2010 10:15:19 AM org.apache.coyote.http11.Http11BaseProtocol init
> INFO: Initializing Coyote HTTP/1.1 on http-8080
> 23/04/2010 10:15:19 AM org.apache.catalina.startup.Catalina load
> INFO: Initialization processed in 484 ms
> 23/04/2010 10:15:20 AM org.apache.catalina.core.StandardService start
> INFO: Starting service Catalina
> 23/04/2010 10:15:20 AM org.apache.catalina.core.StandardEngine start
> INFO: Starting Servlet Engine: Apache Tomcat/5.5.28
> 23/04/2010 10:15:20 AM org.apache.catalina.core.StandardHost start
> INFO: XML validation disabled
> 23/04/2010 10:15:20 AM org.apache.catalina.loader.WebappClassLoader
> validateJarFile
> INFO:
> validateJarFile(E:\workspaces\default\.metadata\.plugins\org.eclipse.wst.server.core\tmp0\wtpwebapps\web-keno\WEB-INF\lib\servlet-api-2.4.jar)
> - jar not loaded. See Servlet Spec 2.3, section 9.7.2. Offending class:
> javax/servlet/Servlet.class
> 10:15:20,578 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback-test.xml]
> 10:15:20,578 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Found resource [logback.xml] at
> [file:/E:/workspaces/default/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/wtpwebapps/web-keno/WEB-INF/classes/logback.xml]
>
> 10:15:20,625 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
> 10:15:20,625 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [FILE]
> 10:15:20,656 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing
> component [rollingPolicy] on top of the object stack.
> 10:15:20,671 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No
> compression will be used
> 10:15:20,671 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will
> use the pattern E:/apache-tomcat-5.5.28/logs/keno.%d{yyyy-MM-dd}.log for
> the active file
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy at 755c62bc
> - The date pattern is 'yyyy-MM-dd' from file name pattern
> 'E:/apache-tomcat-5.5.28/logs/keno.%d{yyyy-MM-dd}.log'.
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy at 755c62bc
> - Roll-over at midnight.
> 10:15:20,687 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter at 10:12
> - no applicable action for [encoder], current pattern is
> [[configuration][appender][encoder]]
> 10:15:20,687 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter at 11:13
> - no applicable action for [pattern], current pattern is
> [[configuration][appender][encoder][pattern]]
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
> name: E:/apache-tomcat-5.5.28/logs/keno.2010-04-23.log
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
> set to [null]
> 10:15:20,687 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - No layout set
> for the appender named "FILE".
> 10:15:20,687 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Popping appender named [FILE] from the object stack
> 10:15:20,687 |-INFO in
> ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of
> ROOT logger to ALL
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender
> named [FILE] to Logger[ROOT]
> 10:15:20,687 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - End of
> configuration.
>
> 10:15:20,578 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback-test.xml]
> 10:15:20,578 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Found resource [logback.xml] at
> [file:/E:/workspaces/default/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/wtpwebapps/web-keno/WEB-INF/classes/logback.xml]
>
> 10:15:20,625 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
> 10:15:20,625 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [FILE]
> 10:15:20,656 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing
> component [rollingPolicy] on top of the object stack.
> 10:15:20,671 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No
> compression will be used
> 10:15:20,671 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will
> use the pattern E:/apache-tomcat-5.5.28/logs/keno.%d{yyyy-MM-dd}.log for
> the active file
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy at 755c62bc
> - The date pattern is 'yyyy-MM-dd' from file name pattern
> 'E:/apache-tomcat-5.5.28/logs/keno.%d{yyyy-MM-dd}.log'.
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy at 755c62bc
> - Roll-over at midnight.
> 10:15:20,687 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter at 10:12
> - no applicable action for [encoder], current pattern is
> [[configuration][appender][encoder]]
> 10:15:20,687 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter at 11:13
> - no applicable action for [pattern], current pattern is
> [[configuration][appender][encoder][pattern]]
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
> name: E:/apache-tomcat-5.5.28/logs/keno.2010-04-23.log
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
> set to [null]
> 10:15:20,687 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - No layout set
> for the appender named "FILE".
> 10:15:20,687 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Popping appender named [FILE] from the object stack
> 10:15:20,687 |-INFO in
> ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of
> ROOT logger to ALL
> 10:15:20,687 |-INFO in
> ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender
> named [FILE] to Logger[ROOT]
> 10:15:20,687 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - End of
> configuration.
>
> 23/04/2010 10:15:20 AM org.apache.axis.utils.JavaUtils
> isAttachmentSupported
> WARNING: Unable to find required classes (javax.activation.DataHandler
> and javax.mail.internet.MimeMultipart). Attachment support is disabled.
> 23/04/2010 10:15:21 AM org.apache.coyote.http11.Http11BaseProtocol start
> INFO: Starting Coyote HTTP/1.1 on http-8080
> 23/04/2010 10:15:21 AM org.apache.jk.common.ChannelSocket init
> INFO: JK: ajp13 listening on /0.0.0.0:8009
> 23/04/2010 10:15:21 AM org.apache.jk.server.JkMain start
> INFO: Jk running ID=0 time=0/47 config=null
> 23/04/2010 10:15:21 AM org.apache.catalina.storeconfig.StoreLoader load
> INFO: Find registry server-registry.xml at classpath resource
> 23/04/2010 10:15:21 AM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 1375 ms
>
> The config does not appear twice when I turn off the debug option in the
> below logback.xml:
>
> <?xml version="1.0" encoding="UTF-8"?>
> <configuration debug="true">
> <appender name="FILE"
> class="ch.qos.logback.core.rolling.RollingFileAppender">
> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
> <FileNamePattern>${catalina.home}/logs/keno.%d{yyyy-MM-dd}.log</FileNamePattern>
>
> <MaxHistory>30</MaxHistory>
> </rollingPolicy>
>
> <encoder>
> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
> </encoder>
> </appender>
>
> <root level="all">
> <appender-ref ref="FILE" />
> </root>
> </configuration>
>
> However nothing seems to get logged. It creates the log file however it
> remains at 0 bytes. I tried using a console appender and had the same
> problem - the log messages did not appear on the console.
>
> When I try to run the above app on a ubuntu9/tomcat6 production-like
> environment, I get the same issue (no log messages) except I can't find
> the console output at all. I have a feeling that is a tomcat config
> issue though - I can't find catalina.out anywhere.
>
> Any ideas what might be causing the log messages to disappear?
>
> Cheers,
> Dan