前文已经讲了log4j2的AsyncAppender的实现【】,今天我们看看AsyncLogger的实现。
看了这个图,应该很清楚AsyncLogger调用Disruptor,然后直接返回。至于 这里已经展开讲了是如何实现的。
AsyncLogger的调用流程
我们来看看AsyncLogger的调用流程,log.info()首先会调用抽象类AbstractLogger,然后调用了Logger的logMessage。
//Logger.java @Override public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message, final Throwable t) { final Message msg = message == null ? new SimpleMessage(Strings.EMPTY) : message; final ReliabilityStrategy strategy = privateConfig.loggerConfig.getReliabilityStrategy(); strategy.log(this, getName(), fqcn, marker, level, msg, t); }
strategy.log是调用了ReliabilityStrategy接口,日志事件传递到适当的appender的对象的接口,然后调用了LoggerConfig.log()方法,来创建有关记录消息的上下文信息。
//LoggerConfig.java @PerformanceSensitive("allocation") public void log(final String loggerName, final String fqcn, final Marker marker, final Level level, final Message data, final Throwable t) { Listprops = null; if (!propertiesRequireLookup) { props = properties; } else { if (properties != null) { props = new ArrayList<>(properties.size()); final LogEvent event = Log4jLogEvent.newBuilder() .setMessage(data) .setMarker(marker) .setLevel(level) .setLoggerName(loggerName) .setLoggerFqcn(fqcn) .setThrown(t) .build(); for (int i = 0; i < properties.size(); i++) { final Property prop = properties.get(i); final String value = prop.isValueNeedsLookup() // since LOG4J2-1575 ? config.getStrSubstitutor().replace(event, prop.getValue()) // : prop.getValue(); props.add(Property.createProperty(prop.getName(), value)); } } } final LogEvent logEvent = logEventFactory.createEvent(loggerName, marker, fqcn, level, data, props, t); try { log(logEvent, LoggerConfigPredicate.ALL); } finally { // LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString()) ReusableLogEventFactory.release(logEvent); } }
接着我们来看AsyncLoggerConfig.logToAsyncDelegate()方法,首先会调用Disruptor,放入环形队列。如果环形队列阻塞,则执行等待策略。
//AsyncLoggerConfig.java private void logToAsyncDelegate(LogEvent event) { if (!isFiltered(event)) { // Passes on the event to a separate thread that will call // asyncCallAppenders(LogEvent). populateLazilyInitializedFields(event); if (!delegate.tryEnqueue(event, this)) { //如果获取Disruptor队列需要等待则执行等待策略,这里类似AsyncAppender等待策略 handleQueueFull(event); } } } private void handleQueueFull(final LogEvent event) { if (AbstractLogger.getRecursionDepth() > 1) { // LOG4J2-1518, LOG4J2-2031 // If queue is full AND we are in a recursive call, call appender directly to prevent deadlock AsyncQueueFullMessageUtil.logWarningToStatusLogger(); logToAsyncLoggerConfigsOnCurrentThread(event); } else { // otherwise, we leave it to the user preference final EventRoute eventRoute = delegate.getEventRoute(event.getLevel()); // 1、DefaultAsyncQueueFullPolicy---等待队列,转为同步操作策略 // 2、DiscardingAsyncQueueFullPolicy---按照日志等级抛弃日志策略 eventRoute.logMessage(this, event); } }
然后再来看看Disruptor写入 的过程。LogEvent是记录消息的上下文信息的接口,然后调用tryPublishEvent去获取环形队列的位置,然后发布数据到环形队列上。这一块具体可以看笔者前文,这里就不展开讨论。
//AsyncLoggerConfigDisruptor.java @Override public boolean tryEnqueue(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) { final LogEvent logEvent = prepareEvent(event); return disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig); }
日志的消费过程,定义RingBufferLogEventHandler类实现Disruptor的SequenceReportingEventHandler的onEvent方法,从ringbuffer读取事件进行处理。最后会调用该logger绑定的默认appender输出。
最后提供下笔者测试demo
总结
1、Log4j 2的异步记录日志在一定程度上提供更好的吞吐量,但是一旦队列已满,appender线程需要等待,这个时候就需要设置等待策略,AsyncAppender是依赖于消费者最序列最后的消费者,会持续等待。至于异步性能图可以看下官方提供的吞吐量比较图,差异很明显。
2、因为AsyncAppender是采用Disruptor,通过环形队列无阻塞队列作为缓冲,多生产者多线程的竞争是通过CAS实现,无锁化实现,可以降低极端大的日志量时候的延迟尖峰, 可是号称一个线程里每秒处理600万订单的高性能队列。