log4j2用asyncRoot配置异步日志是如何使用disruptor

Posted 2021-12-29 simoncook

用asyncRoot配置对应的对接disruptor类是AsyncLoggerConfigDisruptor,用Log4jContextSelector启动参数配置全局异步的对应的对接disruptor类是AsyncLoggerDisruptor。下面分析的是AsyncLoggerConfigDisruptor

disruptor的创建与启动需要的部件实现

AsyncLoggerConfigDisruptor.start方法用来创建并启动disruptor实例
创建disruptor需要EventFactory，ringBuffer的大小，ThreadFactory，ProducerType，等待策略waitStrategy
创建后需要设置ExceptionHandler，设置EventHandler。
发布(生产)事件的translator。

EventFactory

分是否可变(mutable字段)场景对应两个不同的EventFactory。
不可变的factory的逻辑是：

@Override
public Log4jEventWrapper newInstance() 
    return new Log4jEventWrapper();

可变的factory逻辑是：

public Log4jEventWrapper newInstance() 
    return new Log4jEventWrapper(new MutableLogEvent());

会在 Log4jEventWrapper的构造函数中传入MutableLogEvent实例。

ringBuffer的大小

是根据AsyncLoggerConfig.RingBufferSize配置值算出来的。
这个配置项的值最小不能小于128，默认值分两种情况进行设定：如果启用了ENABLE_THREADLOCALS(优化GC的一个配置项)，那么默认值是4 * 1024，否则是256 * 1024。
这个配置是通过System properties指定，同样存在不同版本，配置项名称不一致的情况，log4j2.asyncLoggerRingBufferSize (AsyncLogger.RingBufferSize)。详细可以参见这里

ThreadFactory

主要是定制线程名：
线程名格式是："AsyncLoggerConfig-" + FACTORY_NUMBER(自增) + "-" + threadFactoryName + "-" + THREAD_NUMBER(自增)
默认的实际示例是： Log4j2-TF-1-AsyncLoggerConfig--1，跟上面的有些差异，上面的分析错了吗？？

ProducerType

多生产者

等待策略waitStrategy

默认是10ms的TimeoutBlockingWaitStrategy。 支持可配置SleepingWaitStrategy、YieldingWaitStrategy、BlockingWaitStrategy、BusySpinWaitStrategy、TimeoutBlockingWaitStrategy。
这个配置是通过System properties指定，同样存在不同版本，配置项名称不一致的情况，log4j2.asyncLoggerWaitStrategy (AsyncLogger.WaitStrategy)。

ExceptionHandler

可以配置，配置项名称是AsyncLoggerConfig.ExceptionHandler，默认是用AsyncLoggerConfigDefaultExceptionHandler，打印: AsyncLogger error handling event seq=..., value=...,并打出异常栈。

EventHandler

此处使用了 Log4jEventWrapperHandler RingBufferLogEventHandler，是disruptor的SequenceReportingEventHandler实现。

/**
 * EventHandler performs the work in a separate thread.
 */
private static class Log4jEventWrapperHandler implements SequenceReportingEventHandler<Log4jEventWrapper> 
    private static final int NOTIFY_PROGRESS_THRESHOLD = 50;
    private Sequence sequenceCallback;
    private int counter;

    @Override
    public void setSequenceCallback(final Sequence sequenceCallback) 
        this.sequenceCallback = sequenceCallback;
    

    @Override
    public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
            throws Exception 
        event.event.setEndOfBatch(endOfBatch);
        event.loggerConfig.asyncCallAppenders(event.event);
        event.clear();

        notifyIntermediateProgress(sequence);
    

    /**
     * Notify the BatchEventProcessor that the sequence has progressed. Without this callback the sequence would not
     * be progressed until the batch has completely finished.
     */
    private void notifyIntermediateProgress(final long sequence) 
        if (++counter > NOTIFY_PROGRESS_THRESHOLD) 
            sequenceCallback.set(sequence);
            counter = 0;
        
    

event.loggerConfig.asyncCallAppenders(event.event); 这个会触发日志的输出

translator

跟EventFactory一样分mutable是否可变的两种情况。
不可变：

private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> TRANSLATOR =
        new EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig>() 
    @Override
    public void translateTo(final Log4jEventWrapper ringBufferElement, final long sequence,
            final LogEvent logEvent, final AsyncLoggerConfig loggerConfig) 
        ringBufferElement.event = logEvent;
        ringBufferElement.loggerConfig = loggerConfig;
    
;

可变：

/**
 * Object responsible for passing on data to a RingBuffer event with a MutableLogEvent.
 */
private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> MUTABLE_TRANSLATOR =
        new EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig>() 
    @Override
    public void translateTo(final Log4jEventWrapper ringBufferElement, final long sequence,
            final LogEvent logEvent, final AsyncLoggerConfig loggerConfig) 
        ((MutableLogEvent) ringBufferElement.event).initFrom(logEvent);
        ringBufferElement.loggerConfig = loggerConfig;
    
;

都是完成一个事情给ringBufferElement元素的event赋值或者初始化。

事件进队列的tryEnqueue方法逻辑分析

• prepareEvent

1. ensureImmutable：创建LogEvent的快照，传递进来的原LogEvent在应用线程还会被继续修改，所以此处要创建快照
2. Log4jLogEvent.makeMessageImmutable：格式化消息。因为是异步日志，针对需要format的消息在此处进行格式化，否则会因为引用对象值的改变导致日志不准确

• tryPublishEvent

1. 发布事件对象到disruptor队列

事件出队列的处理

先看按下调用栈:

Daemon Thread [Log4j2-TF-1-AsyncLoggerConfig--1] (Suspended (breakpoint at line 37 in PatternFormatter))    
    PatternFormatter.format(LogEvent, StringBuilder) line: 37   
    PatternLayout$PatternSerializer.toSerializable(LogEvent, StringBuilder) line: 334   
    PatternLayout.toText(AbstractStringLayout$Serializer2, LogEvent, StringBuilder) line: 233   
    PatternLayout.encode(LogEvent, ByteBufferDestination) line: 218 
    PatternLayout.encode(Object, ByteBufferDestination) line: 58    
    ConsoleAppender(AbstractOutputStreamAppender<M>).directEncodeEvent(LogEvent) line: 177  
    ConsoleAppender(AbstractOutputStreamAppender<M>).tryAppend(LogEvent) line: 170  
    ConsoleAppender(AbstractOutputStreamAppender<M>).append(LogEvent) line: 161 
    AppenderControl.tryCallAppender(LogEvent) line: 156 
    AppenderControl.callAppender0(LogEvent) line: 129   
    AppenderControl.callAppenderPreventRecursion(LogEvent) line: 120    
    AppenderControl.callAppender(LogEvent) line: 84 
    AsyncLoggerConfig(LoggerConfig).callAppenders(LogEvent) line: 448   
    AsyncLoggerConfig.asyncCallAppenders(LogEvent) line: 129    
    AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigDisruptor$Log4jEventWrapper, long, boolean) line: 111  
    AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(Object, long, boolean) line: 97 
    BatchEventProcessor<T>.run() line: 129  
    Log4jThread(Thread).run() line: 748 

Log4jEventWrapperHandler.onEvent 111行是event.loggerConfig.asyncCallAppenders(event.event)，参见上面EventHandler，此处完成日志真正写出。