目前java應用日志收集都是采用日志框架(slf4j、apache commons logging)+日志系統(log4j、log4j2、LogBack、JUL等)的方式。而針對在分布式環境需要實時分析統計的日志,一般采用apache flume、facebook scribe等分布式日志收集系統。
日志框架:提供日志調用的接口,實際的日志輸出委托給日志系統實現。
日志系統:負責輸出日志
目前我們的應用大部分都是使用了SLF4j作為門面,然後搭配log4j或者log4j2日志系統。


下面將介紹slf4j + Log4j2 日志組件的引入、以及配置和使用
org.slf4j slf4j-api1.7.13 org.apache.logging.log4j log4j-slf4j-impl2.4.1 org.apache.logging.log4j log4j-1.2-api2.0 org.apache.logging.log4j log4j-api2.4.1 org.apache.logging.log4j log4j-core2.4.1 com.lmax disruptor3.2.0
當Logger記錄一個事件時,它將事件轉發給適當的Appender。然後Appender使用Layout來對日志記錄進行格式化,並將其發送給控制台、文件或者其它目標位置。另外,Filters可以讓你進一步指定一個Appender是否可以應用在一條特定的日志記錄上。在日志配置中,Filters並不是必需的,但可以讓你更靈活地控制日志消息的流動。
ConsoleAppender是最常用的Appenders之一,它只是將日志消息顯示到控制台上。許多日志框架都將其作為默認的Appender,並且在基本的配置中進行預配置。例如,在Log4j中ConsoleAppender的配置參數如下所示。
FileAppenders將日志記錄寫入到文件中,它負責打開、關閉文件,向文件中追加日志記錄,並對文件進行加鎖,以免數據被破壞或者覆蓋。
在Log4j中,如果想創建一個FileAppender,需要指定目標文件的名字,寫入方式是追加還是覆蓋,以及是否需要在寫入日志時對文件進行加鎖:
RollingFileAppender跟FileAppender的基本用法一樣。但RollingFileAppender可以設置log文件的size(單位:KB/MB/GB)上限、數量上限,當log文件超過設置的size上限,會自動被壓縮。RollingFileAppender可以理解為滾動輸出日志,如果log4j2記錄的日志達到上限,舊的日志將被刪除,騰出的空間用於記錄新的日志。
我們已經介紹了一些經常用到的Appenders,還有很多其它Appender。它們添加了新功能或者在其它的一些Appender基礎上實現了新功能。例如,Log4j中的RollingFileAppender擴展了FileAppender,它可以在滿足特定條件時自動創建新的日志文件;SMTPAppender會將日志內容以郵件的形式發送出去;FailoverAppender會在處理日志的過程中,如果一個或者多個Appender失敗,自動切換到其他Appender上。
Layouts將日志記錄的內容從一種數據形式轉換成另外一種。日志框架為純文本、HTML、syslog、XML、JSON、序列化以及其它日志提供了Layouts。
Logger負責捕捉事件並將其發送給合適的Appender,Logger之間是有繼承關系的。總是存在一個rootLogger,即使沒有顯示配置也是存在的,並且默認輸出級別為DEBUG,其它的logger都繼承自這個rootLogger。
Log4J中的繼承關系是通過名稱可以看出來,如"A"、"A.B"、"A.B.C",A.B繼承A,A.B.C繼承A.B,比較類似於包名。
DEBUG , INFO ,WARN ,ERROR四種,分別對應Logger類的四種方法
debug(Object message ) ;
info(Object message ) ;
warn(Object message ) ;
error(Object message ) ;
如果設置級別為INFO,則優先級大於等於INFO級別(如:INFO、WARN、ERROR)的日志信息將可以被輸出,
小於該級別的如:DEBUG將不會被輸出
先上圖


