作者： 詹嵩 某公司架構部中介軟體架構師

校對：程超 某公司架構部中介軟體負責人

一、logback和log4j2壓測比較

1、logback壓測資料

logback壓測資料，50個執行緒，500萬條日誌寫入時間。

logback:messageSize = 5000000,threadSize = 50,costTime = 27383ms
logback:messageSize = 5000000,threadSize = 50,costTime = 26391ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25373ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25636ms
 

logback:messageSize = 5000000,threadSize = 50,costTime = 25525ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25775ms
logback:messageSize = 5000000,threadSize = 50,costTime = 27056ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25741ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25707ms
logback:messageSize = 5000000,threadSize = 50,costTime = 25619ms
 

說明：
這個是logback日誌的壓測資料，在開發機（雙核四執行緒），高配開發機（四核八執行緒）和伺服器（32核）壓測的效率都差不多，而且執行緒開多的時候，效能反而有下降，壓測資料如下：

logback:messageSize = 5000000,threadSize = 100,costTime = 33376ms

這個是在32核機器上壓測的平均值，高於開發機。

2、log4j2壓測資料

log4j2壓測資料，因測試資料會佔用一些篇幅，這裡僅取中位數，但上下差距並不大

log4j2:messageSize = 5000000,threadSize = 100,costTime = 15509ms   ---開發機   

log4j2:messageSize = 5000000,threadSize = 100,costTime = 5042ms  ---高配開發機
 


log4j2:messageSize = 5000000,threadSize = 100,costTime = 3832ms  ---伺服器

本次壓測，基本上與log4j2官網資料吻合，經過驗證非同步日誌確實可以極大的提高IO效率

下圖為同步、非同步、只非同步appender的效能對比

Async loggers have much higher throughput than sync loggers.

和其他日誌框架的對比：

Async loggers have the highest throughput.

從本次壓測中，也得知確實在同步日誌寫到一定程度下，會大大的影響伺服器的吞吐率，各位同學可以根據自己專案的情況，做日誌上的優化。

下圖為併發量大時，日誌框架對系統吞吐率產生的影響，這裡看logback和log4j確實影響很大，但實際情況中，感受到的要遠遠小於此圖。

二、壓測配置

log4j2的效率可以在多執行緒時，線上程數量大的情況下，超過logback10倍左右！500萬資料大概0.25G，只需3秒左右就可以寫進磁碟。

在配置上，首先第一條建議是如果做非同步，那麼所有的日誌都是非同步寫，這樣的效能指數的增長是量級的。當然也可以混合部署，但是效能影響就沒有全部非同步這麼明顯。

配置上，優化一定的屬性，對效能也有一定的影響。

log4j2本身提供了20多種appender供使用者選用，但一般開發中採用的就是RollingRandomAccessFile，該元件有多個屬性配置，常用的做一下說明（其他配置對效能意義不大，有興趣的同學可自己去官網檢視）

一般採用預設值，除非系統寫日誌的IO影響了主執行緒的執行，可以調大該配置。
本次壓測採用的日誌配置

在asyncRoot中可以新增includeLocation="true"屬性，該屬性如果為true，可以攜帶類名和行號等資訊，但是抽取這些資訊，會有一些效能損耗

log4j2改版以後，元件和功能極大豐富，有興趣的同學可以去官網http://logging.apache.org/log4j/2.x/manual/index.html或找我來一起交流。

三、disruptor佇列

檢視底層程式碼，log4j2之所以能在非同步寫日誌時效能提高這麼多，離不開優秀的mq元件disruptor。

目前使用該佇列的知名軟體包括但不限於Apache Storm、Camel、Log4j 2。

由於時間有限，本篇著重講解底層佇列的實現，因為這個對效能的影響是最大的。

以此圖為例：

Async loggers have much higher throughput than sync loggers.

同步效能最差，非同步全域性非同步的效能接近非同步appender的10倍，同樣是非同步實現的，為何效能有如此大的差距？

去看原始碼：

以上是非同步Appender的實現，可以看到，內部內建了一個BlockingQueue佇列，具體實現採用了ArrayBlockingQueue

接著是全域性非同步loggers的實現方式，可見內部的佇列使用的是disruptor。

效能上的優劣，絕大部分原因都是資料模型的問題，往下我們分析一下BlockingQueue和disruptor的實現方式，由於篇幅有限，從JDK原始碼來看：

1、ArrayBlockingQueue

可以看到ArrayBlockingQueue採用的是加鎖的方式來處理執行緒安全問題的。

加鎖的問題，雖然歷代JDK一直投入大量的精力去解決問題，比如優化Sync關鍵字的實現方式、新增讀寫鎖等，但是由於結構特性的問題，一直無法從根本上解決效能開銷問題。

題外話 ^_ 除了鎖的問題，還牽涉到底層CPU在計算時讀取記憶體資料的問題。

舉個例子：當你遍歷一個數組時（陣列在CPU計算時，是簡單資料結構），你讀取到第一個元素時，其他元素也會相應的放入1級快取（距離CPU最近），所以你遍歷資料的方式是最快的，這就是簡單資料結構的優勢。

但是如果你在操作一個Queue時，一般會涉及幾個變數，這裡以ArrayBlockingQueue為例：

這裡有三個變數，分別代表了下一個要出的元素下標，要進的元素下標和長度

當然，這幾個簡單型別是非常容易放入1級快取並進行高速計算的，但是問題是，這個Queue是一個生產者和消費者的模型，牽涉到兩端操作，於是當生產者寫入元素時，takeIndex和putIndex數值發生改變，消費者在消費時要拿的takeIndex也跟著改變，這時就需要去主存中重新去取takeIndex，而無法利用1級快取進行高速計算。

以上大致解釋了ArrayBlockingQueue的效能劣勢，接下來就看disputor如果解決這些問題。

2、Disputor

引入官網的一段話（首先要明白背景和訴求）：

這裡的表述和我們的目標一致，都是要解決鎖和快取缺失帶來的效能開銷問題。

引用幾張官網的截圖（風格還比較有趣）：

https://www.slideshare.net/trishagee/introduction-to-the-disruptor?from=new_upload_email   這是該PPT的地址，有興趣的同學可以關注下。

他們採用了環形資料結構來解決這個問題（他們稱之為魔法圓環，或魔法圓圈之類的），此種資料結構的有點是，不需要記錄額外的下標，直接由JNI返回可以操作的地址，然後當多執行緒併發讀寫的時候，使用的也是CAS方式。

這樣，不能使用1級快取和加鎖操作的問題就解決了（關於CAS大家可自行谷歌，有非常多的文章來介紹）。

由於篇幅和經歷有限，本次分享先寫到這裡，如果之後對disruptor有需要的話，可以再次深入研究。

Tips：加入中生代架構群，新增群管微信：zsdwyq，註明姓名-公司-技術方向