logback-RollingFileAppender源码分析（关于缓冲和性能）

打印性能是日志打印框架的核心关注点之一，从logback的日志打印流程看看其性能如何？

本文基于logback1.2.3版本，以下配置（1.2.0版本后，logback提供了 SizeAndTimeBasedRollingPolicy 策略，可同时基于时间+空间两个维度控制日志文件的滚动）

形如下面这句debug日志的打印，调用栈是这样的

LOGGER.debug("msg {}", msg);

Appender接口&实现类

Appender接口作为logback的核心三大件（Logger、Appender、Layout）之一，所有的日志打印Appender类都必须遵循Appender接口的规范。

关于性能的代码

根据上文的调用栈，可以看到Logger.debug()最终调用了OutputStreamAppender.subAppend()，其中核心代码就两句：encode和writeBytes

/**
 * Actual writing occurs here.
 * <p>
 * Most subclasses of <code>WriterAppender</code> will need to override this
 * method.
 * 
 * @since 0.9.0
 */
protected void subAppend(E event) {
    if (!isStarted()) {
        return;
    }
    try {
        // this step avoids LBCLASSIC-139
        if (event instanceof DeferredProcessingAware) {
            ((DeferredProcessingAware) event).prepareForDeferredProcessing();
        }
        // the synchronization prevents the OutputStream from being closed while we
        // are writing. It also prevents multiple threads from entering the same
        // converter. Converters assume that they are in a synchronized block.
        // lock.lock();

        byte[] byteArray = this.encoder.encode(event);
        writeBytes(byteArray);	// 写入encode的日志内容

    } catch (IOException ioe) {
        // as soon as an exception occurs, move to non-started state
        // and add a single ErrorStatus to the SM.
        this.started = false;
        addStatus(new ErrorStatus("IO failure in appender", this, ioe));
    }
}

官方注释：OutputStream的输出需要同步，同时为了防止多个线程同时使用，converter对event对象向输出流数据的转换需要得到串行化保障。

再看下writeBytes()的实现，可以看到所有的日志打印线程到这个方法中需要阻塞、同步执行write方法。

// OutputStreamAppender line: 54，默认立即刷新=true
boolean immediateFlush = true;

/**
 * All synchronization in this class is done via the lock object.
 */
protected final ReentrantLock lock = new ReentrantLock(false);


private void writeBytes(byte[] byteArray) throws IOException {
    if(byteArray == null || byteArray.length == 0)
        return;
    
    lock.lock();	// 重入锁
    try {
        this.outputStream.write(byteArray);
        if (immediateFlush) {	// 是否立即刷新缓冲内容
            this.outputStream.flush();
        }
    } finally {
        lock.unlock();
    }
}

其次需要关注immediateFlush变量，因为我们没有配置，默认是开启立即刷新。
官方注释：1.2.0版本后，支持在logback.xml的<appender>节点设置immediateFlush属性，如果不设置，默认值是true，即每次日志输出流缓冲队列都将被刷新。

同时提醒，开启立即刷新，虽然比较“安全”，但将降低系统日志输出的整体性能。

/**
 * Sets the immediateFlush option. The default value for immediateFlush is 'true'. If set to true,
 * the doEncode() method will immediately flush the underlying OutputStream. Although immediate flushing
 * is safer, it also significantly degrades logging throughput.
 *
 * @since 1.0.3
 */
public void setImmediateFlush(boolean immediateFlush) {
    addWarn("As of version 1.2.0 \"immediateFlush\" property should be set within the enclosing Appender.");
    addWarn("Please move \"immediateFlush\" property into the enclosing appender.");
    this.immediateFlush = immediateFlush;
}

为了确认缓冲是真实存在的，就要看看这里this.outputStream的具体实现类：ch.qos.logback.core.recovery.ResilientFileOutputStream，其中组合了一个os（BufferedOutputStream）对象

// FileAppender中定义了缓冲区大小，默认是 8192 字节（8kb）
public static final long DEFAULT_BUFFER_SIZE = 8192;
private FileSize bufferSize = new FileSize(DEFAULT_BUFFER_SIZE);

// 构造方法，组合BufferedOutputStream
public ResilientFileOutputStream(File file, boolean append, long bufferSize) throws FileNotFoundException {
    this.file = file;
    fos = new FileOutputStream(file, append);
    this.os = new BufferedOutputStream(fos, (int) bufferSize);
    this.presumedClean = true;
}

// 抽象父类默认方法，调用os.write
public void write(byte b[], int off, int len) {
    if (isPresumedInError()) {
        if (!recoveryCoordinator.isTooSoon()) {
            attemptRecovery();
        }
        return; // return regardless of the success of the recovery attempt
    }

    try {
        os.write(b, off, len);
        postSuccessfulWrite();
    } catch (IOException e) {
        postIOFailure(e);
    }
}

至此我们已经知道 RollingFileAppender 的日志打印最终会调用BufferedOutpuStream.write方法，那么说明日志打印存在缓冲，且缓冲队列的默认是8kb。

在FileAppender有bufferSize字段，找到了其setter方法，没有其他类调用，猜测是可以通过反射配置的。

public void setBufferSize(FileSize bufferSize) {
    addInfo("Setting bufferSize to ["+bufferSize.toString()+"]");
    this.bufferSize = bufferSize;
}

那我们能显示的设置FileAppender#bufferSize大小吗？我做了以下尝试：
1.Logback官网查找Appender目录中的bufferSize设置，无果
2.项目中直接配置 <bufferSize>1MB</bufferSize> 没有起作用
3.stackoverflow搜索无果

总结

1.对于同步的RollingFileAppender而言，多线程的log appender打印是有意义的，因为只会在调用BufferedOutpuStream.write方法时加锁同步，encode等方法也是比较耗时的，多线程可以增加系统吞吐量;对于 AsyncAppender而言，增加日志消费线程则意义不大， 这应该也是AsyncAppender中只提供了一个worker守护线程的原因。

2.使用 RollingFileAppender 时，logback提供给我们<ImmediateFlush>标签使用，设置为false时可获得更高的logging吞吐量。

3.FileAppender中的bufferSize字段无法从外部设置，默认大小是8kb，在ImmediateFlush=false的情况下满8kb刷新一次缓冲区。