第一張圖可以看出Log4j2的asyncLogger的性能較使用asyncAppender和sync模式有非常大的提升,特別是線程越多的時候。
第二張圖是將log4j2的異步日志機制和其他日志系統進行對比,log4j2的asyncLogger 性能也是很有優勢。
這裡主要涉及了兩個概念AsyncLogger和AysncAppender,是支持異步的Logger和Appender,下面分別簡要介紹下這兩個概念。
AsyncAppender持有其他的配置了aysnc的appender引用列表(appender需要通過配置注冊成異步的),當其他的logger需要打日志的時候(logEvent事件),asyncAppender會接收logEvent,緩存到queue中,然後用單獨的線程完成從queue中取logEvent打印到目的appender,這個邏輯比較簡單,看下源碼就能明白這個流程。ps. AsyncAppender是Log4j 和Log4j2 都有的,不是新東西,但從上面的性能對比上還是有一點點差異的,主要的原因是:(引用官方說法)Asynchronous Appendersalready existed in Log4j 1.x, but have been enhanced to flush to disk at the end of a batch (when the queue is empty).
如何配置一個AsyncAppender:
%d %p %c{1.} [%t] %m%n
@Plugin(name = "Async", category = "Core", elementType = "appender", printObject = true)
public final class AsyncAppender extends AbstractAppender {
private static final long serialVersionUID = 1L;
private static final int DEFAULT_QUEUE_SIZE = 128;
private static final String SHUTDOWN = "Shutdown";
private static final AtomicLong THREAD_SEQUENCE = new AtomicLong(1);
private static ThreadLocal isAppenderThread = new ThreadLocal<>();
private final BlockingQueue queue;
private final int queueSize;
private final boolean blocking;
private final long shutdownTimeout;
private final Configuration config;
private final AppenderRef[] appenderRefs;
private final String errorRef;
private final boolean includeLocation;
private AppenderControl errorAppender;
private AsyncThread thread;
private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs,
final String errorRef, final int queueSize, final boolean blocking, final boolean ignoreExceptions,
final long shutdownTimeout, final Configuration config, final boolean includeLocation) {
super(name, filter, null, ignoreExceptions);
this.queue = new ArrayBlockingQueue<>(queueSize);
this.queueSize = queueSize;
this.blocking = blocking;
this.shutdownTimeout = shutdownTimeout;
this.config = config;
this.appenderRefs = appenderRefs;
this.errorRef = errorRef;
this.includeLocation = includeLocation;
}
@Override
public void start() {
final Map map = config.getAppenders();
final List appenders = new ArrayList<>();
for (final AppenderRef appenderRef : appenderRefs) {
final Appender appender = map.get(appenderRef.getRef());
if (appender != null) {
appenders.add(new AppenderControl(appender, appenderRef.getLevel(), appenderRef.getFilter()));
} else {
LOGGER.error("No appender named {} was configured", appenderRef);
}
}
if (errorRef != null) {
final Appender appender = map.get(errorRef);
if (appender != null) {
errorAppender = new AppenderControl(appender, null, null);
} else {
LOGGER.error("Unable to set up error Appender. No appender named {} was configured", errorRef);
}
}
if (appenders.size() > 0) {
thread = new AsyncThread(appenders, queue);
thread.setName("AsyncAppender-" + getName());
} else if (errorRef == null) {
throw new ConfigurationException("No appenders are available for AsyncAppender " + getName());
}
thread.start();
super.start();
}
@Override
public void stop() {
super.stop();
LOGGER.trace("AsyncAppender stopping. Queue still has {} events.", queue.size());
thread.shutdown();
try {
thread.join(shutdownTimeout);
} catch (final InterruptedException ex) {
LOGGER.warn("Interrupted while stopping AsyncAppender {}", getName());
}
LOGGER.trace("AsyncAppender stopped. Queue has {} events.", queue.size());
}
/**
* Actual writing occurs here.
*
* @param logEvent The LogEvent.
*/
@Override
public void append(LogEvent logEvent) {
if (!isStarted()) {
throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
}
if (!(logEvent instanceof Log4jLogEvent)) {
if (!(logEvent instanceof RingBufferLogEvent)) {
return; // only know how to Serialize Log4jLogEvents and RingBufferLogEvents
}
logEvent = ((RingBufferLogEvent) logEvent).createMemento();
}
logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
final Log4jLogEvent coreEvent = (Log4jLogEvent) logEvent;
boolean appendSuccessful = false;
if (blocking) {
if (isAppenderThread.get() == Boolean.TRUE && queue.remainingCapacity() == 0) {
// LOG4J2-485: avoid deadlock that would result from trying
// to add to a full queue from appender thread
coreEvent.setEndOfBatch(false); // queue is definitely not empty!
appendSuccessful = thread.callAppenders(coreEvent);
} else {
final Serializable serialized = Log4jLogEvent.serialize(coreEvent, includeLocation);
try {
// wait for free slots in the queue
queue.put(serialized);
appendSuccessful = true;
} catch (final InterruptedException e) {
// LOG4J2-1049: Some applications use Thread.interrupt() to send
// messages between application threads. This does not necessarily
// mean that the queue is full. To prevent dropping a log message,
// quickly try to offer the event to the queue again.
// (Yes, this means there is a possibility the same event is logged twice.)
//
// Finally, catching the InterruptedException means the
// interrupted flag has been cleared on the current thread.
// This may interfere with the application's expectation of
// being interrupted, so when we are done, we set the interrupted
// flag again.
appendSuccessful = queue.offer(serialized);
if (!appendSuccessful) {
LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
getName());
}
// set the interrupted flag again.
Thread.currentThread().interrupt();
}
}
} else {
appendSuccessful = queue.offer(Log4jLogEvent.serialize(coreEvent, includeLocation));
if (!appendSuccessful) {
error("Appender " + getName() + " is unable to write primary appenders. queue is full");
}
}
if (!appendSuccessful && errorAppender != null) {
errorAppender.callAppender(coreEvent);
}
}
/**
* Create an AsyncAppender.
*
* @param appenderRefs The Appenders to reference.
* @param errorRef An optional Appender to write to if the queue is full or other errors occur.
* @param blocking True if the Appender should wait when the queue is full. The default is true.
* @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events
* in the queue on shutdown. The default is zero which means to wait forever.
* @param size The size of the event queue. The default is 128.
* @param name The name of the Appender.
* @param includeLocation whether to include location information. The default is false.
* @param filter The Filter or null.
* @param config The Configuration.
* @param ignoreExceptions If {@code "true"} (default) exceptions encountered when appending events are logged;
* otherwise they are propagated to the caller.
* @return The AsyncAppender.
*/
@PluginFactory
public static AsyncAppender createAppender(@PluginElement("AppenderRef") final AppenderRef[] appenderRefs,
@PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef,
@PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking,
@PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout,
@PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size,
@PluginAttribute("name") final String name,
@PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation,
@PluginElement("Filter") final Filter filter, @PluginConfiguration final Configuration config,
@PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) {
if (name == null) {
LOGGER.error("No name provided for AsyncAppender");
return null;
}
if (appenderRefs == null) {
LOGGER.error("No appender references provided to AsyncAppender {}", name);
}
return new AsyncAppender(name, filter, appenderRefs, errorRef, size, blocking, ignoreExceptions,
shutdownTimeout, config, includeLocation);
}
/**
* Thread that calls the Appenders.
*/
private class AsyncThread extends Thread {
private volatile boolean shutdown = false;
private final List appenders;
private final BlockingQueue queue;
public AsyncThread(final List appenders, final BlockingQueue queue) {
this.appenders = appenders;
this.queue = queue;
setDaemon(true);
setName("AsyncAppenderThread" + THREAD_SEQUENCE.getAndIncrement());
}
@Override
public void run() {
isAppenderThread.set(Boolean.TRUE); // LOG4J2-485
while (!shutdown) {
Serializable s;
try {
s = queue.take();
if (s != null && s instanceof String && SHUTDOWN.equals(s.toString())) {
shutdown = true;
continue;
}
} catch (final InterruptedException ex) {
break; // LOG4J2-830
}
final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
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 Serializable s = queue.take();
if (Log4jLogEvent.canDeserialize(s)) {
final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
event.setEndOfBatch(queue.isEmpty());
callAppenders(event);
count++;
} else {
ignored++;
LOGGER.trace("Ignoring event of class {}", s.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);
}
/**
* Calls {@link AppenderControl#callAppender(LogEvent) callAppender} on all registered {@code AppenderControl}
* objects, and returns {@code true} if at least one appender call was successful, {@code false} otherwise. Any
* exceptions are silently ignored.
*
* @param event the event to forward to the registered appenders
* @return {@code true} if at least one appender call succeeded, {@code false} otherwise
*/
boolean callAppenders(final Log4jLogEvent event) {
boolean success = false;
for (final AppenderControl control : appenders) {
try {
control.callAppender(event);
success = true;
} catch (final Exception ex) {
// If no appender is successful the error appender will get it.
}
}
return success;
}
public void shutdown() {
shutdown = true;
if (queue.isEmpty()) {
queue.offer(SHUTDOWN);
}
}
}
/**
* Returns the names of the appenders that this asyncAppender delegates to as an array of Strings.
*
* @return the names of the sink appenders
*/
public String[] getAppenderRefStrings() {
final String[] result = new String[appenderRefs.length];
for (int i = 0; i < result.length; i++) {
result[i] = appenderRefs[i].getRef();
}
return result;
}
/**
* Returns {@code true} if this AsyncAppender will take a snapshot of the stack with every log event to determine
* the class and method where the logging call was made.
*
* @return {@code true} if location is included with every event, {@code false} otherwise
*/
public boolean isIncludeLocation() {
return includeLocation;
}
/**
* Returns {@code true} if this AsyncAppender will block when the queue is full, or {@code false} if events are
* dropped when the queue is full.
*
* @return whether this AsyncAppender will block or drop events when the queue is full.
*/
public boolean isBlocking() {
return blocking;
}
/**
* Returns the name of the appender that any errors are logged to or {@code null}.
*
* @return the name of the appender that any errors are logged to or {@code null}
*/
public String getErrorRef() {
return errorRef;
}
public int getQueueCapacity() {
return queueSize;
}
public int getQueueRemainingCapacity() {
return queue.remainingCapacity();
}
}
1,Disruptor使用了一個RingBuffer替代隊列,用生產者消費者指針替代鎖。
2,生產者消費者指針使用CPU支持的整數自增,無需加鎖並且速度很快。Java的實現在Unsafe package中。
盡管AsyncLogger 能夠大幅度的提高性能,但是也會帶來一些問題,下面是翻譯官方的文檔的Trade-offs:
Benefits
Drawbacks
全局配置異步Logger
配置所有Logger都為AsyncLogger,只需要增加disruptor包,然後配置一個system property,-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector,Log4j的配置文件不需要修改。
混合使用同步和異步Logger
單獨配置某個logger為async的,通過或者
%d %p %class{1.} [%t] %location %m %ex%n
當layouts配置了輸出%C or $class, %F or %file, %l or %location, %L or %line, %M or %method,或者HTMLlocationInfo,log4j會獲取location的一個快照,而這對於sync 和async的logger都是一個耗時的操作(官方文檔上說syncLogger會慢1.3~5倍,async會慢4-20倍),所以默認都是不會輸出location信息,除非Logger配置了includeLocation="true"(官方文檔這麼說的,但是我測試的是默認是輸出的,不管了,反正當日志出現慢的時候,可以考慮通過配置includeLocation控制是否輸出location信息)。