logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From bugzi...@apache.org
Subject DO NOT REPLY [Bug 17201] - DailyRollingFileAppender and multi-instance loses data
Date Mon, 10 May 2004 15:02:28 GMT
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG 
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://issues.apache.org/bugzilla/show_bug.cgi?id=17201>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND 
INSERTED IN THE BUG DATABASE.

http://issues.apache.org/bugzilla/show_bug.cgi?id=17201

DailyRollingFileAppender and multi-instance loses data

srevilak@f7.net changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|DailyRollingFileAppender and|DailyRollingFileAppender and
                   |multi-instance              |multi-instance loses data



------- Additional Comments From srevilak@f7.net  2004-05-10 15:02 -------
I too have found problems with DailyRollingFileAppender where
multiple processes are writing to the same logfile, across the time
boundary of a rotation period.  The ultimate result is data loss, and
it is easily reproducible.

Accompanying this writeup are four file attachments: the first three
comprise a test case to demonstrate this behavior; the fourth file is
a patch to DailyRollingFileAppender that prevents this data loss.

Test case files:

  1) log4j.properties -
     Configures log4j with a DailyRollingFileAppender, whose rotation
     period is one minute, writing to a file named "test.log".

  2) LogLoop.java -
     A command line java program.  LogLoop takes arguments of M and
     N.  It logs M info lines, spaces at N-second intervals, followed
     by "done".

  3) runtest.sh - 
     Bourne shell script that runs the test case.


runtest.sh invokes three concurrent LogLoop instances

  * instance #1 logs 300 lines, at 1 second intervals + "done"
  * instance #2 logs 150 lines, at 2 second intervals + "done"
  * instance #3 logs 100 lines, at 3 second intervals + "done"

Prior to the first rotation, test.log looks something like the
following:

   20040510.100541 INFO  [main] LogLoop - log: 0 of 300 (interval=1)
   20040510.100541 INFO  [main] LogLoop - log: 0 of 100 (interval=3)
   20040510.100541 INFO  [main] LogLoop - log: 0 of 150 (interval=2)
   20040510.100542 INFO  [main] LogLoop - log: 1 of 300 (interval=1)
   20040510.100543 INFO  [main] LogLoop - log: 2 of 300 (interval=1)
   20040510.100543 INFO  [main] LogLoop - log: 1 of 150 (interval=2)
   20040510.100544 INFO  [main] LogLoop - log: 3 of 300 (interval=1)
   20040510.100544 INFO  [main] LogLoop - log: 1 of 100 (interval=3)


The entries from the three processes are intermixed in the same file
- just what one would expect.


After the 5 minute test, one can aggregate the "interval=" entries
across all of the test.log.* files.  Below is the aggregation from one
sample run:

  # of interval=1: 0
  # of interval=2: 141
  # of interval=3: 14


We would expect a total of 553 entries (300 + 150 + 100 + 1 + 1 + 1).
Above, there are only 155.  In other words, roughly two-thirds of the
data has been lost.  These results will vary non-deterministically
among different runs, but any single run will produce data loss -- one
process wins, while the other two lose.

Admittedly, unsynchronized writes by independant processes are not
ideal.  However, for cases where this is seen as acceptable (eg - one
recognizes the possibility of the occassionally corrupt log entry), I
would maintain that a logging system should make reasonable attempts
to prevent the loss of large portions of data.


The attachment "DailyRollingFileAppender.java.patch" contains a patch
with changes to rollover().  With this patch applied, the aggregation
of logs from runtest.sh is as follows:

  # of interval=1: 301
  # of interval=2: 151
  # of interval=3: 101

All 553 entries present.

I hope that you'll consider incorporating these changes into the next
release of log4j.


--
Steve Revilak

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message