Bug 17498

Summary: Logging inconsistencies using DailyRollingFileAppender
Product: Log4j - Now in Jira Reporter: Andrew De Bona <a_debona>
Component: AppenderAssignee: log4j-dev <log4j-dev>
Status: REOPENED ---    
Severity: normal CC: apache, jnarula, obillaneni_sai, sonrani
Priority: P3    
Version: 1.2   
Target Milestone: ---   
Hardware: Sun   
OS: other   
Attachments: An alternate appender for daily rolling log files.

Description Andrew De Bona 2003-02-27 16:28:09 UTC
I have an unusual problem with Logging and DailyRollingFileAppender.  I have 
configured Log4J as follows:

# The debug log configuration
log4j.appender.A7=org.apache.log4j.DailyRollingFileAppender
log4j.appender.A7.DatePattern='.'yyyy-MM-dd
log4j.appender.A7.File=${debug_log_file} 
log4j.appender.A7.layout=org.apache.log4j.PatternLayout
log4j.appender.A7.layout.ConversionPattern=%d - %m%n
#This log can be turned off by changing the priority lower than ERROR which is 
DEBUG or INFO or WARN
log4j.category.com.cibc.ibas.logger.debug=DEBUG, A7

The Problem is that when I look in the logs directory I see the following:

-rw-rw-r--   1 proj12   proj12    829643 Feb 27 11:11 ibas.log
-rw-rw-r--   1 proj12   proj12    747099 Feb 27 11:15 ibas.log.2003-02-26

as you can see today's log (for Feb.27th) and yesterday's log have the same  
timestamp which means that Log4J is still writing to both logs files.  When I 
look at the log ibas.log.2003-02-26 it has logging activity for the 27th of 
February.  It seems that the log files are always a day behind. (i.e. 
ibas.log.2003-02-25 has logging activity for the 26th.. ibas.log.2003-02-24 has 
logging activity for the 25th etc..)

It seems as though log4j rolls over the file however keeps writing to both the 
new log file and the backup log file. Then repeats the same pattern the 
following day. We are running WebLogic 6.1 SP3 in Sun Solaris 5.8 O/S.

Any help would be much appreciated,
Comment 1 Ceki Gulcu 2004-05-28 18:00:56 UTC
This is probably a variant of bug 900.
Comment 2 Matt Coarr 2004-11-17 15:37:18 UTC
We are also experiencing the same problem on solaris.  

We are running iPlanet App Server 6.0 SP4 which uses J2SDK 1.2.2.  This is
running on Solaris 8.  This problem appears for us inside a stateless session
bean using the daily rolling file appender.

Bug 900 refers to similar symptoms, but is on Windows NT. So I'm not sure if
it's related.
Comment 3 Sean Mullins 2005-01-05 13:01:53 UTC
We are also experiencing this problem, with iPlanet on Solaris.
I think this may be the same problem as bug 24107/31458
Are you running in a clustered environment?
Comment 4 Vikash Singh 2005-01-20 09:56:09 UTC
I am also experiencing a similar problem.I am running j2sdk1.4.2 on Sun Solaris 
5.8.We have pure java single threaded processes running in the same machine. We 
have a Log file for each process and each have their own properties file.I am 
also using the DailyRollingFileAppender.Below is a sample of my properties file.


log4j.rootCategory=debug, R
log4j.appender.R=org.apache.log4j.DailyRollingFileAppender
log4j.appender.R.File=/cdd/apps/logs/XProcess.log
log4.appender.LOG.DatePattern='.'yyyy-MM-dd
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d [%t] %-5p %c - %m%n

The issue is that the process is writing into the present day’s log as well as 
the previous days log.This pattern continues and the following day’s log as 
well as the previous day’s log.
-rw-rw-r--  1 proj12     proj12 829643 Jan 27 11:11   XProcess.log
-rw-rw-r--  1 proj12     proj12 747099 Jan 27 11:15   XProcess.log.2005-01-16

As a result I am loosing some of the data that is overwritten by the following 
day’s logs.Note the process does not write the same data in to the two logs but 
instead writes part of the log in the present day log and part of the log in 
the previous day logs.

