Logback與Log4j2日志框架性能對比與調優方式

Posted on by

前言

看到目前線上大多日志框架測評大多從宏觀角度，直接對比異步同步的吞吐量，但是沒有考量到更深層的淘汰機制、等待策略、隊列長度等對性能表現的影響，因此本文將從更多的角度對比及分析兩款日志框架的性能表現，通過JProfiler+Jmeter壓測及數據采集，從線程占用、鎖占用、宏觀耗時等多維度可視化數據。

性能測試

logback

同步日志

耗時

在這裡插入圖片描述

在這裡插入圖片描述

未經過任何調優，采用Logback默認配置得出上圖，一百萬條日志打印耗時(ms)，如圖：單線程下性能最佳，耗時隨線程數增加而下降。

線程占用

單線程

在這裡插入圖片描述

無阻塞狀態

多線程

多線程打印日志時，會產生大量線程阻塞，線程越多阻塞狀態越多

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

鎖占用

在這裡插入圖片描述

線程發生多次占用鎖的情況。查看Logback源碼可得知，檢查容量、放入隊列、取出隊列都需要在取得鎖後進行

異步日志（隊列擴容）

樣本數100萬，隊列長度110萬

耗時

在這裡插入圖片描述

在這裡插入圖片描述

線程占用

單線程

在這裡插入圖片描述

多線程

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

鎖占用

在這裡插入圖片描述

每次寫入隊列都需要占用鎖，同時Appender從隊列取出也需要占用鎖

異步日志（半隊列擴容）

樣本數100萬，隊列長度50萬，不啟用拋棄策略

耗時

在這裡插入圖片描述

在這裡插入圖片描述

線程占用

單線程

在這裡插入圖片描述

多線程

寫入耗時明顯增長，寫入過程仍然發生阻塞狀態

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

鎖占用

在這裡插入圖片描述

log4j2

同步日志

樣本數100萬，Logger到Appender串行執行，輸出到文件

耗時

在這裡插入圖片描述

在這裡插入圖片描述

線程占用

線程產生長時間的等待，主要是緩沖環溢出後無法寫入，生產者根據等待策略進入等待狀態

單線程

在這裡插入圖片描述

單線程生產不需要爭搶鎖，因此全程無阻塞

多線程

整體來看，阻塞的時間隨著線程增多而增多，因此多線程對同步日志影響極大，性能損失嚴重

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

後續監控因阻塞時間太長跳過

鎖占用

在這裡插入圖片描述

阻塞在Appender上的輸出流上，輸出流是在單線程中執行的

異步日志（隊列擴容）

樣本數100萬，隊列長度110萬，使用Yield等待策略

耗時

在這裡插入圖片描述

在這裡插入圖片描述

單線程占用最高，耗時隨線程數增加而縮短，直到線程數超過CPU核數。單線程耗時與logback相當，多線程耗時比logback縮短瞭2倍

線程占用

單線程與多線程使用都無阻塞狀態，保證足夠的隊列容量，能使日志操作保持高吞吐和低延遲，避免阻塞等待

單線程

在這裡插入圖片描述

多線程

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

使用與宿主機CPU核數相等的線程數，日志寫入過程無阻塞、無線程切換

十六線程

在這裡插入圖片描述

異步日志（日志淘汰策略）

樣本數100萬，隊列長度50萬，啟用拋棄策略

耗時

在這裡插入圖片描述

在這裡插入圖片描述

線程占用

隊列長度50萬，正常來說應與半隊列擴容一樣，產生阻塞現象，但啟用瞭日志淘汰策略，無法寫入隊列的將直接拋棄不阻塞等待

單線程

在這裡插入圖片描述

多線程

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

異步日志（半隊列擴容）

樣本數100萬，隊列長度50萬，使用Yield等待策略

耗時

在這裡插入圖片描述

在這裡插入圖片描述

當隊列滿後，大幅影響瞭響應時間，吞吐量依賴Appender的消費性能

線程占用

單線程記錄日志時，前半段隊列未滿時生產線程一直處於工作狀態，後半段因消費能力跟不上生產能力，導致隊列滿載，生產線程開始出現等待狀態

單線程

在這裡插入圖片描述

等待的時間比多線程少，是因為單線程下日志生產速度慢，同時日志也在倍消費

多線程

前一段時間可以維持高性能工作，但後面隊列滿後開始發送等待，導致耗時延長

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

