Course – LS – All

Get started with Spring and Spring Boot, through the Learn Spring course:

>> CHECK OUT THE COURSE

1. Overview

While log files often convey useful information, they naturally grow bigger over time. If allowed to grow indefinitely, their size could become a problem.

Logging libraries address this problem using rolling file appenders, which automatically “roll” or archive the current log file, and resume logging in a new file when certain predefined conditions occur, thereby preventing unwanted downtime.

In this tutorial, we’ll learn how to configure rolling file appenders in some of the most widely used logging libraries: Log4j, Log4j2, and Slf4j.

We’ll demonstrate how to roll log files based on size, date/time, and a combination of size and date/time. We’ll also explore how to configure each library to automatically compress, and later delete, the old log files, saving us from writing tedious housekeeping code.

2. Our Sample Application

Let’s start with an example application that logs some messages. This code is based on Log4j, but we can easily modify it to work with Log4j2 or Slf4j:

import org.apache.log4j.Logger;

public class Log4jRollingExample {

    private static Logger logger = Logger.getLogger(Log4jRollingExample.class);

    public static void main(String[] args) throws InterruptedException {
        for(int i = 0; i < 2000; i++) {
            logger.info("This is the " + i + " time I say 'Hello World'.");
            Thread.sleep(100);
        }
    }
}

The application is quite naive; it writes some messages in a loop, with a short delay between iterations. With 2,000 loops to run, and a pause of 100 ms in each loop, the application should take a little more than three minutes to complete.

We’ll use this sample to demonstrate several features of different kinds of rolling file appenders.

3. Rolling File Appenders in Log4j

3.1. Maven Dependencies

First, to use Log4j in our application, we’ll add this dependency to our project’s pom.xml file:

<dependency>
    <groupId>log4j</groupId>
    <artifactId>log4j</artifactId>
    <version>1.2.17</version>
</dependency>

For the additional appenders provided by apache-log-extras that we’ll use in the next examples, we’ll add the following dependency, being sure to use the same version that we declared for Log4j in order to ensure full compatibility:

<dependency>
    <groupId>log4j</groupId>
    <artifactId>apache-log4j-extras</artifactId>
    <version>1.2.17</version>
</dependency>

We can find the latest release of Log4j and Apache Log4j Extras on Maven Central.

3.2. Rolling Based on File Size

In Log4j, as in other logging libraries, file rolling is delegated to the appender. Let’s look at the configuration for a rolling file appender in Log4j that rolls based on file size:

<appender name="roll-by-size" class="org.apache.log4j.RollingFileAppender">
    <param name="file" value="target/log4j/roll-by-size/app.log" />
    <param name="MaxFileSize" value="5KB" />
    <param name="MaxBackupIndex" value="2" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %m%n" />
        </layout>
</appender>

Here we configured Log4j to roll the log file when its size reaches 5KB using the MaxFileSize parameter. We also instructed Log4j to keep a maximum of two rolled log files using the MaxBackupIndex parameter.

When we run our sample application, we obtain the following files:

27/11/2016  10:28    138 app.log
27/11/2016  10:28  5.281 app.log.1
27/11/2016  10:28  5.281 app.log.2

So what happened? Log4j started writing to the app.log file. When the file size exceeded the 5KB limit, Log4j moved app.log to app.log.1, created a new empty app.log, and continued writing new log messages to app.log.

Then, after the new app.log exceeded the 5KB limit, this rolling process was repeated. This time, app.log.1 was moved to app.log.2, making room for another new empty app.log.

This rolling process was repeated several times during the run, but since we configured our appender to keep two rolled files at most, there isn’t a file called app.log.3.

So we solved one of the original problems because now we can set up a limit on the size of the produced log files.

When we check the first line of app.log.2, it contains the message related to the 700th iteration, meaning all previous log messages were lost:

2016-11-27 10:28:34 INFO  This is the 700 time I say 'Hello World'.

