Hi,
We've recently noticed that our log4j configuration logs are pretty empty. I
decided I must have changed something that ruptured the configuration, so with
a brand new installation of Tomcat 5.5.11 and a basic log4j config file (shown
below) I set about testing what was happening.
Before taking you through the steps, you will see that the log4j file
configures appenders for apache, hibernate and spring. As soon as Tomat
initialises the web application I am testing, both hibernate and spring
initialiizations take place.
Test 1
1. Brand new installation of 5.5.11
2. Deploy web application manually
3. Add log4j.properties to web app's WEB-INF/classes
4. Add log4j1.2.9.jar to web app's WEB-INF/lib
5. Start Tomcat
I move to the Tomcat logs folder (empty) and wait. The stdout_<date>.log is
created (as Tomcat is running as a Windows Service). I see a visible delay of
10 seconds or so with the file size increasing in this log file (non-log4j)
before the log4j configured logs appear. When Tomcat has fully started up (29s)
I note that the log4j logs have no logging, and that the stdout log has
collected all the web app's hibernate and spring logging.
Test 2
0. Clear logs folder
1. Delete log4j.properties from web app's WEB-INF/classes
2. Copy log4j.propeties to catalina.home/common/classes
3. Copy log4j1.2.9.jar to catalina.home/common/lib
4. Copy commons-logging.jar to catalina.home/common/lib
5. Start Tomcat
I move to the Tomcat logs folde (empty) and wait. This time, the log4j
configured logs appear instantly and all at once. A delay takes place until the
web app is initialized whereupon hibernate and spring logging starts getting
fed into the appropriate logs as desired.
Conclusion
When the same log4j configuration is used in Tomcat's common/classes (which I
presume is first to be loaded by the class loader) the log configuration is
immediately available and the correct behaviour takes place by the time the web
application's classes and libs are loaded.
When the same log4j configuration is used within the web application only, the
logs are created what appears too late and all logging is dumped into the
stdout log.
Is this known or understood by anyone?
Thanks, Allistair.
== log4j.properties ==
log4j.rootLogger=DEBUG, RootA
log4j.appender.RootA=org.apache.log4j.DailyRollingFileAppender
log4j.appender.RootA.File=${catalina.home}/logs/iq-Root.log
log4j.appender.RootA.layout=org.apache.log4j.PatternLayout
log4j.appender.RootA.layout.ConversionPattern=%d - %5p (%C:%L) - %m%n
log4j.appender.RootA.DatePattern=.yyyy-MM-dd
# Apache
log4j.appender.ApacheA=org.apache.log4j.DailyRollingFileAppender
log4j.appender.ApacheA.File=${catalina.home}/logs/iq-Api-Apache.log
log4j.appender.ApacheA.layout=org.apache.log4j.PatternLayout
log4j.appender.ApacheA.layout.ConversionPattern=%d - %5p (%C:%L) - %m%n
log4j.appender.ApacheA.DatePattern=.yyyy-MM-dd
log4j.logger.org.apache=INFO, ApacheA
log4j.additivity.org.apache=false
# Hibernate
log4j.appender.HibernateA=org.apache.log4j.DailyRollingFileAppender
log4j.appender.HibernateA.File=${catalina.home}/logs/iq-Api-Hibernate.log
log4j.appender.HibernateA.layout=org.apache.log4j.PatternLayout
log4j.appender.HibernateA.layout.ConversionPattern=%d - %5p (%C:%L) - %m%n
log4j.appender.HibernateA.DatePattern=.yyyy-MM-dd
log4j.logger.org.hibernate=DEBUG, HibernateA
log4j.additivity.org.hibernate=false
# Spring
log4j.appender.SpringA=org.apache.log4j.DailyRollingFileAppender
log4j.appender.SpringA.File=${catalina.home}/logs/iq-Api-Spring.log
log4j.appender.SpringA.layout=org.apache.log4j.PatternLayout
log4j.appender.SpringA.layout.ConversionPattern=%d - %5p (%C:%L) - %m%n
log4j.appender.SpringA.DatePattern=.yyyy-MM-dd
log4j.logger.org.springframework=DEBUG, SpringA
log4j.additivity.org.springframework=false
<FONT SIZE=1 FACE="VERDANA,ARIAL" COLOR=BLUE>
-------------------------------------------------------
QAS Ltd.
Registered in England: No 2582055
Registered in Australia: No 082 851 474
-------------------------------------------------------
</FONT>
