52

I would like to configure logback to do the following.

  • Log to a file
  • Roll the file when it reaches 50MB
  • Only keep 7 days worth of logs
  • On startup always generate a new file (do a roll)

I have it all working except for the last item, startup roll. Does anyone know how to achieve that? Here's the config...

  <appender name="File" class="ch.qos.logback.core.rolling.RollingFileAppender">

    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg \(%file:%line\)%n</Pattern>
    </layout>

    <File>server.log</File>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <FileNamePattern>server.%d{yyyy-MM-dd}.log</FileNamePattern>
      <!-- keep 7 days' worth of history -->
      <MaxHistory>7</MaxHistory>

      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <MaxFileSize>50MB</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>

    </rollingPolicy>
  </appender>
Undo
  • 25,519
  • 37
  • 106
  • 129
Mike Q
  • 22,839
  • 20
  • 87
  • 129

12 Answers12

30

None of the other suggestions was appropriate for my situation. I didn't want to use a size-and-time-based solution, because it requires configuring a MaxFileSize, and we are using a strictly time-based policy. Here is how I accomplished rolling the file on startup with a TimeBasedRollingPolicy:

@NoAutoStart
public class StartupTimeBasedTriggeringPolicy<E> 
        extends DefaultTimeBasedFileNamingAndTriggeringPolicy<E> {

    @Override
    public void start() {
        super.start();
        nextCheck = 0L;
        isTriggeringEvent(null, null);
        try {
            tbrp.rollover();
        } catch (RolloverFailure e) {
            //Do nothing
        }
    }

}

The trick is to set the nextCheck time to 0L, so that isTriggeringEvent() will think it's time to roll the log file over. It will thus execute the code necessary to calculate the filename, as well as conveniently resetting the nextCheck time value. The subsequent call to rollover() causes the log file to be rolled. Since this only happens at startup, it is a more optimal solution than the ones that perform a comparison inside isTriggerEvent(). However small that comparison, it still degrades performance slightly when executed on every log message. This also forces the rollover to occur immediately at startup, instead of waiting for the first log event.

The @NoAutoStart annotation is important to prevent Joran from executing the start() method before all the other initialisation is complete. Otherwise, you get a NullPointerException.

Here is the config:

  <!-- Daily rollover appender that also appends timestamp and rolls over on startup -->
  <appender name="startupDailyRolloverAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_FILE}</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${LOG_FILE}.%d{yyyyMMdd}_%d{HHmmss,aux}</fileNamePattern>
      <TimeBasedFileNamingAndTriggeringPolicy class="my.package.StartupTimeBasedTriggeringPolicy" />
    </rollingPolicy>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender> 

Hope this helps!

Betlista
  • 10,327
  • 13
  • 69
  • 110
Dave
  • 400
  • 4
  • 4
  • 1
    I was struggling and this is exactly what I want, thanks! IMO this should be a standard feature and to config is a bit unintuitive – vincentlcy Nov 22 '12 at 11:32
  • 1
    Thanks for the solution - I agree with @vincentlcy and also think this should be a standard feature. – dcompiled Aug 05 '13 at 16:24
  • Just want to add my thanks for a great solution. I want to add this only works (Logback 1.0.13) if you have defined a raw filename: event.txt If you exclude this from your config so that you only get .0,.1,.2,etc indexed files (this is actually recommended by the Logback documentation for Windows platforms to avoid encountering file lock/rename issues) then this solution unfortunately won't actually perform a rollover because in TimeBasedRollingPolicy.rollover() the call to getParentsRawFileProperty() returns null. – Mykro Aug 16 '13 at 01:48
  • This seems to break the `cleanHistoryOnStart`. I used this technique for a short running tool to generate a separate log file for every run, and notice that the configured `maxHistory` is not working. Could this be some race condition? – haridsv Jun 04 '14 at 07:59
  • 2
    Since my requirement is for a command-line tool, I don't need time based triggering at all, so I was able to get it working by switching to `FixedWindowRollingPolicy` and a custom `TriggeringPolicy` class with an `isTriggering` method that returns `true` only once. – haridsv Jun 04 '14 at 10:07
  • 1
    For some reason this causes several log files to be created at startup instead of rolling just one. – Andrew White Oct 16 '14 at 01:30
  • 1
    This solution does not work for me using logback 1.2.3. Configuring `TimeBasedFileNamingAndTriggeringPolicy ` in the XML file causes the class of your choice to be instantiated, but it is later overridden with another instance. `start` is not invoked when annotated with `@NoAutoStart`, ever. Will post my solution. – Dico Jun 16 '19 at 03:01
