logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Simon Chan <sialn...@gmail.com>
Subject Re: rolled log file continues to grow unbound
Date Thu, 31 Mar 2016 23:51:32 GMT
Hi Ron,

You are right! fd 1 and 2 are blocking log4j from closing the log file
properly.

tomcat starts the Java process with: java -Dblah... >> catalina.out 2>&1  &

I wonder how we did not notice this in the past years.

Thanks again
Simon

On Thu, Mar 31, 2016 at 2:38 PM, Ron Gonzalez <gonz.ron@gmail.com> wrote:

> 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