本篇文章帶給大家的內容是關於logback日誌非同步列印的方法介紹(程式碼範例),有一定的參考價值,有需要的朋友可以參考一下,希望對你有幫助。
最近碰到一個問題:客戶的伺服器程式偶爾出現請求回應過慢的情況,透過查看日誌發現RSA驗證簽章的程式碼執行超過20秒,而正常情況下只需要16毫秒。
RSA憑證是伺服器啟動就載入好的,不存在讀檔慢的問題。看了一下那幾行程式碼,最有嫌疑的就是logback日誌列印的程式碼了。
查看了生產日誌配置,logback.xml裡配置為,每月產生一個資料夾,當月的日誌檔案都在同一資料夾下,例如201901資料夾下是2019年1月的所有日誌文件。每個檔案配置為*.log.zip後綴,大小為10MB,也就是說10MB為大小分隔檔。日誌列印類別配置的是RollingFileAppender。
2019-1-30那一天,2019年1月資料夾下已經產生了5000多個日誌文件,平均每天167個日誌文件。
所以懷疑是日誌檔案太多,索引檔案的時間太長導致程式碼執行變慢,也就是說,要這樣懷疑的話,那就有一個前提:日誌列印是同步的,呼叫列印日誌的那行程式碼執行完了寫入檔案後,才會繼續向下執行業務程式碼。
我問了好幾個同事,都給我說日誌列印是非同步執行的,只有一個朋友說是同步的。我們都會以為列印日誌寫檔案比較消耗時間,日誌框架應該不會同步去寫檔案吧。然而事實卻是如果不配置非同步列印方式的話,就是以同步方式進行的日誌印製的。
斷點跟進程式碼發現是同步執行日誌寫入檔案的,只有當設定的appender是AsyncAppender時,日誌列印才是按照非同步方式列印的。
下面是同步列印日誌的情況:
logback.xml設定:
#<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> ...... </appender> <root level="DEBUG"> <appender-ref ref="CONSOLE"/> </root>##執行程式碼:
LogWork.debug("111111111111"); System.out.println("2222222222222");運行結果: #可以看到,執行結果是先把日誌框架的日誌列印執行完,再執行後面的業務代碼的。所以是同步的。
下面是配置非同步列印日誌類別的方法:
非同步列印日誌類AsyncAppender需要引用一個其他的日誌列印類,ASYNC只需要把需要列印的日誌寫入定義好的快取佇列裡,然後開啟一個守護執行緒去佇列裡取得日誌呼叫CONSOLE日誌列印器去寫入檔案。這樣日誌列印就是非同步進行的了。 logback.xml設定:<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> ...... </appender> <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender"> <discardingThreshold>0</discardingThreshold> <queueSize>100</queueSize> <neverBlock>true</neverBlock> <appender-ref ref="CONSOLE"/> </appender> <root level="INFO"> <appender-ref ref="ASYNC"/> </root>#執行程式碼:
LogWork.debug("111111111111"); System.out.println("2222222222222");################ ##運行結果:###############運行結果說明,呼叫日誌框架列印的程式碼執行後只是把要列印的日誌放入快取佇列,然後就繼續向下執行後面的程式碼,所以才先列印了後面的222222,之後才列印111111。說明是現在經過配置,日誌列印非同步工作的。 ######因文章開頭的問題引出了對日誌列印同步性的問題,所以研究了一番,不過最終也沒有和遇到的問題聯繫起來,因為就算知道了日誌是同步打印的,也沒辦法解釋為什麼偶爾出現幾分鐘程式碼執行特別慢。證據不充分,所以沒辦法給結論。 ###
以上是logback日誌非同步列印的方法介紹(程式碼範例)的詳細內容。更多資訊請關注PHP中文網其他相關文章!