13

For a solution using already existing components the logback suggests the uniquely named files: http://logback.qos.ch/manual/appenders.html#uniquelyNamed

During the application development phase or in the case of short-lived applications, e.g. batch applications, it is desirable to create a new log file at each new application launch. This is fairly easy to do with the help of the <timestamp> element.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <timestamp key="startTimestamp" datePattern="yyyyMMddHHmmssSSS"/>
    <appender name="File"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg \(%file:%line\)%n</Pattern>
        </layout>

        <file>server-${startTimestamp}.log</file>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>server-${startTimestamp}-%d{yyyy-MM-dd}-%i.log</FileNamePattern>
            <!-- keep 7 days' worth of history -->
            <MaxHistory>7</MaxHistory>

            <TimeBasedFileNamingAndTriggeringPolicy
            class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <MaxFileSize>1KB</MaxFileSize>
            </TimeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
    </appender>
    <root level="DEBUG">
        <appender-ref ref="File" />
    </root>
</configuration>

UPDATED for logback-1.2.1

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <timestamp key="startTimestamp" datePattern="yyyyMMddHHmmssSSS"/>
    <appender name="File"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg \(%file:%line\)%n</Pattern>
        </layout>

        <file>server-${startTimestamp}.log</file>

        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>server-${startTimestamp}-%d{yyyy-MM-dd}-%i.log</fileNamePattern>
            <maxFileSize>10MB</maxFileSize>
            <!-- keep 7 days' worth of history -->
            <maxHistory>7</maxHistory>
            <totalSizeCap>20GB</totalSizeCap>
        </rollingPolicy>
    </appender>
    <root level="DEBUG">
        <appender-ref ref="File" />
    </root>
</configuration>
Betlista
  • 10,327
  • 13
  • 69
  • 110
raisercostin
  • 8,777
  • 5
  • 67
  • 76
  • 3
    The problem with this approach and almost all the approaches here is that logback will not be able to clean up on restart since the `fileNamePattern` has changed. Only while the instance is running will cleanup happen as the timestamp will remain constant. The only solution I can see is to modify TimeBaseArchiveRemover. – Adam Gent Nov 17 '20 at 13:51
7

I found another solution for rolling the logFile once, when the application starts.

I use logback's RollingFileAppender with logback's FixedWindowRollingPolicy and my own implementation of a TriggeringPolicy<E>.

The FixedWindowRollingPolicy gets the fileNamePattern for the new logFile, where %1 is the new number of the file. The maxIndex stands for the maximum number of my "history". More information: FixedWindowRollingPolicy

My implementations TriggeringPolicy returns true for the first time, when isTriggeringEvent(...) gets called. So the WindowRollingPolicy rolls over the logfiles, when the Policy gets called the first time, and afterwards it will not roll over again.

The xml-configuration for the RollingFileAppender:

<configuration>
    ...
    <appender name="FILE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logFile.log</file>

        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <fileNamePattern>logFile.%i.log</fileNamePattern>
            <minIndex>1</minIndex>
            <maxIndex>4</maxIndex>
        </rollingPolicy>

        <triggeringPolicy class="my.classpath.RollOncePerSessionTriggeringPolicy"/>
    </appender>
...
</configuration>

The TriggeringPolicy:

package my.classpath;

import ch.qos.logback.core.rolling.TriggeringPolicyBase;

import java.io.File;

public class RollOncePerSessionTriggeringPolicy<E> extends TriggeringPolicyBase<E> {
    private static boolean doRolling = true;

    @Override
    public boolean isTriggeringEvent(File activeFile, E event) {
        // roll the first time when the event gets called
        if (doRolling) {
            doRolling = false;
            return true;
        }
        return false;
    }
}
Betlista
  • 10,327
  • 13
  • 69
  • 110
