你的Java日誌，有沒有用這些改進辦法

標籤：

轉自【http://mp.weixin.qq.com/s?__biz=MjM5MDE0Mjc4MA==&mid=207451012&idx=1&sn=de9fba4eda0f221363b6d5ae54243416&scene=2&from=timeline&isappinstalled=0#rd】

摘要：

 

在任何系統中，日誌都是非常重要的組成部分，它是反映系統運行情況的重要依據，也是排查問題時的必要線索。絕大多數人都認可日誌的重要性，但是又有多少人仔細想過該怎麼打日誌，日誌對效能的影響究竟有多大呢？今天就讓我們來聊聊Java日誌效能那些事……

 

說到Java日誌，大家肯定都會說要選擇合理的記錄層級、合理控制日誌內容，但是這僅是萬裡長征第一步……哪怕一些DEBUG層級的日誌在生產環境中不會輸出到檔案中，也可能帶來不小的開銷。我們撇開判斷和方法調用的開銷，在Log4J 2.x的效能文檔中有這樣一組對比：

 

logger.debug("Entry number: " + i + " is " +  String.valueOf(entry[i])); 
logger.debug("Entry number: {} is {}", i, entry[i]);

 

 

上面兩條語句在日誌輸出上的效果是一樣的，但是在關閉DEBUG日誌時，它們的開銷就不一樣了，主要的影響在於字串轉換和字串拼接上，無論是否生效，前者都會將變數轉換為字串並進行拼接，而後者則只會在需要時執行這些操作。Log4J官方的測試結論是兩者在效能上能相差兩個數量級。試想一下，如果某個對象的toString()方法裡用了ToStringBuilder來反射輸出幾十個屬性時，這時能省下多少資源。

 

因此，某些仍在使用Log4J 1.x或Apache Commons Logging（它們不支援{}模板的寫法）的公司都會有相應的編碼規範，要求在一定層級的日誌（比如DEBUG和INFO）輸出前增加判斷：

 

if (logger.isDebugEnabled()) {     logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i])); }

 

除了記錄層級和日誌訊息，通常在日誌中還會包含一些其他資訊，比如日期、線程名、類資訊、MDC變數等等，根據Takipi的測試，如果在日誌中加入class，效能會急劇下降，比起LogBack的預設配置，輸送量的降幅在6成左右。如果一定要列印類資訊，可以考慮用類名來命名Logger。

 

在分布式系統中，一個請求可能會經過多個不同的子系統，這時最好產生一個UUID附在請求中，每個子系統在列印日誌時都將該UUID放在MDC裡，便於後續查詢相關的日誌。《The Ultimate Guide: 5 Methods For Debugging Production Servers At Scale》一文中就如何在生產環境中進行調試給出了不少建議，當中好幾條是關於日誌的，這就是其中之一。另一條建議是記錄下所有未被捕獲的日誌，其實拋出異常有開銷，記錄異常同樣會帶來一定的開銷，主要原因是Throwable類的fillInStackTrace方法預設是同步的：

 

public synchronized native Throwable fillInStackTrace();

 

 

一般使用logger.error都會打出異常的堆棧，如果對輸送量有一定要求，在情況運行時可以考慮覆蓋該方法，去掉synchronized native，直接返回執行個體本身。

 

聊完日誌內容，再來看看Appender。在Java中，說起IO操作大家都會想起NIO，到了JDK 7還有了AIO，至少都知道讀寫加個Buffer，日誌也是如此，同步寫的Appender在高並發大流量的系統裡多少有些力不從心，這時就該使用AsyncAppender了，同樣是使用LogBack：

 

在10線程並發下，輸出200字元的INFO日誌，AsyncAppender的輸送量最高能是FileAppender的3.7倍。在不丟失日誌的情況下，同樣使用AsyncAppender，隊列長度對效能也會有一定影響。

 

如果使用Log4J 2.x，那麼除了有AsyncAppender，還可以考慮效能更高的非同步Logger，由於底層用了Disruptor，沒有鎖的開銷，效能更為驚人。根據Log4J 2.x的官方測試，同樣使用Log4J 2.x：

 

64線程下，非同步Logger比非同步Appender快12倍，比同步Logger快68倍。

 

同樣是非同步，不同的庫之間也會有差異：

 

同等硬體環境下，Log4J 2.x全部使用非同步Logger會比LogBack的AsyncAppender快12倍，比Log4J 1.x的非同步Appender快19倍。

 

 

Log4J 2.x的非同步Logger效能強悍，但也有不同的聲音，覺得這隻是個看上去很優雅，只能當成一個玩具。關於這個問題，還是留給讀者自己來思考吧。

 

如果一定要用同步的Appender，那麼可以考慮使用ConsoleAppender，然後將STDOUT重新導向到檔案裡，這樣大約也能有10%左右的效能提升。

 

大部分生產系統都是叢集部署。對於分布在不同伺服器上的日誌，用Logstash之類的工具收集就好了。很多時候還會在單機上部署多執行個體以便充分利用伺服器資源，這時千萬不要貪圖日誌監控或者日誌查詢方便，將多個執行個體的日誌寫到同一個記錄檔中，雖然LogBack提供了prudent模式，能夠讓多個JVM往同一個檔案裡寫日誌，但此種方式對效能同樣也有影響，大約會使效能降低10%。

 

如果對同一個記錄檔有大量的寫需求，可以考慮拆分日誌到不同的檔案。做法之一是添加多個Appender，同時修改代碼，不同的情況使用不同Logger；LogBack提供了SiftingAppender，可以直接根據MDC的內容拆分日誌，Jetty的教程中就有根據host來拆分日誌的範例，而根據Takipi的測試，SiftingAppender的效能會隨著拆分檔案數的增長一同提升，當拆分為4個檔案時，10並發下SiftingAppender的輸送量約是FileAppender的3倍多。

 

看了上面這麼多的資料，不知您是否覺得自己的日誌有不少改進的餘地，您還沒有把系統最佳化到極致，亦或者您還有其他日誌最佳化的方法，不妨分享給大家。

 

 

回複關鍵詞查看對應內容：

React | 架構師 | 營運 | 雲 | 開源 | Kubernetes | 架構 | 人工智慧 | Kafka | Docker | Netty | CoreOS | QCon | Github | Swift | 敏捷 | 語言 | 程式員 | 實踐 | 物聯網 |

 

 

如果想要評論本篇文章，直接戳右下角的“評論”。發表觀點和建議，我們一直在尋找的技術人中的KOL，也許就是你！

 

 

著作權及轉載聲明：

 

極客邦科技專註為技術人提供優質內容傳播。尊重作者、譯者、及InfoQ網站編輯的勞動，所有內容僅供學習交流傳播，不支援盜用。未經許可，禁止轉載。若轉載，需予以告知，並註明出處。

你的Java日誌，有沒有用這些改進辦法