鎖占用

在這裡插入圖片描述

並未發現日志記錄過程中發生鎖占用

異步日志（等待策略）

樣本數100萬，隊列長度50萬，使用Timeout等待策略

耗時

在這裡插入圖片描述

在這裡插入圖片描述

線程占用

在這裡插入圖片描述

未產生阻塞狀態

單線程

多線程

因Timeout等待策略使用瞭鎖，因此產生一定的阻塞

四線程

在這裡插入圖片描述

八線程

在這裡插入圖片描述

十六線程

在這裡插入圖片描述

鎖占用

在這裡插入圖片描述

使用Timeout等待策略時，放入隊列前會取鎖，進行消費者線程喚醒動作

性能調優

異步日志

無論是logback還是log4j2，使用異步日志可以大幅提高日志操作耗時，間接提高業務方整體耗時

日志可靠性

異步日志無法保證日志可靠性，系統意外關閉會丟失隊列中的日志，因此要求高可靠的日志，應該選擇數據庫或者MQ來保證

Logback

通過

<appender name="async-log-all" class="ch.qos.logback.classic.AsyncAppender">

設置

Log4j2

通過

System.setProperty("Log4jContextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector")

設置

日志拋棄策略

將溢出隊列的日志拋棄，保持穩定的響應速度。對業務方來說能保持良好、穩定的日志服務，但需要容忍一定的日志丟

Log4j2

通過

System.setProperty("log4j2.AsyncQueueFullPolicy","Discard")

設置

Logback

通過&lt;discardingThreshold&gt;指定拋棄日志的閾值

拋棄邊界

當隊列剩餘容量小於閾值後，將拋棄ERROR以下的日志

禁用拋棄策略

設置為0則表示不拋棄，業務線程等待隊列空間可用後寫入

默認閾值

默認閾值為隊列長度的20%，隊列長度100閾值為20

日志等待策略

Log4j2獨有的特性，指定隊列滿時，生產者進行等待的行為，需要在不開啟拋棄策略下進行

TimeoutWaitStrategy

Log4j2默認的等待策略，通過Object.wait等待隊列騰空。在放入隊列時會加鎖，不推薦使用。

YieldWaitStrategy

通過

System.setProperty("log4j2.asyncLoggerWaitStrategy","Yield")

設置。通過System.yield()等待隊列騰空，比Timeout等待策略更高效，比Busy等待策略更節能

隊列容量

由性能測試可知，不適用日志拋棄策略下，隊列滿載後生產線程將阻塞等待隊列騰空，直接影響業務方的效率

Logback

通過<queueSize>指定隊列長度，Logback固定使用ArrayBlockingQueue作為隊列

Log4j2

通過

System.setProperty("log4j2.asyncLoggerRingBufferSize","x")

指定

二次方長度

RingBuffer內部計算位置時通過二進制方式計算，使用二的指數長度可以提高計算速度

長度計算公式

暫未找到統一標準的計算公式，本人覺得可以通過(日志峰值TPS#消費TPS)*15*60來計算

承載容量

這個公式的含義是：應用15分鐘以峰值去生產的日志可以全部被隊列容納

成本

從成本的角度看，隊列不應該無限量地預估，在保證系統不受到容量影響下，盡可能地使用小的長度，節省內存開支

響應時間

一般應用不應該長時間在峰值運行，如果出現長時間在峰值運行，則應該進行水平拓展分散請求壓力。因此容納15分鐘之內的峰值，可以有足夠時間讓運維響應，進行水平拓展分散壓力。

消費瓶頸

日志消費TPS由Appender消費效率決定，當日志TPS超過消費TPS時，日志將開始在隊列中堆積

消費TPS

某個Appender在一秒內消費的日志數量，舉FileAppender為例，每條日志消費花費100微妙(性能好的主機可以到60)，一秒可以消費1萬條日志，即消費TPS為1萬

請求TPS

一般Web應用不會承載超過消費TPS的流量。假設每個請求打印五條日志，則需要5000以上的TPS才能產生日志堆積

消費者優化

日志TPS長時間(15min+)超過消費TPS的場景下，應該對消費能力進行優化，使用輕量級的Appedner、簡單的Layout、日志拋棄策略、過濾器、業務方規范等方面進行優化

以上為個人經驗，希望能給大傢一個參考，也希望大傢多多支持WalkonNet。

推薦閱讀：