[logback-user] weird RollingFileAppender behavior if not building a full date string

[Chris Curtin]

Hi,

I've been evaluating logback for a project and started playing with a
RollingFileAppender. Using 1.1.2

I was getting some strange behavior, including missing several log events
with a very simple test program. I finally tracked it back to the
definition of the rotate interval.

I had this:

<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

 <fileNamePattern>${userid}/${userid}.%d{yyyy-MM-dd-mm}.log</fileNamePattern>
   <maxHistory>30</maxHistory>
</rollingPolicy>

and was trying to roll over every minute.

Simple test program:

 Logger logger = LoggerFactory.getLogger(LogbackTest.class);
        MDC.put("userid", "chris");

        for (int i = 0; i < 30; i++) {
            logger.debug("Hello World {}", i);
            try {
                Thread.sleep(5000);
            } catch (Exception e) { }
        }

What I found was the first file created, the minute when the process
started, was either missing the first 2-5 log entries or the file was
missing.

If you look closely at the fileNamePattern you'll see I forgot to add the
hour to the format. Changing to:

 <fileNamePattern>${userid}/${userid}.%d{yyyy-MM-dd-HH-mm}.log.gz</fileNamePattern>

Worked as expected.

While the mistake was on my side, why would leaving off the hours cause
data to be missing? No errors, printing the LoggerContext after it was done
running didn't show any errors either.

I did remove the files between runs, so there was no chance of a file
already existing.

Thanks,

Chris
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20141017/22007c44/attachment.html>