logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ron Gonzalez <gonz....@gmail.com>
Subject Re: rolled log file continues to grow unbound
Date Thu, 31 Mar 2016 21:38:36 GMT
My first inclination is that you shouldn't have two locks on the same file
from the same process.  That points to multiple writers independently
locking the file.  This means when one tries to roll the other will still
retain the lock on the file blocking the other one.

You should identify whether your application code has a handle leak or
whether different components are instantiating multiple versions of log4j
which both want to retain locks to the same file.

A thread dump from the jvm when the issue is happening should help isolate
it.

HTH

Ron
On Mar 31, 2016 4:14 PM, "Simon Chan" <sialnije@gmail.com> wrote:

> 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
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message