[logback-dev] [JIRA] (LOGBACK-992) Rolling File Appender creates .tmp files but never deletes them

[Stefan Prange (JIRA)]

Stefan Prange commented on LOGBACK-992 Rolling File Appender creates .tmp files but never deletes them Hi, one of our developers observed a similar behavior recently. He found this log output after enabling the "debug" attribute in the <configuration> element in logback.xml: [11/5/14 0:00:05:004 CET] 0000001a SystemOut O 00:00:05,004 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Elapsed period: Tue Nov 04 16:33:30 CET 2014 [11/5/14 0:00:05:005 CET] 0000001a SystemOut O 00:00:05,005 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [logs/log-output-MyAppl.log] to [logs/log-output-MyAppl.log14538255624893230.tmp] [11/5/14 0:00:05:019 CET] 0000001a SystemOut O 00:00:05,019 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization [11/5/14 0:00:05:019 CET] 0000001a SystemOut O 00:00:05,019 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - periodsElapsed = 64 [11/5/14 0:00:05:019 CET] 00000092 SystemOut O 00:00:05,019 |-INFO in ch.qos.logback.core.rolling.helper.Compressor - GZ compressing [logs/log-output-MyAppl.log14538255624893230.tmp] as [logs/log-output-MyAppl.log.2014-11-04.gz] [11/5/14 0:00:05:019 CET] 0000001a SystemOut O 00:00:05,019 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - deleting logs/log-output-MyAppl.log.2014-10-04.gz [11/5/14 0:00:30:018 CET] 0000002b SystemOut O 00:00:30,018 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Elapsed period: Tue Nov 04 16:33:30 CET 2014 [11/5/14 0:00:30:019 CET] 0000002b SystemOut O 00:00:30,019 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [logs/log-output-MyAppl.log] to [logs/log-output-MyAppl.log14538280639291244.tmp] [11/5/14 0:00:30:019 CET] 0000002b SystemOut O 00:00:30,019 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization [11/5/14 0:00:30:019 CET] 00000093 SystemOut O 00:00:30,019 |-WARN in ch.qos.logback.core.rolling.helper.Compressor - The target compressed file named [logs/log-output-MyAppl.log.2014-11-04.gz] exist already. Aborting file compression. [11/5/14 0:00:30:020 CET] 0000002b SystemOut O 00:00:30,019 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - periodsElapsed = 64 As you can see, logback tries to compress the log file twice. The second time it fails because the target .gz file already exists. In my opinion, logback should remove the .tmp file by all means, also in case of compression failure. The root cause of the problem (at least in our case) is that logback seems to be running twice here. We haven't tracked that down yet, our environment is sort of messed up at the moment, but I assume a JavaEE classloading problem here. Logback is encapsulated by SLF4J and both are running in a IBM WebSphere Application Server which brings its own Slf4J jar. So having not the correct classloading order configured can produce strange effects. Versions used here are: Logback 1.1.2 and SLF4J 1.7.7 on IBM WebSphere Application Server 8.0.0.8

This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira

_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-dev