Logback源码赏析-日志按时间滚动（切割）

引言

用过Logback的同学们大多都知道Logback日志框架可以自动按照某个时间点切割日志的功能。但了解其中工作原理的同学可能并不是很多。楼主今天就带领各位了解一下其中的核心源码。本文的示例引用了Logback 1.1.7版的源码。

举个实际的例子，如果希望某一个Appender按天切割日志，那么我们需要类似如下的配置：

    <appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/service-log.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} %level [%class:%line] - %m%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <fileNamePattern>logs/service-log.%d{yyyy-MM-dd}.log.zip</fileNamePattern>
        </rollingPolicy>
    </appender>

如果需要日志切割功能，首先要选用RollingFileAppender这种Appender，之后要配置TimeBasedRollingPolicy作为该Appender的滚动策略。

源码解读

业务代码在调用Logback的记录日志的方法时，Logger类会调用ch.qos.logback.core.Appender#doAppend方法。Appender的doAppend就是Appender记录日志功能的入口。
我们先来看一下RollingFileAppender的继承关系

看起来貌似有些晕。没关系，doAppend方法经过几层之后会调到ch.qos.logback.core.rolling.RollingFileAppender#subAppend 这个方法。而跟日志切割相关的逻辑就在这里面。因此从doAppend到subAppend之间的调用链路我们在此略过不提，而是从subAppend这个方法切入。

    /**
    * This method differentiates RollingFileAppender from its super class.
    */
    @Override
    protected void subAppend(E event) {
        // The roll-over check must precede actual writing. This is the
        // only correct behavior for time driven triggers.

        // We need to synchronize on triggeringPolicy so that only one rollover
        // occurs at a time
        synchronized (triggeringPolicy) {
            if (triggeringPolicy.isTriggeringEvent(currentlyActiveFile, event)) {
                rollover();
            }
        }

        super.subAppend(event);
    }

第一步判断是否需要切割日志，需要就执行滚动操作。第二步执行父类中的写日志操作。
TimeBasedRollingPolicy中实现了按照时间切割日志的策略。

ch.qos.logback.core.rolling.TimeBasedRollingPolicy#isTriggeringEvent方法

    public boolean isTriggeringEvent(File activeFile, final E event) {
        return timeBasedFileNamingAndTriggeringPolicy.isTriggeringEvent(activeFile, event);
    }

这个timeBasedFileNamingAndTriggeringPolicy是DefaultTimeBasedFileNamingAndTriggeringPolicy类的实例。
ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy#isTriggeringEvent方法

    public boolean isTriggeringEvent(File activeFile, final E event) {
        long time = getCurrentTime();//获得当前时间
        if (time >= nextCheck) {//如果当前时间大于下一次滚动时间点，则执行如下逻辑
            Date dateOfElapsedPeriod = dateInCurrentPeriod;//之前时间段的开始时间
            addInfo("Elapsed period: " + dateOfElapsedPeriod);
            elapsedPeriodsFileName = tbrp.fileNamePatternWithoutCompSuffix.convert(dateOfElapsedPeriod);//算出之前一个时间段的文件名字（用于将当前文件重命名）
            setDateInCurrentPeriod(time);//将当前时间保存起来，作为下次滚动时的上一次滚动的时间点
            computeNextCheck();//计算下次滚动时间
            return true;
        } else {
            return false;
        }
    }

ch.qos.logback.core.rolling.helper.FileNamePattern类的convert方法根据上次滚动执行的开始时间计算出了本次操作的文件名。

计算下次滚动执行的时间。

    protected void computeNextCheck() {
        nextCheck = rc.getNextTriggeringDate(dateInCurrentPeriod).getTime();
    }

上述方法调用了ch.qos.logback.core.rolling.helper.RollingCalendar#getNextTriggeringDate
RollingCalendar这个工具类是用来计算每一次触发滚动操作的时间的。RollingCalendar的periodicityType成员变量就是滚动时间类型枚举，可以是天、小时、分钟等等时间单位。这个值并不是在logback.xml文件中配置的，而是拿到日期格式“%d{yyyy-MM-dd}”之后自动计算出来的。计算原理就是用日期格式创建一个SimpleDateFormat然后按照时间单位从小到大（必须是从小到大）的顺序依次试验。每次试验的方法就是用SimpleDateFormat生成两个时间，这两个时间相差1倍的该时间单位的时间，然后将两个时间转换成字符串进行对比，如果这两个字符串不相等就说明该日期格式对应的时间单位是当前试验的时间单位。

看完判断是否触发滚动的逻辑之后我们把视线转回ch.qos.logback.core.rolling.RollingFileAppender#subAppend方法。如果到了应该切割日志的时间则会调用rollover方法。

    /**
     * Implemented by delegating most of the rollover work to a rolling policy.
     */
    public void rollover() {
        lock.lock();
        try {
            // Note: This method needs to be synchronized because it needs exclusive
            // access while it closes and then re-opens the target file.
            //
            // make sure to close the hereto active log file! Renaming under windows
            // does not work for open files.
            this.closeOutputStream();
            attemptRollover();
            attemptOpenFile();
        } finally {
            lock.unlock();
        }
    }

滚动方法里面自己控制了线程同步逻辑，保证多个线程只有一个会执行滚动操作。attemptRollover方法调用了ch.qos.logback.core.rolling.TimeBasedRollingPolicy#rollover方法

    public void rollover() throws RolloverFailure {

        // when rollover is called the elapsed period's file has
        // been already closed. This is a working assumption of this method.

        String elapsedPeriodsFileName = timeBasedFileNamingAndTriggeringPolicy.getElapsedPeriodsFileName();//获得上个周期的文件名字

        String elapsedPeriodStem = FileFilterUtil.afterLastSlash(elapsedPeriodsFileName);

        if (compressionMode == CompressionMode.NONE) {
            if (getParentsRawFileProperty() != null) {
                renameUtil.rename(getParentsRawFileProperty(), elapsedPeriodsFileName);//将当前文件重命名
            } // else { nothing to do if CompressionMode == NONE and parentsRawFileProperty == null }
        } else {
            if (getParentsRawFileProperty() == null) {
                compressionFuture = compressor.asyncCompress(elapsedPeriodsFileName, elapsedPeriodsFileName, elapsedPeriodStem);//执行异步压缩，里面用到了java语言的Future
            } else {
                compressionFuture = renameRawAndAsyncCompress(elapsedPeriodsFileName, elapsedPeriodStem);
            }
        }

        if (archiveRemover != null) {
            Date now = new Date(timeBasedFileNamingAndTriggeringPolicy.getCurrentTime());
            cleanUpFuture = archiveRemover.cleanAsynchronously(now);//执行清理，清楚过期日志
        }
    }

其中有一些工具类可以供我们在业务开发过程中使用，比如ch.qos.logback.core.rolling.helper.RenameUtil#rename可以将文件重命名，拿来用就可以不用重复造轮子了。

    private void attemptOpenFile() {
        try {
            // update the currentlyActiveFile LOGBACK-64
            currentlyActiveFile = new File(rollingPolicy.getActiveFileName());//创建一个当前的文件，新的日志输出到这个文件。因此日志的滚动操作就完成了

            // This will also close the file. This is OK since multiple close operations are safe.
            this.openFile(rollingPolicy.getActiveFileName());
        } catch (IOException e) {
            addError("setFile(" + fileName + ", false) call failed.", e);
        }
    }

结束语

由于篇幅关系，一些细节没有展开。欢迎大家拍砖。