日志收集在互聯(lián)網(wǎng)企業(yè)尤其是大數(shù)據(jù)時代是一件非常重要的事情,日志記錄著用戶行為和系統(tǒng)行為,是一種重要的數(shù)據(jù)來源。Log4j是Java應(yīng)用程序使用的最多的一種日志收集工作。目前大量的Java應(yīng)用程序都使用著Lo4j 1.2.X版本,Log4j 1.X版本飽受詬病的原因是使用了大量的鎖,在高并發(fā)的情況下影響了系統(tǒng)的性能。這篇簡單提供一種思路,說說如何擴(kuò)展一下Log4j,提升一下Log4j的性能。
網(wǎng)上有很多分析Log4j源碼的文章,這里不重復(fù)說了,只簡單分析一下最重要的幾個組件。
先看一下Log4j的配置文件log4j.xml
- <?xml version="1.0" encoding="UTF-8" ?>
- <!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
-
- <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
- <appender name="rootAppender" class="org.apache.log4j.DailyRollingFileAppender">
- <param name="File" value="test.log" />
- <param name="DatePattern" value="'.'yyyy-MM-dd" />
- <layout class="org.apache.log4j.PatternLayout">
- <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %5p %c{1}:%L - %m%n" />
- </layout>
- </appender>
- <logger name="com.test" additivity="false">
- <level value="debug" />
- <appender-ref ref="rootAppender" />
- </logger>
- <root>
- <level value="debug" />
- <appender-ref ref="rootAppender" />
- </root>
- </log4j:configuration>
從log4j.xml里面我們就可以看到Log4j最主要的幾個組件
1. Logger,表示日志收集器,包含了各種Level下收集日志的方法,比如debug, info, error等。Logger的一個重要屬性是additivity,表示是否附加到父Logger。Logger被設(shè)置成單根的樹形結(jié)構(gòu),根就是Root,收集日志時,可以從葉子Logger一直往上直到Root。
Logger還包含了level表示級別,包含了一個appender列表,一個Logger可以對應(yīng)多個Appender
2. Appender,表示如何處理日志,可以寫本地文件,可以寫遠(yuǎn)程文件,也可以輸出到消息隊列,等等。最常見的場景就是寫本地文件。寫文件的抽象是WriterAppender,封裝了一個過濾器流QuietWriter。既然是過濾器流,那么可以包裝節(jié)點流,默認(rèn)的就是FileOutputStream流。Log4j也支持Buffer流,在WriterAppender的子類FileAppender里面有bufferedIO屬性,如果采用Buffer流,就會在FileOutputStream外包一層BufferedWriter,最后在包到QuietWriter中。
- public
- synchronized
- void setFile(String fileName, boolean append, boolean bufferedIO, int bufferSize)
- throws IOException {
- LogLog.debug("setFile called: "+fileName+", "+append);
-
- if(bufferedIO) {
- setImmediateFlush(false);
- }
-
- reset();
- FileOutputStream ostream = null;
- try {
- ostream = new FileOutputStream(fileName, append);
- } catch(FileNotFoundException ex) {
- String parentName = new File(fileName).getParent();
- if (parentName != null) {
- File parentDir = new File(parentName);
- if(!parentDir.exists() && parentDir.mkdirs()) {
- ostream = new FileOutputStream(fileName, append);
- } else {
- throw ex;
- }
- } else {
- throw ex;
- }
- }
- Writer fw = createWriter(ostream);
- if(bufferedIO) {
- fw = new BufferedWriter(fw, bufferSize);
- }
- this.setQWForFiles(fw);
- this.fileName = fileName;
- this.fileAppend = append;
- this.bufferedIO = bufferedIO;
- this.bufferSize = bufferSize;
- writeHeader();
- LogLog.debug("setFile ended");
- }
關(guān)于Appender,尤其是基于文件的FileAppender,一定要理解,一個FileAppender實例表示的是一個打開文件對象,在計算機(jī)底層知識拾遺(四)理解文件系統(tǒng) 中我們說了從Linux的角度來說,open調(diào)用就創(chuàng)建了一個打開文件對象,并返回了一個文件描述符,其他系統(tǒng)調(diào)用都用文件描述符來引用這個打開文件對象。打開文件對象包含了當(dāng)前的讀寫位置,文件長度等等。 而在Java中并沒有提供open操作,在Java中,new一個FileInputStream/FileOutputStream實例表示創(chuàng)建了一個打開文件對象。FileInputStream/FileOutputStream維護(hù)著當(dāng)前的讀寫位置,還維護(hù)了文件描述符FileDescriptor對象和FileChannel對象。隨便提一下,日志收集操作基本上都是對文件的Append,F(xiàn)ileOutputStream支持文件的append打開方式。
可以看到, new一個FileOutputStream會創(chuàng)建一個FileDescriptor對象,并支持open和openAppend方式。這和Linux的open系統(tǒng)調(diào)用完成的功能是一樣的。
- public
- class FileOutputStream extends OutputStream
- {
- /**
- * The system dependent file descriptor. The value is
- * 1 more than actual file descriptor. This means that
- * the default value 0 indicates that the file is not open.
- */
- private FileDescriptor fd;
-
- private FileChannel channel= null;
-
- private boolean append = false;
-
- public FileOutputStream(File file, boolean append)
- throws FileNotFoundException
- {
- String name = (file != null ? file.getPath() : null);
- SecurityManager security = System.getSecurityManager();
- if (security != null) {
- security.checkWrite(name);
- }
- if (name == null) {
- throw new NullPointerException();
- }
- fd = new FileDescriptor();
- fd.incrementAndGetUseCount();
- this.append = append;
- if (append) {
- openAppend(name);
- } else {
- open(name);
- }
- }
- }
理解了一個FileOutputStream對象實例表示了一個打開文件之后,我們再來看一下操作系統(tǒng)內(nèi)部為進(jìn)程維護(hù)運行時文件數(shù)據(jù)結(jié)構(gòu)的圖。可以看到文件描述符指向了打開文件對象,打開文件對象又指向了inode對象,inode對象代表了一個文件在操作系統(tǒng)中的實例。
對于Java來說,JVM采用了單進(jìn)程多線程的方式來支持并發(fā),進(jìn)程打開的所有文件對象對所有線程都是共享的。既然是共享,就涉及到多線程并發(fā)安全問題。在這里涉及到到3個地方存在并發(fā)安全問題。
1. 一個new FileOutputStream對象表示一個打開文件對象。那么當(dāng)多個線程使用同一個FileOutputStream對象寫文件時,就需要進(jìn)行同步操作。
2. 當(dāng)多個線程new了多個FileOutputStream對象對同一個文件進(jìn)行寫操作時,會出現(xiàn)并發(fā)問題,寫入的順序和位置都是不確定的。這種情況比較難同步,因為多個FileOutputStream對象是分散的,難以加鎖。盡量避免這樣寫文件。當(dāng)然也有解決方案,比如采用集中的地方來對外提供FileOutputStream對象,使用文件鎖對inode對象加鎖等等。
3. 當(dāng)有另外的JVM進(jìn)程對同一個文件進(jìn)行操作時。這種情況只能通過加文件鎖的方式來解決
Java提供了文件鎖的支持,F(xiàn)ileChannel提供了lock方法,并返回一個FileLock對象。
對于Log4j的使用場景,肯定是多線程并發(fā)的情況。第3種情況不用考慮。第二種情況比較復(fù)雜,所以只有第一種情況是適合的。Log4j也是采用了這一種方式。
可以把一個FileAppender對象理解成維護(hù)了一個打開文件對象,當(dāng)Logger在多線程情況下把日志寫入文件時,需要對Appender進(jìn)行同步,也就是說對Logger加鎖,保證使用同一個Logger對象時,一次只有一個線程使用這個FileAppender來寫文件,避免了多線程情況下寫文件錯誤。
就是下面這兩段代碼進(jìn)行的同步操作,但是這也是Log4j被詬病最多的地方
- Hierarchy.java
-
- // 多個線程使用同一個Logger時,加鎖
-
- public
- void callAppenders(LoggingEvent event) {
- int writes = 0;
-
- for(Category c = this; c != null; c=c.parent) {
- // Protected against simultaneous call to addAppender, removeAppender,...
- synchronized(c) {
- if(c.aai != null) {
- writes += c.aai.appendLoopOnAppenders(event);
- }
- if(!c.additive) {
- break;
- }
- }
- }
-
- if(writes == 0) {
- repository.emitNoAppenderWarning(this);
- }
- }
-
-
- AppenderSkeleton.java
-
- // 多個線程使用同一個Appender時,對Appender加鎖
-
- public
- synchronized
- void doAppend(LoggingEvent event) {
- if(closed) {
- LogLog.error("Attempted to append to closed appender named ["+name+"].");
- return;
- }
-
- if(!isAsSevereAsThreshold(event.getLevel())) {
- return;
- }
-
- Filter f = this.headFilter;
-
- FILTER_LOOP:
- while(f != null) {
- switch(f.decide(event)) {
- case Filter.DENY: return;
- case Filter.ACCEPT: break FILTER_LOOP;
- case Filter.NEUTRAL: f = f.getNext();
- }
- }
-
- this.append(event);
- }
這幾個鎖在高并發(fā)的情況下對系統(tǒng)的性能影響很大,會阻塞掉業(yè)務(wù)進(jìn)程。而日志收集工作應(yīng)該是作為一個輔助功能,不能影響主業(yè)務(wù)功能。
所以可以考慮從幾個方面對Log4j進(jìn)行擴(kuò)展
1. 同步操作改異步操作,將對業(yè)務(wù)線程的影響減到最小。比如使用一個緩沖隊列,Logger.debug操作只將LoggingEvent放入緩沖隊列就結(jié)束,然后用單獨的線程做消費者去消費緩沖隊列
2. 使用阻塞隊列來做緩沖,可以用基于數(shù)組的有界隊列的,內(nèi)存可控,但是在高并發(fā)下可能會阻塞生產(chǎn)者線程,也可以用基于鏈表的無界隊列,用內(nèi)存空間換性能
3. 消費這個緩沖隊列時,可以持續(xù)消費,也可以采用定時批量消費的方式。持續(xù)消費就是使用一個無限循環(huán)的線程,只要緩沖隊列不空,就從隊列中取LoggingEvent來寫文件。由于FileAppender維護(hù)了一個打開的FileOutputStream對象實例,不會重復(fù)執(zhí)行打開文件操作,也就是說只打開一次,然后一直寫,性能也可以接受。
定時批量消費就是采用一個定時的線程,一個時間段消費一次,一次消費一批數(shù)據(jù)。
Log4j本身就提供一個AsyncAppender類來異步收集日志。
1. 它采用阻塞式的有界緩沖隊列,但是沒有采用基于管城的BlockingQueue,而是使用了普通的ArrayList,并結(jié)合條件隊列操作wait, notifty來實現(xiàn)阻塞隊列。默認(rèn)容量是128個LoggingEvent
2. 包含了一個AppenderAttachableImpl,這是一個Appender的列表結(jié)構(gòu),可以包含多個Appender
3. 使用了Dispatcher線程來做消費者
4. 消費者采用持續(xù)消費的方式,只要緩沖隊列不為空,就喚醒消費者,先將buffer填充到一個數(shù)組中,然后單獨對這個數(shù)組消費,buffer可以繼續(xù)給生產(chǎn)者使用。
- public class AsyncAppender extends AppenderSkeleton
- implements AppenderAttachable {
-
- public static final int DEFAULT_BUFFER_SIZE = 128;
- private final List buffer = new ArrayList();
- private final Map discardMap = new HashMap();
- private int bufferSize = DEFAULT_BUFFER_SIZE;
- /** Nested appenders. */
- AppenderAttachableImpl aai;
-
- private final AppenderAttachableImpl appenders;
-
- public AsyncAppender() {
- appenders = new AppenderAttachableImpl();
- aai = appenders;
-
- dispatcher =
- new Thread(new Dispatcher(this, buffer, discardMap, appenders));
- dispatcher.setDaemon(true);
- dispatcher.setName("AsyncAppender-Dispatcher-" + dispatcher.getName());
- dispatcher.start();
- }
-
- private static class Dispatcher implements Runnable {
- private final AsyncAppender parent;
- private final List buffer;
- private final Map discardMap;
- private final AppenderAttachableImpl appenders;
-
- }
AsyncAppender的代碼比較老,可以使用ArrayBlockingQueue對其進(jìn)行改寫,減少條件隊列的操作。也可以進(jìn)一步優(yōu)化,采用無界的LinkedBlockingQueue,采用空間換性能的方式,這樣不會阻塞生產(chǎn)者線程,也就是不阻塞業(yè)務(wù)線程。只有當(dāng)LinedBlockingQueue為空時才會阻塞消費線程。這是可以接受的,因為消費線程不是業(yè)務(wù)線程,也防止了消費線程的空轉(zhuǎn)。
還可以使用定時批量處理的生產(chǎn)者消費者模式來異步處理線程,下面是一個簡單的基于定時線程池的定時批量異步日志收集器實現(xiàn)
1. 使用ScheduledExecutorService 定時線程池
2. 使用LinkedBlockingQueue無界阻塞隊列做緩沖,不會阻塞生產(chǎn)者線程
3. 定時執(zhí)行Dispatcher線程,每次把緩沖隊列填充到一個局部的列表,只對局部列表中的數(shù)據(jù)處理,緩沖隊列可以繼續(xù)被生產(chǎn)者使用
4. appenders上的鎖是防止添加刪除appender時出并發(fā)問題,實際上Logger一旦創(chuàng)建,很少會在運行時取修改appenders,所以這個鎖基本沒有影響
具體采用持續(xù)消費,還是定時批量消費,可以根據(jù)實際情況進(jìn)行選擇。定時批量消費時還可以優(yōu)化,比如先把批量的日志日志變成一個大日志,一次只寫一次文件文件,減少寫文件的次數(shù)。
最后看一下如何運行時創(chuàng)建Logger,而不是使用log4j.xml配置文件的方式
- static{
- Layout patternLayout = new PatternLayout();
- Appender appender = null;
- String fileName = Configuration.getInstance().getLogFileName();
- try {
- appender = new DailyRollingFileAppender(patternLayout, fileName, "'.'yyyy-MM-dd");
- } catch (IOException e) {
- e.printStackTrace();
- }
- log.addAppender(rtracerAppender);
- log.setLevel(Level.DEBUG);
- log.setAdditivity(false);
- }