- 生產環境日誌級別為info,請看如下這行程式碼:
LOGGER.debug("the DTO info: {}", JSON.toJSONString(DTO));
這段程式碼主要有兩個需要注意的地方:
- 日誌級別為info,而線上環境是warn級別。我們可以得出結論,線上環境肯定不會輸出這行日誌。
- 列印日誌的行為中有JSON序列化動作。
第二點是此文的關鍵。我們假設DTO是一個很小的物件,JSON序列化時間以及開銷可以忽略不計,那麼這行程式碼依然沒有問題。但是,如果DTO是一個很大的物件,比如10k,甚至100k,即使快如fastjson,其耗時依然高達數百毫秒,並且非常消耗CPU。如果是在高併發的系統中,這麼大的開銷完全不可接受,甚至可能就會拖垮整個系統。
有同學就會說了,我不是info日誌麼,為什麼還會執行這行程式碼?請繼續往下看。我們首先看一下slf4j中logger.info()這個方法是如何申明的:第二個引數為Object型別。我們的程式碼中傳遞給第二個引數的值為:JSON.toJSONString(DTO),很明顯這行程式碼是傳遞一個String型別的欄位給Object arg。那麼String如何來呢?答案也很明顯,必須先執行JSON序列化才能得到String,所以不論日誌是否列印,JSON序列化都會執行。那麼logger.info這個info在什麼時候起作用呢?答案是它只能 在輸出日誌這個動作時起作用:
2. 解決方案
如何解決這個問題?很簡單,在輸入日誌時加個級別判斷(需要說明的是,這種規範很容易被忽略,比如專案成員更替時,很容易引入有問題的程式碼。所以筆者寫了一段指令碼:掃描所有Java程式碼,如果logger.info()中有JSON序列化動作,那麼必須判斷優先順序後才能輸出日誌。即可以簡單的認為它的前一行程式碼必須是logger.isInfoEnabled()。如果你的專案有CICD環境,那麼把這段指令碼整合到掃描規範中,才是解決這個問題最完美的方案):
if (LOGGER.isInfoEnabled()) {
LOGGER.info("the DTO info: {}", JSON.toJSONString(DTO));
}