duffy356
  • 3,678
  • 3
  • 32
  • 47
7

It works for me, using the following class as timeBasedFileNamingAndTriggeringPolicy :

import java.io.File;
import java.util.concurrent.atomic.AtomicBoolean;

import ch.qos.logback.core.joran.spi.NoAutoStart;
import ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP;

@NoAutoStart
public class Trigger<E> extends SizeAndTimeBasedFNATP<E>
{
    private final AtomicBoolean trigger = new AtomicBoolean();

    public boolean isTriggeringEvent(final File activeFile, final E event) {
        if (trigger.compareAndSet(false, true) && activeFile.length() > 0) {
            String maxFileSize = getMaxFileSize();
            setMaxFileSize("1");
            super.isTriggeringEvent(activeFile, event);
            setMaxFileSize(maxFileSize);
            return true;
        }
        return super.isTriggeringEvent(activeFile, event);
    }
}
proactif
  • 11,331
  • 1
  • 17
  • 11
3

Overriding the isTriggeringEvent() method in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP should work nicely. Just return 'true' the first time isTriggeringEvent() method is called.

Ceki
  • 26,753
  • 7
  • 62
  • 71
2

Ceki's solution doesn't appear to work for me, but seems to be part way there at least.

It blows up because it can't see the rolling policy when starting the TimeBasedFileNamingAndTriggeringPolicyBase. With some hackery I got it to do some logging, and with some more I got it to observe the trigger, but then it broke again because it couldn't resolve one of the filename properties... The package is a logback one so I could get to some of the internals, to replicate some of the logic in SizeAndTimeBasedFNATP#isTriggeringEvent and call computeCurrentPeriodsHighestCounterValue. I think something along those lines might work, just haven't found the magic combination yet. I really hope I'm doing something silly, because otherwise I think it will mean either opening up some of the details for subclassing, or putting this straight into logback as another rolling/triggering policy.

logback.xml: tried various orderings of triggeringPolicy, TimeBasedFileNamingAndTriggeringPolicy inside and outside the rollingPolicy.

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_DIR}/${LOG_FILE_BASE}.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>${LOG_DIR}/${LOG_FILE_BASE}.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
        <MaxHistory>7</MaxHistory>

        <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.RollOnStartupPolicy" />
    </rollingPolicy>

    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>INFO</level>
    </filter>

    <encoder>
        <pattern>%msg%n</pattern>
    </encoder>
</appender>

The trigger policy:

package ch.qos.logback.core.rolling;
public class RollOnStartupPolicy<E> extends SizeAndTimeBasedFNATP<E> {
private final AtomicBoolean firstTime = new AtomicBoolean(true);

    @Override
    public boolean isTriggeringEvent(File activeFile, E event) {
        if (!firstTime.get()) { // fast path
            return false;
        }

        if (firstTime.getAndSet(false)) {
            return true;
        }
        return false;
    }
}

The exception:

java.lang.NullPointerException
at  at ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.start(TimeBasedFileNamingAndTriggeringPolicyBase.java:46)
at  at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP.start(SizeAndTimeBasedFNATP.java:36)
at  at ch.qos.logback.core.joran... [snip joran config]
Betlista
  • 10,327
  • 13
  • 69
  • 110
Joe Kearney
  • 7,397
  • 6
  • 34
  • 45
2

I finally figure it out. I can roll by size, time and start up. Here is solution:

1st create you own class

@NoAutoStart
public class StartupSizeTimeBasedTriggeringPolicy<E> extends SizeAndTimeBasedFNATP<E> {

    private boolean started = false;

    @Override
    public boolean isTriggeringEvent( File activeFile, E event ) {
        if ( !started ) {
            nextCheck = 0L;
            return started = true;
        }

        return super.isTriggeringEvent( activeFile, event );
    };
}

2nd configure logback

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOGS_DIR}/${FILE_NAME}.log</file>
    <encoder>
        <pattern>%d [%thread] %-5level %logger{50} - %msg%n</pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>${LOGS_DIR}/${FILE_NAME}.%d{yyyy-MM-dd}_%d{HHmmss,aux}.%i.log.zip</fileNamePattern>
        <maxHistory>30</maxHistory>
        <TimeBasedFileNamingAndTriggeringPolicy class="my.StartupSizeTimeBasedTriggeringPolicy">
            <MaxFileSize>250MB</MaxFileSize> 
        </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