Now let’s see if we can devise a setup better suited to a production environment, where losing log messages isn’t considered the best approach.

To do this, we’ll use other more powerful, flexible, and configurable Log4j appenders that are shipped in a dedicated package, called apache-log4j-extras.

The appenders contained in this artifact offer lots of options to fine tune the log rolling, and they introduce the distinct concepts of triggering policy and rolling policy. The triggering policy describes when a roll should occur, while the rolling policy describes how the rolling should be carried out. These two concepts are key to rolling log files, and other libraries use them more or less explicitly as well.

3.3. Rolling With Automatic Compression

Let’s go back to the Log4j example and improve our setup by adding the automatic compression of the rolled files to save space:

<appender name="roll-by-size" class="org.apache.log4j.rolling.RollingFileAppender">
    <rollingPolicy class="org.apache.log4j.rolling.FixedWindowRollingPolicy">
        <param name="ActiveFileName" value="target/log4j/roll-by-size/app.log" />
        <param name="FileNamePattern" value="target/log4j/roll-by-size/app.%i.log.gz" />
    <param name="MinIndex" value="7" />
    <param name="MaxIndex" value="17" /> 
    </rollingPolicy>
    <triggeringPolicy class="org.apache.log4j.rolling.SizeBasedTriggeringPolicy">
        <param name="MaxFileSize" value="5120" />
    </triggeringPolicy>
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %m%n" />
    </layout>
</appender>

With the triggering policy element, we stated that the roll should occur when the log exceeds the size of 5,120 bytes.

Within the rolling policy tag, the ActiveFileName parameter states the path of the main log files containing the latest messages, and the FileNamePattern parameter specifies a template describing what the path of the rolled files should be. Let’s note that this is indeed a pattern because the special placeholder %i will be replaced with the index of the rolled file.

Let’s also note that FileNamePattern ends with a “.gz” extension. Whenever we use an extension associated with a supported compressed format, we’ll have the old rolled files compressed without any extra effort from our side.

Now when we run the application, we obtain a different set of log files:

03/12/2016 19:24 88 app.1.log.gz
...
03/12/2016 19:26 88 app.2.log.gz
03/12/2016 19:26 88 app.3.log.gz
03/12/2016 19:27 70 app.current.log

The file app.current.log is where the last logs occurred. The previous logs are rolled and compressed when their size reaches the set limit.

3.4. Rolling Based on Date and Time

In other scenarios, we may want to configure Log4j to roll the files based on the date and time of the log messages, instead of the size of the file. In a web application, for instance, we may want to have all the log messages issued in one day in the same log file.

To do this, we can use the TimeBasedRollingPolicy. With this policy, it’s mandatory to specify a template for the path of the log file that contains a time-related placeholder. Each time a log message is issued, the appender verifies what the resulting log path will be. If it differs from the last used path, then a roll will occur. Here’s a quick example that configures such an appender:

<appender name="roll-by-time"
    class="org.apache.log4j.rolling.RollingFileAppender">
    <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
        <param name="FileNamePattern" value="target/log4j/roll-by-time/app.%d{HH-mm}.log.gz" />
    </rollingPolicy>
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p - %m%n" />
    </layout>
</appender>

3.5. Rolling Based on Size and Time

Combining the SizeBasedTriggeringPolicy and the TimeBasedRollingPolicy, we can obtain an appender that rolls based on date/time, and when the size of the file reaches the set limit, it rolls based on size too:

<appender name="roll-by-time-and-size" class="org.apache.log4j.rolling.RollingFileAppender">
    <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
        <param name="ActiveFileName" value="log4j/roll-by-time-and-size/app.log" />
        <param name="FileNamePattern" value="log4j/roll-by-time-and-size/app.%d{HH-mm}.%i.log.gz" />
    </rollingPolicy>
    <triggeringPolicy
        class="org.apache.log4j.rolling.SizeBasedTriggeringPolicy">
        <param name="MaxFileSize" value="100" />
    </triggeringPolicy>
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p - %m%n" />
    </layout>
