TimeBasedRollingPolicy not rolling unless there are new logs

villager picture villager · Mar 5, 2014 · Viewed 15.9k times · Source

Here's my config:

<appender name="myAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <append>true</append>
    <file>mylogs.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <!-- daily rollover -->
        <fileNamePattern>mylogs-%d{yyyy-MM-dd_HH-mm}.log</fileNamePattern>

        <!-- keep 30 days' worth of history -->
        <maxHistory>30</maxHistory>
    </rollingPolicy>

    <encoder>
        <pattern>%d{HH:mm:ss.SSS} %-5level %logger{36} [%thread] - %M:%L - %msg%n</pattern>
    </encoder>
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>INFO</level>
    </filter>
</appender>

According to the logback's document found here (http://logback.qos.ch/manual/appenders.html#TimeBasedRollingPolicy) , file will be rollover every minute based on my %d{yyyy-MM-dd_HH-mm} fileNamePattern.

I observed how this works and here are my findings:

  • It doesn't create a log file very minute.
  • It only create a log file for the previous minute when the a new log arrives. (e.g. I have a log on 11:53pm, and it's now 11:55pm, it doesn't create a new log file immediately for the 11:53pm when it hits 11:54pm, but when a new log came later, say at 11:56pm, it now creates the file for 11:53pm.)

Am I missing something, I thought it will create a log file every minute?

Answer

sheltem picture sheltem · Mar 5, 2014

Scroll down further in the section of the documentation you linked and you will find this:

For various technical reasons, rollovers are not clock-driven but depend on the arrival of logging events. For example, on 8th of March 2002, assuming the fileNamePattern is set to yyyy-MM-dd (daily rollover), the arrival of the first event after midnight will trigger a rollover. If there are no logging events during, say 23 minutes and 47 seconds after midnight, then rollover will actually occur at 00:23'47 AM on March 9th and not at 0:00 AM. Thus, depending on the arrival rate of events, rollovers might be triggered with some latency. However, regardless of the delay, the rollover algorithm is known to be correct, in the sense that all logging events generated during a certain period will be output in the correct file delimiting that period.

Short version: It's not time-triggered, but logging-event-triggered. No logging events means no rollover. In a configuration set to rollover each minute that means there will be no files for any minute for which no logging-events arrive.