Can anyone Help me on this…..
Comment 5 Chuck 2005-10-06 23:59:43 UTC
Do you guys have a solution for this? if so what is it. I want to know since we 
are facing the same situation
Comment 6 Frank Peters 2005-12-21 11:52:19 UTC
We have the same problem on Linux/i386 using log4j 1.2.8. As far as I can see,
there was no relating bug fix up to the current version log4j 1.2.13. Am I right? 
Comment 7 Frank Peters 2006-08-01 15:25:48 UTC
Forget about my comment #6. We had an configuration problem with our tomcat,
different web applications loaded instances of log4j and wrote unsynchronized to
the logfile.
Comment 8 Jeffrey Born 2006-08-25 15:17:41 UTC
I am also running into this problem on a Solaris 8 box.  We are using version
1.2.12 of log4j.

The log4j properties we are using are as follows:
# Configure the name of the logout for the rolling appender
log4j.appender.rolling.File=/dir/webapp.log
log4j.appender.rolling.layout.ConversionPattern=%d [%t] - %p %c - %m%n
# Configure the Layout pattern and conversion pattern for the rolling appender
log4j.appender.rolling.layout=org.apache.log4j.PatternLayout
# Configure the rolling appender to be a RollingFileAppender
log4j.appender.rolling=org.apache.log4j.DailyRollingFileAppender
log4j.appender.rolling.DatePattern='.'yyyy-MM-dd
#  Configure the stdout appender to use the PatternLayout
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
# Pattern to output the caller's file name and line number.
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n
# Configure the stdout appender to go to the Console
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
# Create two appenders, one called stdout and the other called rolling
log4j.rootLogger=DEBUG, rolling
# Set the logger level for everything under "org.apache" to WARN
log4j.logger.org.apache=WARN
# Set the logger level for "org.apache.commons.validator.ValidatorUtil" to
# FATAL because we know that errors will be generated here that we want to
# ignore (due to the fact that it is unknown whether a consumer is personal
# or business and the validation.xml file is not set up to accomodate the
# differences)
log4j.logger.org.apache.commons.validator.ValidatorUtil=FATAL
log4j.logger.com.harland.collective.config.ApplicationConfig=WARN
log4j.logger.com.harland.choice.web.tags.CustomLink=WARN
log4j.logger.com.harland.choice.web.tags.html.HarlandLinkTag=WARN
log4j.logger.com.harland.choice.web.filters.PrivacyPolicyFilter=WARN
log4j.logger.com.harland.choice.web.util.resources.ChoiceMessageResources=WARN


The webapp is running under iPlanet and no other applications use this log4j.
Only one JVM.

This behaviour is clobbering the rolled file on us, so seems quite critical in
nature because we are losing yesterdays logs.
Comment 9 Asgeir Nilsen 2006-08-28 10:38:14 UTC
Created attachment 18756 [details]
An alternate appender for daily rolling log files.

DailyRollingFileAppender has issues when running in a multi-threaded
environment, as a servlet container in it's nature is.

The decision to roll over the file is handled within the appender, which in
many cases may exist in several instances, possibly due to placement in the
classloader hierarchy.

Many of the appender instances may be unaware that the name of the file under
their open file descriptor has changed.

We have also experiences loss of logging data in this context, as DRFA deletes
the log file if it already exists when performing the roll over.

Have you tried placing log4j in the boot classpath, ensuring that it sits on
top of the classloader hierarcy?

In a web container, the .war files should NOT bundle log4j by themselves.

I've attached an alternate appender we use for daily rolling.  It avoids the
issue by simply creating a dated log file in the first place.
Comment 10 Curt Arnold 2007-08-22 10:35:19 UTC
Marking as invalid as it is likely due to multiple instances of DRFA with same configuration.
Comment 11 Curt Arnold 2007-08-22 19:08:53 UTC
*** Bug 38874 has been marked as a duplicate of this bug. ***
Comment 12 Curt Arnold 2007-08-22 20:10:06 UTC
*** Bug 42562 has been marked as a duplicate of this bug. ***
Comment 13 Curt Arnold 2007-08-22 20:18:17 UTC
*** Bug 42797 has been marked as a duplicate of this bug. ***
Comment 14 Sid Behura 2014-11-24 11:57:03 UTC
I am also facing this problem .
Please refer https://issues.apache.org/bugzilla/show_bug.cgi?id=57240