</appender>

When we run our application with this setup, we obtain the following log files:

03/12/2016 19:25 234 app.19-25.1481393432120.log.gz
03/12/2016 19:25 234 app.19-25.1481393438939.log.gz
03/12/2016 19:26 244 app.19-26.1481393441940.log.gz
03/12/2016 19:26 240 app.19-26.1481393449152.log.gz
03/12/2016 19:26 3.528 app.19-26.1481393470902.log

The file app.19-26.1481393470902.log is where the current logging takes place. As we can see, all the logs in the interval between 19:25 and 19:26 are stored in multiple compressed log files with names starting with “app.19-25″. The “%i” placeholder is replaced by an ever increasing number.

4. Rolling File Appenders in Log4j2

4.1. Maven Dependencies

To use Log4j2 as our preferred logging library, we need to update our project’s POM with the following dependency:

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.7</version>
</dependency>

As usual, we can find the latest version on Maven Central.

4.2. Rolling Based on File Size

Let’s change our example application to use the Log4j2 logging libraries. We’ll set up file rolling based on the size of the log file in the log4j2.xml configuration file:

<RollingFile 
  name="roll-by-size" 
  fileName="target/log4j2/roll-by-size/app.log"
  filePattern="target/log4j2/roll-by-size/app.%i.log.gz" 
  ignoreExceptions="false">
    <PatternLayout>
        <Pattern>%d{yyyy-MM-dd HH:mm:ss} %p %m%n</Pattern>
    </PatternLayout>
    <Policies>
        <OnStartupTriggeringPolicy />
        <SizeBasedTriggeringPolicy size="5 KB" />
    </Policies>
</RollingFile>

In the Policies tag, we specified all the triggering policies we want to apply. OnStartupTriggeringPolicy triggers a roll every time the application starts, which can be useful for stand-alone applications. We also specified a SizeBasedTriggeringPolicy, stating that a roll should occur whenever the log file reaches 5KB.

4.3. Rolling Based on Date and Time

Using the policies offered by Log4j2, we’ll set up an appender to roll and compress the log file based on time:

<RollingFile name="roll-by-time" 
  fileName="target/log4j2/roll-by-time/app.log"
  filePattern="target/log4j2/roll-by-time/app.%d{MM-dd-yyyy-HH-mm}.log.gz"
  ignoreExceptions="false">
    <PatternLayout>
        <Pattern>%d{yyyy-MM-dd HH:mm:ss} %p %m%n</Pattern>
    </PatternLayout>
    <TimeBasedTriggeringPolicy />
</RollingFile>

The key here is the TimeBasedTriggeringPolicy, which allows us to use time-related placeholders in the template of the rolled file names. Note that, since we need only a single triggering policy, we don’t have to use the Policies tag, like in the previous example.

4.4. Rolling Based on Size and Time

As previously described, a more compelling scenario is to roll and compress log files based on both time and size. Here’s an example of how we can set up Log4j2 for this task:

<RollingFile name="roll-by-time-and-size" 
  fileName="target/log4j2/roll-by-time-and-size/app.log"
  filePattern="target/log4j2/roll-by-time-and-size/app.%d{MM-dd-yyyy-HH-mm}.%i.log.gz" 
  ignoreExceptions="false">
    <PatternLayout>
        <Pattern>%d{yyyy-MM-dd HH:mm:ss} %p %m%n</Pattern>
    </PatternLayout>
    <Policies>
        <OnStartupTriggeringPolicy />
        <SizeBasedTriggeringPolicy size="5 KB" />
        <TimeBasedTriggeringPolicy />
    </Policies>
    <DefaultRolloverStrategy>
        <Delete basePath="${baseDir}" maxDepth="2">
            <IfFileName glob="target/log4j2/roll-by-time-and-size/app.*.log.gz" />
            <IfLastModified age="20d" />
        </Delete>
    </DefaultRolloverStrategy>
