[ http://jira.qos.ch/browse/LBCORE-188?page=com.atlassian.jira.plugin.system.i... ] Benoit Sigoure commented on LBCORE-188: --------------------------------------- What's the status on this issue? I have the same problem on a 16 thread machine where I log over 500 log lines per second and roll the log every 1GB or every day. Typically this means 1 log file every 90 minutes. I regularly find these .tmp files left over forever. This is my config: <?xml version="1.0" encoding="UTF-8"?> <configuration> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern> %d{ISO8601} %-5level [%thread] %logger{0}: %msg%n </pattern> </encoder> </appender> <appender name="ACCESS" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>access.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>access.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <maxFileSize>1GB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> <maxHistory>15<!-- days --></maxHistory> </rollingPolicy> <encoder> <pattern>%msg%n</pattern> </encoder> </appender> <logger name="access.log" additivity="false"> <appender-ref ref="ACCESS"/> </logger> <root level="info"> <appender-ref ref="STDOUT"/> </root> </configuration> This is what I see: $ ls -lh [...] -rw-r--r-- 1 nobody nogroup 135M 2011-11-15 02:20 access.2011-11-15.0.log.gz -rw-r--r-- 1 nobody nogroup 245M 2011-11-15 15:57 access.2011-11-15.1.log.gz -rw------- 1 nobody nogroup 255M 2011-11-15 18:45 access.2011-11-15.2.log.gz -rw-r--r-- 1 nobody nogroup 264M 2011-11-16 02:17 access.2011-11-16.0.log.gz -rw-r--r-- 1 nobody nogroup 269M 2011-11-16 03:53 access.2011-11-16.1.log.gz -rw-r--r-- 1 nobody nogroup 272M 2011-11-16 05:38 access.2011-11-16.2.log.gz -rw-r--r-- 1 nobody nogroup 264M 2011-11-16 08:02 access.2011-11-16.3.log.gz -rw-r--r-- 1 nobody nogroup 245M 2011-11-16 10:14 access.2011-11-16.4.log.gz -rw-r--r-- 1 nobody nogroup 236M 2011-11-16 12:15 access.2011-11-16.5.log.gz -rw-r--r-- 1 nobody nogroup 238M 2011-11-16 13:43 access.2011-11-16.6.log.gz -rw-r--r-- 1 nobody nogroup 242M 2011-11-16 14:47 access.2011-11-16.7.log.gz -rw-r--r-- 1 nobody nogroup 247M 2011-11-16 15:50 access.2011-11-16.8.log.gz -rw-r--r-- 1 nobody nogroup 249M 2011-11-16 16:51 access.2011-11-16.9.log.gz -rw-r--r-- 1 nobody nogroup 171M 2011-11-16 17:00 access.log -rw-r--r-- 1 nobody nogroup 513M 2011-11-15 05:01 access.log15647669758468154.tmp -rw-r--r-- 1 nobody nogroup 1.1G 2011-11-15 11:03 access.log15669411384328453.tmp -rw------- 1 nobody nogroup 1.1G 2011-11-15 21:16 access.log15706172211743663.tmp -rw-r--r-- 1 nobody nogroup 1.1G 2011-11-15 23:42 access.log15714960415388814.tmp -rw-r--r-- 1 nobody nogroup 114M 2011-11-15 23:59 access.log15716000623422346.tmp [...]
Log Rotation/Gzip process leaving .tmp files behind ---------------------------------------------------
Key: LBCORE-188 URL: http://jira.qos.ch/browse/LBCORE-188 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.26 Reporter: Bert B-L Assignee: Ceki Gulcu
We are seeing logback leave .tmp files behind in the log directory, presumably due to a hiccup during log rotation or gzip. Size 2365956 Dec 11 00:00 statsreceiver.log.2010-12-10.gz 2679618 Dec 12 00:01 statsreceiver.log.2010-12-11.gz 9190879942 Dec 12 04:00 statsreceiver-debug.log23124507802228260.tmp 2542799 Dec 13 00:00 statsreceiver.log.2010-12-12.gz 9137740366 Dec 13 04:00 statsreceiver-debug.log23210907242250260.tmp 543937393 Dec 13 20:07 statsreceiver-debug.log.2010-12-13_19:00.gz 548781049 Dec 13 22:07 statsreceiver-debug.log.2010-12-13_21:00.gz 2284216 Dec 14 00:00 statsreceiver.log.2010-12-13.gz 8127562 Dec 15 00:00 statsreceiver.log.2010-12-14.gz 19067117496 Dec 15 13:00 statsreceiver-debug.log23416102512001260.tmp 18177324477 Dec 15 16:00 statsreceiver-debug.log23426920509229260.tmp 2257423 Dec 15 23:00 statsreceiver-debug.log.2010-12-15_22:00.gz The logback jar versions are: WEB-INF/lib/logback-classic-0.9.26.jar WEB-INF/lib/logback-core-0.9.26.jar There is only a single application writing to those files, though it is conceivable that the .tmp droppings correlate to restarts of that application. If this is expected on application restarts, could logback start gzip'ing them again when it comes back? Here is the logback.xml file: <?xml version="1.0" encoding="UTF-8"?> <configuration scan="true" scanPeriod="60 seconds"> <appender name="FILE_WARN" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${logdir:-.}/${prog:-unknown}.log</file> <append>true</append>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>warn</level> </filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>${logdir:-.}/${prog:-unknown}.log.%d{yyyy-MM-dd}.gz</fileNamePattern> <maxHistory>7</maxHistory> </rollingPolicy> <encoder> <pattern>%-30(%d{yyyy-MM-dd HH:mm:ss} %.-1level :) %m Context:[%X{GTNDC_INFO}]%n</pattern> </encoder> </appender> <appender name="FILE_DEBUG" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${logdir:-.}/${prog:-unknown}-debug.log</file> <append>true</append>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>debug</level> </filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>${logdir:-.}/${prog:-unknown}-debug.log.%d{yyyy-MM-dd_HH:00}.gz</fileNamePattern> <maxHistory>36</maxHistory> </rollingPolicy> <encoder> <pattern>%-60(%d{yyyy-MM-dd HH:mm:ss} [%thread] %.-1level :) %m Context:[%X{GTNDC_INFO}]%n</pattern> </encoder> </appender> <logger name="org.apache.directory" level="WARN"/> <root><level value="debug"/> <appender-ref ref="FILE_WARN"/> <appender-ref ref="FILE_DEBUG"/> </root> </configuration>
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira