天天看點

從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro

作者:從頭開始自學java

從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchronized同步調用,再結合上文發現每兩分鐘寫滿一個500MB日志檔案的現象,初步懷疑是日志量過大導緻了線程阻塞。

AsyncAppender顧名思義是個異步Appender,采用異步方式處理日志,在其内部維護了一個BlockingQueue隊列,每次處理日志時,都先嘗試把Log4jLogEvent事件存入隊列中,然後交由背景線程從隊列中取出事件并處理(把日志交由AsyncAppender所關聯的Appender處理),但隊列長度總是有限的,且隊列預設大小是128,如果日志量過大或日志異步線程處理不及時,就很可能導緻日志隊列被打滿。

當日志隊列滿時,日志架構内部提供了兩種處理方式,具體如下:

如果blocking配置為true,會選擇相應的處理政策,預設是SYNCHRONOUS政策,可以在log4j2.component.properties檔案中,通過log4j2.AsyncQueueFullPolicy參數配置日志架構提供的其他政策或自定義政策。

DISCARD政策,直接忽略日志。

SYNCHRONOUS政策,目前線程直接發送日志到Appender。

ENQUEUE政策,強制阻塞入隊。

如果blocking配置為false,則由ErrorHandler和ErrorAppender處理失敗日志。日志架構提供了預設的ErrorHandler實作,即DefaultErrorHandler,目前暫不支援業務在XML、JSON等日志配置檔案裡自定義ErrorHandler。日志架構預設不提供ErrorAppender,業務如有需要可在XML、JSON等日志配置檔案裡自定義error-ref配置。

DefaultErrorHandler内部在處理異常日志時增加了條件限制,隻有下述兩個條件任一滿足時才會處理,進而避免大量異常日志導緻的性能問題。

兩條日志處理間隔超過5min。

異常日志數量不超過3次。

但項目所用日志架構版本的預設實作看起來存在一些不太合理的地方:

lastException用于标記上次異常的時間戳,該變量可能被多線程通路,無法保證多線程情況下的線程安全。

exceptionCount用于統計異常日志次數,該變量可能被多線程通路,無法保證多線程情況下的線程安全。

是以,在多線程場景下,可能有大量異常日志同時被DefaultErrorHandler處理,帶來線程安全問題。值得一提的是,該問題已有相關Issue: DefaultErrorHandler can not share values across threads回報給社群,并在2.15.0版本中進行了修複。

從上述DefaultErrorHandler代碼中可以看到,真正負責處理日志的是StatusLogger,繼續跟進代碼進入logMessage方法,方法執行邏輯如下:

如果StatusLogger内部注冊了StatusListener,則由對應的StatusListener負責處理日志。

否則由SimpleLogger負責處理日志,直接輸出日志到System.err輸出流。

從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro
從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro
從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro
從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro
從Blocked線程堆棧着手分析,檢視PrintStream相關代碼片段如下圖5所示,可以看到被阻塞地方有synchro

繼續閱讀