I have a clean tomcat 7 installation on amazon linux (version 201303) with one application deployed as ROOT. log4j-1.2.17.jar resides in WEB-INF/lib. There is a log4j.properties file in WEB-INF/classes containing the following:
log4j.rootLogger=DEBUG,A1, A2
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.Threshold=DEBUG
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d{yyyy-MM-dd}-%t-%x-%-5p-%-10c:%m%n
log4j.appender.A2.File=${catalina.home}/logs/app.log
log4j.appender.A2=org.apache.log4j.DailyRollingFileAppender
log4j.appender.A2.DatePattern='.' yyyy-MM-dd
log4j.appender.A2.MaxFileSize=10MB
log4j.appender.A2.MaxBackupIndex=99
log4j.appender.A2.Append=true
log4j.appender.A2.layout=org.apache.log4j.PatternLayout
log4j.appender.A2.layout.ConversionPattern=%d{yyyy-MM-dd HH\:mm\:ss,SSS}-%t-%x-%-5p-%-10c:%m%n
In the app, log4j is instantiated with
static Logger logger = Logger.getLogger(ClassName.class.getName());
app.log never gets created. If I create it manually, it is never written to. The only logging going on is in logs/catalina.out. What am I missing? I've read through http://tomcat.apache.org/tomcat-7.0-doc/logging.html several times. The following excerpt seems to confirm my approach:
These steps are not needed if you just want to use log4j in your own web application. — In that case, just put log4j.jar and log4j.properties into WEB-INF/lib and WEB-INF/classes of your web application.
There is a log4j.jar and log4j.xml in catalina_home/lib, along with a log4j.properties in catalina_home/conf. Could those be conflicting with the jars included in my WAR? I don't see any errors in catalina.out.
UPDATE
So it appears that the log4j.properties in WEB-INF/classes is loading. I removed the ConsoleAppender (log4j.appender.A1) and log messages stopped appearing in catalina.out. I put it back in and the log messages reappeared in catalina.out. What's weird is the conversion pattern doesn't seem to match the log. Shouldn't %d{yyyy-MM-dd}-%t-%x-%-5p-%-10c:%m%n generate something like 2013-07-10 INFO ClassName Log message? Instead I'm seeing 14:39:29,180 INFO [ClassName] Log message.
UPDATE 2
I found my answer. There was a log4j.xml in ${catalina.home}/lib that was configuring log4j at the container level. I guess if I actually new what I was doing in Tomcat I would have figured it out sooner. Once I started configuring lib/log4j.xml I got the expected result. I'm still a little confused why my app inherited that configuration instead of using its own log4j.properties. Oh well, I achieved the intended result so time to move on.
