摘要
上一篇《Logback日志框架初始化全過程源碼解析》分析了Logback的整個初始化過程以及Logger的創(chuàng)建,這篇文章將繼續(xù)分析Logger的打印過程,上篇文章沒有介紹Logback的架構,所以我們先會簡單介紹下Logback的基礎組成模塊;然后再介紹下logback.xml 配置文件中的主要元素和他們之間的協(xié)作關系,重點說明下Logger的繼承特性;接著梳理下整個日志打印過程,帶著這些概念進入源碼去一一驗證,最后做個簡單的總結。
正文
Logback基礎組成模塊
Logback主要分為3個模塊:
-
logback-core
core模塊是其他兩個模塊的基礎
-
logback-classic
classic模塊依賴core模塊,她是其實是log4j的升級版,logback-classic天然實現(xiàn)了SLF4J API,所以我們可以在Log4j、Jul等日志框架之間隨意切換而不需要改動我們的業(yè)務代碼。
-
logback-access
access模塊主要用于和Servlet容器結合提供記錄HTTP請求日志的功能,通常不使用。
一般使用Logback時我們會引用slf4j-api、logback-core和logback-classic等3個依賴。
Logback配置
logback 提供多種配置方式:
-
通過實現(xiàn)
com.qos.logback.classic.spi.Configurator接口來進行配置上文《Logback日志框架初始化全過程源碼解析》中提到如果Logback初始化過程中如果找不到配置文件,且用戶也沒有實現(xiàn)Configurator接口,則會使用默認配置BasicConfigurator,她其實就實現(xiàn)了Configurator接口。
通過加載配置文件
配置文件其實也提供2類:logback.grovy和logback.xml
兩者大同小異,只是語法不同而已,在這里我們選擇比較熟悉和常用的logback.xml進行簡單解釋。
<configuration>
<property name="pattern" value="%date %level [%thread] %logger{10} [%file : %line] %msg%n"/>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>${pattern}</Pattern>
</layout>
</appender>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>${fileName:-demo.log}</file>
<encoder>
<pattern>${pattern}</pattern>
</encoder>
</appender>
<logger name="com" level="warn" additivity="false">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE"/>
</logger>
<logger name="com.cw" level="info" additivity="false">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE"/>
</logger>
<logger name="com.cw.demo" additivity="false">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE"/>
</logger>
<root level="info">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE"/>
</root>
</configuration>
logback.xml中我們主要看6個xml元素:
appender
appender主要用來指定日志信息最終輸出到什么位置,console、file或者socket等。
layout
layout用來根據(jù)pattern規(guī)則格式化日志內容,將日志event轉換為String類型,然后通過java.io.Writer輸出。
encoder
encoder是0.9.19版本之后出現(xiàn)的,她和layout作用本質上是相同的,都會通過pattern規(guī)則將日志內容格式化,不同點是,encoder將日志event轉化為byte數(shù)組,然后寫到OutputStream。
0.9.19版本之后官方推薦encoder來代替layout,具體原因,官方給出如下解釋:
Why the breaking change?
Layouts, as discussed in detail in the next chapter, are only able to transform an event into a String. Moreover, given that a layout has no control over when events get written out, layouts cannot aggregate events into batches. Contrast this with encoders which not only have total control over the format of the bytes written out, but also control when (and if) those bytes get written out.
意思是說,Layouts只能將日志event轉化為String,不能夠控制何時將日志event寫出,無法將多個event集合到一組。而encoder不僅能控制日志bytes數(shù)據(jù)的格式,還能控制是否以及何時寫出數(shù)據(jù)。簡單來講就是encoder比layout牛逼,能用encoder就不用layout。當然對于之前的使用layout的老代碼,官方也提供一些適配class例如LayoutWrappingEncoder
pattern
pattern主要用來定義日志的輸出格式等,詳見PatternLayout。
logger
logger可以與我代碼中LoggerFactory.getLogger產(chǎn)生的Logger對象相對應,她有三個屬性:
name : 日志名稱,用于Logger對象初始化的時候定位到配置文件中具體的配置。
-
level:標識日志的有效等級,日志等級具有繼承性。
例如:
logback.xml中name="com.cw"的logger(取別名Lc)等級是info, name="com.cw.demo"的logger(取別名為Ld),Lc是Ld的父級,而Ld沒有設置日志等級,那么她的等級就繼承子父級Lc的info,
如果Lc也沒有等級,那么會繼續(xù)往上找到name="com"這個祖先,繼承這個祖先的日志等級warn。
additivity:標識該日志對象是否要將日志event向父級輸出,默認為true,一般我們會設置為false,防止一段日志信息被重復打印到多個日志文件中,無形中增加了日志文件的大小,稍后會結合源碼做分析。
appender-ref
appender-ref作用是將一個logger對象和具體的appender綁定,指定該logger將通過哪個appender將日志輸出到何處。一個logger可存在多個appender-ref,也就是說可以同時綁定多個appender。
root
root其實是個特殊的logger,看名字就知道她是一個根節(jié)點,是所有l(wèi)ogger的祖先,配置文件中必須得有一個root。
日志打印源碼分析
過濾和創(chuàng)建LogEvent
這里我們以我們常用的logger.info() 為入口,info()中實際是調用filterAndLog_1()方法,
這個方法做2件事,過濾和創(chuàng)建LoggingEvent并推送給實際綁定的Appender對象
public final class Logger implements org.slf4j.Logger, LocationAwareLogger, AppenderAttachable<ILoggingEvent>, Serializable {
public void info(String format, Object arg) {
filterAndLog_1(FQCN, null, Level.INFO, format, arg, null);
}
private void filterAndLog_1(final String localFQCN, final Marker marker, final Level level, final String msg, final Object param, final Throwable t) {
/**
* 這里先經(jīng)過一串過濾器處理,根據(jù)傳入的marker滿足的條件不同返回不同的結果,
* FilterReply.NEUTRAL 表示中立的意思
*/
final FilterReply decision = loggerContext.getTurboFilterChainDecision_1(marker, this, level, msg, param, t);
/**
* 過濾后返回NEUTRAL則進一步判斷當前想要打印的日志等級"INFO"是否高于或者等于有效日志級別。
* 如果小于有效日志級別,則表示該日志無效,直接返回,不做具體輸出動作。
*/
if (decision == FilterReply.NEUTRAL) {
if (effectiveLevelInt > level.levelInt) {
return;
}
} else if (decision == FilterReply.DENY) {
return;
}
buildLoggingEventAndAppend(localFQCN, marker, level, msg, new Object[] { param }, t);
}
/**
* 創(chuàng)建日志Event, 推送到與logger綁定的所有appender中
*/
private void buildLoggingEventAndAppend(
final String localFQCN, final Marker marker,
final Level level, final String msg,
final Object[] params, final Throwable t) {
// 創(chuàng)建日志Event
LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);
le.setMarker(marker);
//推送到與logger綁定的所有appender中
callAppenders(le);
}
public void callAppenders(ILoggingEvent event) {
int writes = 0;
/**
* 這里有個熟悉的單詞additive,上面我們介紹logger的時候說到,
* 她是logger的一個屬性,默認為true
* 結合這段代碼我們看下,for循環(huán)中,先將event, 推給當前l(fā)ogger的Appenders中,并且累加
* writes,緊接著判斷additive,
* 如果為true則,取logger的父級,繼續(xù)將event推給父級logger的Appender中,
* 以此類推,直至遇到某個父級或者祖先的additive為false,則break跳出循環(huán),
* 或者 送到root日志根節(jié)點為止。
* 這幾解釋了additive的作用了。
*/
for (Logger l = this; l != null; l = l.parent) {
writes += l.appendLoopOnAppenders(event);
if (!l.additive) {
break;
}
}
// No appenders in hierarchy
if (writes == 0) {
loggerContext.noAppenderDefinedWarning(this);
}
}
private int appendLoopOnAppenders(ILoggingEvent event) {
if (aai != null) {
return aai.appendLoopOnAppenders(event);
} else {
return 0;
}
}
/**
* appenderList是與Logger綁定的Appender
* 例如上述logback.xml中name="FILE"的logger綁定的
* Appender 就是ch.qos.logback.core.FileAppender類。
* 因為每個logger可以同時綁定多個Appender所以這里用數(shù)組appenderList來存儲這些Appender。
*/
public int appendLoopOnAppenders(E e) {
int size = 0;
final Appender<E>[] appenderArray = appenderList.asTypedArray();
final int len = appenderArray.length;
for (int i = 0; i < len; i++) {
appenderArray[i].doAppend(e);
size++;
}
return size;
}
}
通過FileAppender打印到文件
logback.xml中name="FILE"的logger綁定的 Appender 是ch.qos.logback.core.FileAppender類,那么我們就以FileAppender為例分析下日志寫入到文件的整個流程。
FIleAppender類的繼承關系圖:

