The DailyRollingFileAppender (DRFA) tries to rename the log file during roll over. However, when the rename fails, it ends up overwriting the log file, hence loosing information. In particular, on Windows, the file rename can fail if another thread has the file open. This problem was found in 1.2.8 and still exists in 1.2.15. The problem was already described in bug 29726, but at that time the solution was left to 1.3. Then it was again addressed in bug 41735, but only for RollingFileAppender (RFA). I also talked about it on log4j-user ML (http://mail-archives.apache.org/mod_mbox/logging-log4j-user/200709.mbox/%3cc8485ef10709040538k2074c3aag644f7b19a3a41e81@mail.gmail.com%3e). I created a unit test that reproduces the problem (and also tests RFA), and made a patch to solve this problem. The problem was reproduced with both log4j 1.2.9 & 1.2.15 in the following configurations (all combinations): - Win XP SP1, Win XP SP2, Win 2K3 - JDK 1.4.2_03-b02, 1.5.0_10-b03, 1.6.0_02-b06 - JUnit 3.8.1 The following patch applies on 1.2.15 and addresses the issue: (I tested it in all the above configurations.) Index: DailyRollingFileAppender.java =================================================================== --- DailyRollingFileAppender.java (revision 572567) +++ DailyRollingFileAppender.java (working copy) @@ -319,16 +319,19 @@ File file = new File(fileName); boolean result = file.renameTo(target); + boolean continueToAppend = false; if(result) { LogLog.debug(fileName +" -> "+ scheduledFilename); } else { - LogLog.error("Failed to rename ["+fileName+"] to ["+scheduledFilename+"]."); + // if file rename failed, reopen file with append = true + LogLog.warn("Failed to rename ["+fileName+"] to ["+scheduledFilename+"]."); + continueToAppend = true; } try { // This will also close the file. This is OK since multiple // close operations are safe. - this.setFile(fileName, false, this.bufferedIO, this.bufferSize); + this.setFile(fileName, continueToAppend, this.bufferedIO, this.bufferSize); } catch(IOException e) { errorHandler.error("setFile("+fileName+", false) call failed.");
Created attachment 20806 [details] Patch solving the issue
Created attachment 20807 [details] Unit test reproducing the bug
Created attachment 20809 [details] Patch solving the issue (Cleaner version of the patch)
Committed changes in rev 577413. I could not come up with a scenario where it would be undesirable to append to the base log file name, so instead of calculating whether to append based on rename failure, I just hard-coded it to append. I created a much simpler test to add to the existing DRFATestCase that fails with the old code. Changed the bug title since the DRFA is expected to delete files, but not to lose messages.
There is a similar bug 44932, which is reported for log4j version 1.2.15. Does this fix also address the issue mentioned in the bug 44932? There is an issue we have for our application where in rare scenarios, the rollover files are getting deleted and our application starts writing to a single log file which then grows to over 50GB. We are using log4j version 1.2.15. So I am not sure if we should move to the latest version 1.2.16 which has this fix or whether the due to issue mentioned in 44932 (which is still open), the application will continue to behave erratically at times.
(In reply to comment #5) > There is a similar bug 44932, which is reported for log4j version 1.2.15. Does > this fix also address the issue mentioned in the bug 44932? There is an issue > we have for our application where in rare scenarios, the rollover files are > getting deleted and our application starts writing to a single log file which > then grows to over 50GB. We are using log4j version 1.2.15. > So I am not sure if we should move to the latest version 1.2.16 which has this > fix or whether the due to issue mentioned in 44932 (which is still open), the > application will continue to behave erratically at times. We have the same problem ! I think it could be solve issue 44932 but im not sure.