[logback-dev] [JIRA] Commented: (LBCORE-188) Log Rotation/Gzip process leaving .tmp files behind

Benoit Sigoure (JIRA) noreply-jira at qos.ch
Wed Nov 16 18:03:13 CET 2011


    [ http://jira.qos.ch/browse/LBCORE-188?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12308#action_12308 ] 

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

        


More information about the logback-dev mailing list