Greetings,
Hope someone has heard of the problem below or can suggest workarounds or
how to debug this thing.
Problem:
=======
- After rolling, the old (rotated) log file continues to pick up entries
and grows.
The new log file picks up WARN and INFO level logs. The old/rolled file
picks
up ERROR level logs.
- After max rotations, the filename no longer visible to "ls". But the Java
process
still has 2 file descriptors pointing at the deleted file. The file will
keep
growing until it eats up all disk space.
- Only a handful systems have this problem. We have about 20 systems
in the lab and most of them rotate correctly.
One system has this bug happening 100% of the time, meaning after
restarting the
Java process, the rotation problem appears at the first rollover.
It is our stress test system and generates quit a bit of log entries
(busy but not
ridiculously busy).
- 3 other systems entered the above state after moderate effort to
filled the log file to trigger rolling.
Other Symtoms:
=============
Output from the command "ls -l /proc/<pid>/fd | grep catalina.out":
Mar 31 11:21 1 -> /var/log/tomcat/catalina.out.1
Mar 31 11:21 111 -> /var/log/tomcat/catalina.out
Mar 31 11:21 2 -> /var/log/tomcat/catalina.out.1
We have another Java process using identical log4j properties file
(except the log filename part). This process has no rotation problem.
"lsof | grep log4j" output shows this other process has handles
to log4j-1.2.15.jar. But the tomcat process which has rotation
problem does not?! Not sure if this means anything.
History and Environment:
=======================
We have been using log4j since 2012 without any issues. There are about 200
customers using this configuration:
- CentOS 6.4, 6.5 and 6.6 (systems upgrade to latest CentOS releases)
- Java 6 (openjdk)
- tomcat 6.0.32
- log4j 2.15 (base on the filename log4j-1.2.15.jar)
- Dell server with 16G RAM and 12 CPU cores (2 sockets X 6 cores)
This problem appears recently when we upgrade our system to the followings:
- CentOS 6.7
- Java 8 (currently java-1.8.0-openjdk-1.8.0.77-0.b03)
- tomcat 6.0.45 (at one point the stress test system used 6.0.32 and
already
exhibited the rotation problem)
- log4j 2.15
log4j.properties:
================
log4j.rootLogger=WARN, R
##rolling appender
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=${catalina.home}/logs/catalina.out
log4j.appender.R.MaxFileSize=10MB
log4j.appender.R.MaxBackupIndex=10
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
## logging levels
log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost]=WARN
log4j.logger.org.apache.catalina.core=WARN
log4j.logger.org.apache.catalina.session=WARN
log4j.logger.com.ourcompany=INFO
tomcat config
==========
Probably relevant but there are multiple conf files and web.xml and I don't
know which involve logging.
Regards,
Simon