</RollingFile>

With this configuration, we stated that a roll should occur based on time and size. The appender is able to understand what time interval we’re referring to because of the pattern used for the file name, “app.%d{MM-dd-yyyy-HH-mm}.%i.log.gz”, which implicitly sets a roll to occur every minute and compress the rolled file.

We also added a DefaultRolloverStrategy to delete old rolled files matching certain criteria. We configured ours to delete files that match the given pattern when they’re older than 20 days.

4.5. Maven Dependencies

To use Log4j2 as our preferred logging library, we need to update our project’s POM with the following dependency:

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.7</version>
</dependency>

As usual, we can find the latest version on Maven Central.

5. Rolling File Appenders in Slf4j

5.1. Maven Dependencies

When we want to use Slf4j2 with a Logback backend as our logging library, we’ll add this dependency to our pom.xml:

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.6</version>
</dependency>

As usual, we can find the latest version on Maven Central.

5.2. Rolling Based on File Size

Now let’s see how to use Slf4j with its default back-end Logback. We’ll set up file rolling in the configuration file, logback.xml, which is placed in the application’s classpath:

<appender name="roll-by-size" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>target/slf4j/roll-by-size/app.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
        <fileNamePattern>target/slf4j/roll-by-size/app.%i.log.zip</fileNamePattern>
        <minIndex>1</minIndex>
        <maxIndex>3</maxIndex>
        <totalSizeCap>1MB</totalSizeCap>
    </rollingPolicy>
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
       <maxFileSize>5KB</maxFileSize>
    </triggeringPolicy>
    <encoder>
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
    </encoder>
</appender>

Again we encounter the concept of rolling policy. The basic mechanism is the same as that used by Log4j and Log4j2. The FixedWindowRollingPolicy allows us to use an index placeholder in the name pattern of the rolled file.

When the size of the log file grows over the configured limit, a new file is allocated. The old content is stored as the first file on the list, shifting the existing ones one place further.

5.3. Rolling Based on Time

In Slf4j, we can roll a log file based on time using the provided TimeBasedRollingPolicy. This policy allows us to specify the template name of the rolling file using time and date related placeholders:

<appender name="roll-by-time" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>target/slf4j/roll-by-time/app.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>target/slf4j/roll-by-time/app.%d{yyyy-MM-dd-HH-mm}.log.zip
        </fileNamePattern>
        <maxHistory>20</maxHistory>
        <totalSizeCap>1MB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss} %p %m%n</pattern>
    </encoder>
</appender>

5.4. Rolling Based on Size and Time

If we need to roll a file based on both time and size, we can use the provided SizeAndTimeBasedRollingPolicy. When using this policy, we must specify both a time-related placeholder and an index placeholder.

Each time the size of the log file for a certain time interval grows beyond the configured size limit, another log file with the same value for the time-related placeholder, but with an incremented index, is created:

<appender name="roll-by-time-and-size"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>target/slf4j/roll-by-time-and-size/app.log</file>
    <rollingPolicy
      class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>
            target/slf4j/roll-by-time-and-size/app.%d{yyyy-MM-dd-mm}.%i.log.zip
        </fileNamePattern>
        <maxFileSize>5KB</maxFileSize>
        <maxHistory>20</maxHistory>
        <totalSizeCap>1MB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss} %p %m%n</pattern>
    </encoder>
</appender>

6. Conclusion

In this article, we learned that leveraging a logging library to roll the files saves us the burden of managing the log files manually. Instead, we can focus on the development of our business logic. Rolling file appenders are a valuable tool that should be in every developer’s toolbox.

As usual, the sources are available on GitHub, where the example applications presented in this article are configured to log using several different rolling setups in order to allow us to find a good base configuration to be further tweaked to suit our needs.

Course – LS – All

Get started with Spring and Spring Boot, through the Learn Spring course:

>> CHECK OUT THE COURSE
res – REST with Spring (eBook) (everywhere)
Comments are closed on this article!