整個流程如下:
FileAppender 指定日志打印的目標文件,并指定文件的輸出流OutputStream給OutputStreamAppender,
目標文件的指定動作是發(fā)生在logger的初始化過程中,通過加載解析logback.xml找到name="FILE"的<appender>元素,讀取子元素<file>的值來獲取文件;
OutputStreamAppender 提供一個基礎服務,她繼承UnsynchronizedAppenderBase抽象類并實現(xiàn)其中的
append(E eventObject)抽象方法,進行具體的日志格式化和打印動作,其實就是向FileAppender提供的輸出流中輸入格式化后的日志;
通過名稱可看出UnsynchronizedAppenderBase并未做線程安全方面的措施,而是將線程安全方面的問題交給子類自己去處理,OutputStreamAppender確實也自己處理了,她通過在writeBytes(byte[] byteArray)方法中加入 ReentrantLock重入鎖來保證日志寫入的線程安全。
接下來我們從下到上依次來分析下幾個類中重要的方法:
FileAppender
public class FileAppender<E> extends OutputStreamAppender<E> {
...
/**
*
*/
public void start() {
int errors = 0;
if (getFile() != null) {
...
/**
* 檢查該日志文件是否以及被其他Appender綁定了,如果沒被綁定則返回false
*/
if (checkForFileCollisionInPreviousFileAppenders()) {
addError("Collisions detected with FileAppender/RollingAppender instances defined earlier. Aborting.");
addError(MORE_INFO_PREFIX + COLLISION_WITH_EARLIER_APPENDER_URL);
errors++;
} else {
try {
/**
* 打開未被其他Appender綁定的文件輸出流給OutputStreamAppender,
* 用于后續(xù)的日志輸入。
*/
openFile(getFile());
} catch (java.io.IOException e) {
errors++;
addError("openFile(" + fileName + "," + append + ") call failed.", e);
}
}
} else {
errors++;
addError("\"File\" property not set for appender named [" + name + "].");
}
if (errors == 0) {
super.start();
}
}
/**
* 檢查該日志文件是否以及被其他Appender綁定了,如果是的話就返回true
* 否則記錄appender的名稱和日志文件名稱,表示當前文件已經(jīng)被Appender綁定了,
* 不能再和別的Appender綁定,然后返回false
*/
protected boolean checkForFileCollisionInPreviousFileAppenders() {
boolean collisionsDetected = false;
if (fileName == null) {
return false;
}
@SuppressWarnings("unchecked")
Map<String, String> map = (Map<String, String>) context.getObject(CoreConstants.FA_FILENAME_COLLISION_MAP);
if (map == null) {
return collisionsDetected;
}
for (Entry<String, String> entry : map.entrySet()) {
if (fileName.equals(entry.getValue())) {
addErrorForCollision("File", entry.getValue(), entry.getKey());
collisionsDetected = true;
}
}
if (name != null) {
map.put(getName(), fileName);
}
return collisionsDetected;
}
/**
* 創(chuàng)建個ResilientFileOutputStream輸出流,
* 給OutputStreamAppender中的,outputStream成員變量;
* 文件必須是可寫的;
* 雖然該方法是public的但是不要直接調用,
* 而是通過start方法一步步設置還成員變量的后再調用
*/
public void openFile(String file_name) throws IOException {
lock.lock();
try {
File file = new File(file_name);
boolean result = FileUtil.createMissingParentDirectories(file);
if (!result) {
addError("Failed to create parent directories for [" + file.getAbsolutePath() + "]");
}
ResilientFileOutputStream resilientFos = new ResilientFileOutputStream(file, append, bufferSize.getSize());
resilientFos.setContext(context);
setOutputStream(resilientFos);
} finally {
lock.unlock();
}
}
...
}
OutputStreamAppender
public class OutputStreamAppender<E> extends UnsynchronizedAppenderBase<E> {
protected Encoder<E> encoder;
protected final ReentrantLock lock = new ReentrantLock(false);
private OutputStream outputStream;
boolean immediateFlush = true;
@Override
protected void append(E eventObject) {
if (!isStarted()) {
return;
}
subAppend(eventObject);
}
/**
* 真正的的寫入操作
* <p>
* Most subclasses of <code>WriterAppender</code> will need to override this
* method.
*/
protected void subAppend(E event) {
if (!isStarted()) {
return;
}
try {
// this step avoids LBCLASSIC-139
if (event instanceof DeferredProcessingAware) {
((DeferredProcessingAware) event).prepareForDeferredProcessing();
}
// 格式化日志文件
byte[] byteArray = this.encoder.encode(event);
// 寫入日志到特定的輸出流中,使用ReentrantLock保證線程安全
writeBytes(byteArray);
} catch (IOException ioe) {
this.started = false;
addStatus(new ErrorStatus("IO failure in appender", this, ioe));
}
}
/**
* 傳入一個已經(jīng)打開的outputStream,
* 例如FileAppender 中打開的ResilientFileOutputStream
*/
public void setOutputStream(OutputStream outputStream) {
lock.lock();
try {
// close any previously opened output stream
closeOutputStream();
this.outputStream = outputStream;
if (encoder == null) {
addWarn("Encoder has not been set. Cannot invoke its init method.");
return;
}
encoderInit();
} finally {
lock.unlock();
}
}
...
/**
* 寫入日志到特定的輸出流中,使用ReentrantLock保證線程安全
*/
private void writeBytes(byte[] byteArray) throws IOException {
if(byteArray == null || byteArray.length == 0)
return;
lock.lock();
try {
this.outputStream.write(byteArray);
if (immediateFlush) {
this.outputStream.flush();
}
} finally {
lock.unlock();
}
}
}
UnsynchronizedAppenderBase
abstract public class UnsynchronizedAppenderBase<E> extends ContextAwareBase implements Appender<E> {
protected boolean started = false;
/**
* guard 用來防止appender 重復調用自己的doAppend方法
*/
private ThreadLocal<Boolean> guard = new ThreadLocal<Boolean>();
/**
* Appenders are named.
*/
protected String name;
private FilterAttachableImpl<E> fai = new FilterAttachableImpl<E>();
private int statusRepeatCount = 0;
private int exceptionCount = 0;
static final int ALLOWED_REPEATS = 3;
public void doAppend(E eventObject) {
// 判斷當前線程是否正在打印日志,如果不是才進行打印動作。
if (Boolean.TRUE.equals(guard.get())) {
return;
}
try {
guard.set(Boolean.TRUE);
if (!this.started) {
if (statusRepeatCount++ < ALLOWED_REPEATS) {
addStatus(new WarnStatus("Attempted to append to non started appender [" + name + "].", this));
}
return;
}
if (getFilterChainDecision(eventObject) == FilterReply.DENY) {
return;
}
/**
* append是個抽象方法,所以此處會調用append方法的具體實現(xiàn)
* 例如OutputStreamAppender類中實現(xiàn)的該方法
*/
this.append(eventObject);
} catch (Exception e) {
if (exceptionCount++ < ALLOWED_REPEATS) {
addError("Appender [" + name + "] failed to append.", e);
}
} finally {
guard.set(Boolean.FALSE);
}
}
abstract protected void append(E eventObject);
至此整個日志打印過程結束了。
總結
本文主要通過FileAppender類為例詳細分析了整個日志的打印流程,除了FileAppender 還有一些我們常用的Appender,例如:
ConsoleAppender: 打印日志到控制臺
RollingFileAppender: 可以根據(jù)一定的規(guī)則對日志進行切割備份,如:日期、日志大小等規(guī)則
文中就不一一介紹了,他們的流程都大同小異,留個感興趣的同學自己去分析。