log4j2非同步日誌解讀(一)AsyncAppender
log4j、logback、log4j2 歷史和關係,我們就在這裡不展開講了。直接上乾貨,log4j2突出於其他日誌的優勢,非同步日誌實現。
AsyncLogger筆者下文展開講。
下圖是獲取logger和呼叫info操作的流程圖:
一、AsyncAppender
我們先來看看AsyncApperder核心,就是logger將資料通過append方法放入到阻塞佇列中,隨後後臺執行緒從佇列中取出資料然後進行後續的操作。
那這樣看來,就很簡單了,一個append()方法,一個後臺執行緒執行就是我們要看的核心程式碼了。圍繞我們要看的類AsyncAppender,來看看類關係圖。
APPEND()方法
主要實現就是logger將資料通過append方法放入到阻塞佇列中。
//AsyncAppender.java /** * Actual writing occurs here. * * @param logEvent The LogEvent. */ @Override public void append(final LogEvent logEvent) { if (!isStarted()) { throw new IllegalStateException("AsyncAppender " + getName() + " is not active"); }//建立Log4jLogEvent的複製物件memento final Log4jLogEvent memento = Log4jLogEvent.createMemento(logEvent, includeLocation); InternalAsyncUtil.makeMessageImmutable(logEvent.getMessage()); //transfer(memento)將event放入佇列 //預設ArrayBlockingQueueFactory 大小1024 if (!transfer(memento)) {if (blocking) { 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(); logMessageInCurrentThread(logEvent); } else { // delegate to the event router (which may discard, enqueue and block, or log in current thread) /** * 1、DefaultAsyncQueueFullPolicy---等待直到佇列有空閒,退化為同步操作 * 2、DiscardingAsyncQueueFullPolicy---按照日誌級別丟棄一部分日誌 * 3、使用者自定義(需要實現AsyncQueueFullPolicy介面) */ final EventRoute route = asyncQueueFullPolicy.getRoute(thread.getId(), memento.getLevel()); route.logMessage(this, memento); } } else { error("Appender " + getName() + " is unable to write primary appenders. queue is full"); logToErrorAppenderIfNecessary(false, memento); } } } private boolean transfer(final LogEvent memento) { return queue instanceof TransferQueue ? ((TransferQueue<LogEvent>) queue).tryTransfer(memento) : queue.offer(memento); }
如流程圖所示,首先會判斷使用者是否設定了blocking選項,預設是true,如果設定為false,則Appender直接會ToErrorAppender,如果使用者沒有配置或者配置為true,則會按照一定的策略來處理這些訊息。策略可以分為2種,他們分別為:
1、DefaultAsyncQueueFullPolicy---等待直到佇列有空閒,轉為同步操作
public class DefaultAsyncQueueFullPolicy implements AsyncQueueFullPolicy { @Override public EventRoute getRoute(final long backgroundThreadId, final Level level) { // LOG4J2-471: prevent deadlock when RingBuffer is full and object // being logged calls Logger.log() from its toString() method if (Thread.currentThread().getId() == backgroundThreadId) { return EventRoute.SYNCHRONOUS; } return EventRoute.ENQUEUE; }
2、DiscardingAsyncQueueFullPolicy---按照日誌級別丟棄一部分日誌
//DiscardingAsyncQueueFullPolicy.java @Override public EventRoute getRoute(final long backgroundThreadId, final Level level) { if (level.isLessSpecificThan(thresholdLevel)) { if (discardCount.getAndIncrement() == 0) { LOGGER.warn("Async queue is full, discarding event with level {}. " + "This message will only appear once; future events from {} " + "are silently discarded until queue capacity becomes available.", level, thresholdLevel); } return EventRoute.DISCARD; } return super.getRoute(backgroundThreadId, level); }
RUN()方法
主要就是後臺執行緒從佇列中取出資料然後進行後續的操作。
//AsyncAppender.java private class AsyncThread extends Log4jThread { private volatile boolean shutdown = false; private final List<AppenderControl> appenders; private final BlockingQueue<LogEvent> queue; public AsyncThread(final List<AppenderControl> appenders, final BlockingQueue<LogEvent> queue) { super("AsyncAppender-" + THREAD_SEQUENCE.getAndIncrement()); this.appenders = appenders; this.queue = queue; setDaemon(true); } @Override public void run() { while (!shutdown) { LogEvent event; try { event = queue.take(); if (event == SHUTDOWN_LOG_EVENT) { shutdown = true; continue; } } catch (final InterruptedException ex) { break; // LOG4J2-830 } event.setEndOfBatch(queue.isEmpty()); final boolean success = callAppenders(event); if (!success && errorAppender != null) { try { errorAppender.callAppender(event); } catch (final Exception ex) { // Silently accept the error. } } } // Process any remaining items in the queue. LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.", queue.size()); int count = 0; int ignored = 0; while (!queue.isEmpty()) { try { final LogEvent event = queue.take(); if (event instanceof Log4jLogEvent) { final Log4jLogEvent logEvent = (Log4jLogEvent) event; logEvent.setEndOfBatch(queue.isEmpty()); callAppenders(logEvent); count++; } else { ignored++; LOGGER.trace("Ignoring event of class {}", event.getClass().getName()); } } catch (final InterruptedException ex) { // May have been interrupted to shut down. // Here we ignore interrupts and try to process all remaining events. } } LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. " + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored); } ... }
該執行緒會一直嘗試從阻塞佇列中獲取LogEvent,如果獲取成功,呼叫AppenderRef所引用Appender的append方法。我們也可以看到,AsyncAppender實際上主要是類似於中轉,日誌非同步化,當訊息放入阻塞佇列,返回成功,這樣能夠大幅提高日誌記錄的吞吐。使用者可以在權衡效能與日誌收集質量上進行權衡配置策略(設定blocking選項),當然也可以設定不同型別的阻塞佇列已到達更好的日誌記錄吞吐。