</appender>
Draken
  • 3,134
  • 13
  • 34
  • 54
Perlos
  • 2,028
  • 6
  • 27
  • 37
2

The API has changed (for example setMaxFileSize no longer exists) and a lot of the stuff above doesn't seem to work, but I have something that is working for me against logback 1.1.8 (the latest at this time).

I wanted to roll on startup and roll on size, but not time. This does it:

public class RollOnStartupAndSizeTriggeringPolicy<E> extends SizeBasedTriggeringPolicy<E> {
    private final AtomicBoolean firstTime = new AtomicBoolean();

    public boolean isTriggeringEvent(final File activeFile, final E event) {
        if (firstTime.compareAndSet(false, true) && activeFile != null && activeFile.length() > 0) {
            return true;
        }
        return super.isTriggeringEvent(activeFile, event);
    }
}

With this you also need a rolling policy. FixedWindowRollingPolicy would probably do, but I don't like it because I want to keep a large number of files and it is very inefficient for that. Something that numbers incrementally up (instead of sliding like FixedWindow) would work, but that doesn't exist. As long as I am writing my own I decided to use time instead of count. I wanted to extend current logback code, but for the time based stuff the rolling and triggering policies are often combined into one class, and there is logs of nesting and circular stuff and fields with no getters, so I found that rather impossible. So I had to do a lot from scratch. I keep it simple and didn't implement features like compression - I'd love to have them but I am just trying to keep it simple.

public class TimestampRollingPolicy<E> extends RollingPolicyBase {
    private final RenameUtil renameUtil = new RenameUtil();
    private String activeFileName;
    private String fileNamePatternStr;
    private FileNamePattern fileNamePattern;

    @Override
    public void start() {
        super.start();
        renameUtil.setContext(this.context);
        activeFileName = getParentsRawFileProperty();
        if (activeFileName == null || activeFileName.isEmpty()) {
            addError("No file set on appender");
        }
        if (fileNamePatternStr == null || fileNamePatternStr.isEmpty()) {
            addError("fileNamePattern not set");
            fileNamePattern = null;
        } else {
            fileNamePattern = new FileNamePattern(fileNamePatternStr, this.context);
        }
        addInfo("Will use the pattern " + fileNamePattern + " to archive files");
    }

    @Override
    public void rollover() throws RolloverFailure {
        File f = new File(activeFileName);
        if (!f.exists()) {
            return;
        }
        if (f.length() <= 0) {
            return;
        }
        try {
            String archiveFileName = fileNamePattern.convert(new Date(f.lastModified()));
            renameUtil.rename(activeFileName, archiveFileName);
        } catch (RolloverFailure e) {
            throw e;
        } catch (Exception e) {
            throw new RolloverFailure(e.toString(), e);
        }
    }

    @Override
    public String getActiveFileName() {
        return activeFileName;
    }

    public void setFileNamePattern(String fnp) {
        fileNamePatternStr = fnp;
    }
}

And then config looks like

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
  <encoder>
    <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
  </encoder>
  <file>/tmp/monitor.log</file>
  <rollingPolicy class="my.log.TimestampRollingPolicy">
    <fileNamePattern>/tmp/monitor.%d{yyyyMMdd-HHmmss}.log</fileNamePattern>
  </rollingPolicy>
  <triggeringPolicy class="my.log.RollOnStartupAndSizeTriggeringPolicy">
    <maxFileSize>1gb</maxFileSize>
  </triggeringPolicy>
</appender>

if you're frustrated this is not solved natively, vote for it at

http://jira.qos.ch/browse/LOGBACK-204

http://jira.qos.ch/browse/LOGBACK-215

