代码改变世界

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

2019-06-08 11:11  chen.simon  阅读(10953)  评论(0编辑  收藏  举报

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

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

AsyncLoggerConfigDisruptor.start方法用来创建并启动disruptor实例
创建disruptor需要EventFactoryringBuffer的大小ThreadFactoryProducerType等待策略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。 支持可配置SleepingWaitStrategyYieldingWaitStrategyBlockingWaitStrategyBusySpinWaitStrategyTimeoutBlockingWaitStrategy
这个配置是通过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,此处完成日志真正写出。