Bug 45236

Summary: Wriring output to an out-dated file.
Product: Log4j - Now in Jira Reporter: Nagireddy Satti <nagireddy9>
Component: OtherAssignee: log4j-dev <log4j-dev>
Status: NEEDINFO ---    
Severity: critical CC: thorbjoern
Priority: P1    
Version: 1.2   
Target Milestone: ---   
Hardware: PC   
OS: AIX   
Attachments: The bug result
PDF version of original Microsoft Word template

Description Nagireddy Satti 2008-06-19 04:52:45 UTC
While writing log to a file, it's writing to an out-dated file. Please find the attachment.
Comment 1 Nagireddy Satti 2008-06-19 06:00:11 UTC
Created attachment 22144 [details]
The bug result
Comment 2 Thorbjørn Ravn Andersen 2008-06-30 14:32:07 UTC
Can you see in the lines what was logged at that time?

Is it just a single line or many lines?
Comment 3 Nagireddy Satti 2008-07-02 01:40:37 UTC
A bulk of output lines have been written to an out-dated log. It's not once, frequently happening. As I know, writing one line or multiple lines to an 
out-dated log file is not important. Please try to fix this as soon as possible,as some times we are unable to find out the correct log statements. Some times it's writing to multiple files(Out-dated).
Comment 4 Curt Arnold 2008-07-02 06:32:31 UTC
Created attachment 22209 [details]
PDF version of original Microsoft Word template

The original attachment is a Microsoft Word template file (.dot) which suggests the presences of a Word Macro virus.
Comment 5 Curt Arnold 2008-07-02 06:41:22 UTC
The behavior mentioned is consistent with configuring multiple instances of log4j writing to the same DailyRollingFileAppender.  The behavior and attachment suggests that the platform is a Unix and not Windows XP as reported.  Having multiple instances of any file appender write to the same path name is known to be error-prone and is strongly discouraged and unsupported.

If multiple instances are writing to the same file names, one instance may rename a file while another instance continues to write to it.  When the second instance attempts to roll over its working file, it fails since the target file already exists.

Unless the problem is not related to multiple instances and additional information is provided, the report should be marked INVALID.
Comment 6 Nagireddy Satti 2008-07-02 07:15:51 UTC
We are not using multiple instances of log4j. See here the problem is only one instance that exists in the system is trying to write the log statements to an out-dated file. For example, today is 02/07/2008. So the log4j is supposed to write the log statements to a file called smmt.log. But some times it is trying to write to a file smmt.log.2008-06-29. 

We have the following properties as part of log4j.propertis file.

log4j.appender.R=org.apache.log4j.DailyRollingFileAppender
log4j.appender.R.File=smmt.log
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss,SSS} [%-5p] %c - %m\n
log4j.appender.R.Threshold=DEBUG

 here R is the logger name.
Comment 7 Thorbjørn Ravn Andersen 2008-07-02 16:47:17 UTC
(In reply to comment #5)
> The behavior mentioned is consistent with configuring multiple instances of
> log4j writing to the same DailyRollingFileAppender.  The behavior and
> attachment suggests that the platform is a Unix and not Windows XP as reported.

The screen dump in the PDF strongly suggest to come from a Unix machine.  The naming is consistent with the "Configuring Linux for the Installation of Oracle Database 10g" document from Oracle

http://www.oracle.com/technology/obe/obe10gdb/install/linuxpreinst/linuxpreinst.htm

It is known that the DailyRollingFileAppender is not rolling over until an event is logged which then triggers a check.  It would be consistent with known behaviour if there were multiple log4j instances writing to the same files, so one instance has rolled over but with others not having checked yet. I agree with your findings.

As OC4J is mentioned in the screen dump it would be reasonable to expect that we are dealing with the Oracle web container OC4J, and that the multiple loggers could happen from two or more web applications with their own log4j copy, but with the same log4j configuration.

Comment 8 Thorbjørn Ravn Andersen 2008-07-02 16:51:48 UTC
(In reply to comment #6)
> We are not using multiple instances of log4j. See here the problem is only one
> instance that exists in the system is trying to write the log statements to an
> out-dated file. For example, today is 02/07/2008. So the log4j is supposed to
> write the log statements to a file called smmt.log. But some times it is trying
> to write to a file smmt.log.2008-06-29. 
> 
> We have the following properties as part of log4j.propertis file.
> 
> log4j.appender.R=org.apache.log4j.DailyRollingFileAppender
> log4j.appender.R.File=smmt.log
> log4j.appender.R.layout=org.apache.log4j.PatternLayout
> log4j.appender.R.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss,SSS} [%-5p]
> %c - %m\n
> log4j.appender.R.Threshold=DEBUG
> 
>  here R is the logger name.

I believe that this may be caused by several web applications configured identically even if it is in the same web container.  If you need common logging for all web applications you need to move log4j.jar out of the individual web applications and into the area providing common jars for all web application.

Can you please create a small example reproducing the behaviour you see, and give "uname -a" on the host having the problems?
Comment 9 Thorbjørn Ravn Andersen 2008-08-02 09:04:19 UTC
Awaiting information from original reporter.

This might be yet another "cannot roll over in RollingFileAppender" but I find it suspicious that there are two different files which have been written to and they have only one inode count each.  Hence the need to clarify the configuration in this problem.