(it's been years, and to me this is absolutely critical functionality, although I know many other frameworks fail at it also)

dlipofsky
  • 289
  • 1
  • 4
  • 18
1

I got the following to work (combining ideas from previous answers). Note I was dealing with size-based files, not time-based, but I am guessing the same solution works.

public class StartupSizeBasedTriggeringPolicy<E> extends ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy<E> {

private final AtomicReference<Boolean> isFirstTime = new AtomicReference<Boolean>(true);

@Override
public boolean isTriggeringEvent(final File activeFile, final E event) {

    //this method appears to have side-effects so always call
    boolean result = super.isTriggeringEvent(activeFile, event);

    return isFirstTime.compareAndSet(true, false) || result;
}

}

djechlin
  • 59,258
  • 35
  • 162
  • 290
1

Create your own subclass of ch.qos.logback.core.rolling.TimeBasedRollingPolicy and override its start

public class MyPolicy
    extends ch.qos.logback.core.rolling.TimeBasedRollingPolicy
{

    public void start ( )
    {
        super.start( );
        rollover( );
    }
}
Alexander Pogrebnyak
  • 44,836
  • 10
  • 105
  • 121
  • Sadly this doesn't work because the triggering policy returns null from getElapsedPeriodsFileName() which then blows up the rollover(). – Mike Q Mar 22 '10 at 14:13
1

This solution really works, thanks a lot. However, there is one annoying glitch: when you run the program first time, the log is rolled right after it is created, when it is empty or almost empty. So I suggest a fix: check whether the log file exists and is not empty at the time the method is called. Also, one more cosmetic fix: rename the "started" variable, because it is hiding the inherited member with the same name.

@NoAutoStart
public class StartupSizeTimeBasedTriggeringPolicy<E> extends     SizeAndTimeBasedFNATP<E> {

    private boolean policyStarted;

    @Override
    public boolean isTriggeringEvent(File activeFile, E event) {
        if (!policyStarted) {
            policyStarted = true;
            if (activeFile.exists() && activeFile.length() > 0) {
                nextCheck = 0L;
                return true;
            }
        }
        return super.isTriggeringEvent(activeFile, event);
    }
}

Also, I believe it works properly with logback version 1.1.4-SNAPSHOT (I got the source and compiled it myself), but it does not fully work with 1.1.3 release. With 1.1.3, it names the files properly with the specified time zone, but rollover still happens at default time zone midnight.

  • I see the version 1.1.7 is out now, but this feature is still not there. Are there any plans to add it to the standard package? It looks to be pretty simple. Obviously I am still using my own StartupSizeTimeBasedTriggeringPolicy, but it is annoying keep such a small addition around. – Leonid Ilyevsky Apr 07 '16 at 18:16
0

I found a way to do this that that does not require injecting a custom class into the configuration. It leverages a test API to trick the appender into thinking it is time to roll the file.

This example assuems that you have a RollingFileAppender configured in your XML named ROLLING that is set for daily rollover with a SizeAndTimeBasedRollingPolicy:

<appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>./logs/${app-name}.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>./logs/${app-name}-%d{yyyy-MM-dd}-%i.log</fileNamePattern>
        <maxFileSize>100MB</maxFileSize>
        <maxHistory>5</maxHistory>
        <totalSizeCap>5GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>${LOG_PATTERN}</pattern>
    </encoder>
</appender>

The code below will find the rolling policy and trigger the rollover. Note that this will globally override the appender's clock for a short time so don't call it when any other threads could potentially write messages.

// get the root logger
ch.qos.logback.classic.Logger _logger = (ch.qos.logback.classic.Logger)LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);

// get the triggering policy from the rolling appender
RollingFileAppender<?> _appender = (RollingFileAppender<?>)_logger.getAppender("ROLLING");
SizeAndTimeBasedRollingPolicy<?> _policy = (SizeAndTimeBasedRollingPolicy<?>)_appender.getRollingPolicy();
TimeBasedFileNamingAndTriggeringPolicy<?> _trigger = _policy.getTimeBasedFileNamingAndTriggeringPolicy();

// trick the appender into thinking it is time to rollover
_trigger.setCurrentTime(System.currentTimeMillis() + 24*60*60*1000);

// this message will trigger the rollover
LOG.info("Initializing log for app: {}", _appName);

// turn off fake time
_trigger.setCurrentTime(0);
Chad Juliano
  • 1,195
  • 9
  • 4