近一年多以來想要分享知識的欲望降低了許多，不知道是否是近一年來工作較忙的原因，導致整個21年沒有對外輸出什么內容，唯一的一篇 “Log4j2 Jndi 漏洞原理解析、復盤” 還是在趁熱想抓波熱點的情況下寫的這篇文章（21年12月10號爆出漏洞、11號公司內修復、12號凌晨05:00趁熱發布文章，發布完以后直接埋頭睡了一天，現在想來簡直喪心病狂！）。
轉眼已經到了2022，復盤2021的時候會發現並非如此，整個2021年是有做很多輸入的，但由於並沒有對外輸出，而只是將對應的內容簡單的記錄到了自己的筆記中，導致回頭再看時，會發現筆記中的很多內容並不系統，只是記錄了一個點的問題，而非面。
輸出是一個很好的習慣，輸入並輸出的過程也是在不斷的翻新自我知識體系的過程，在持續輸出的過程中，不僅幫助了自己也可能會幫助到他人。一舉多得。
所以，就用這篇來作為2022年博客園的第一篇吧，GO，GO！ （PS：該篇文章已經在筆記中躺了有段時間了、略微整理后，重新分享出來。）
背景
公司當前日志平台一天所沉淀的業務日志有近600億條，40T左右的大小，隨着公司內降本增效的事項推進，再加上業務方業務日志越來越多等問題，導致整個日志平台的資源是越發緊張的。
為了約束業務團隊的日志數量，除了一些硬性的手段（日志SDK端采樣、服務端采樣、成本平攤），以及通過一些硬性的指標，要求業務團隊的日志條數鏈路比、日志大小鏈路比 必須控制在一個合理的范圍內之外，還需要一些小的科普。
而這個科普便是這次內容的主題 “日志最佳實踐”，目的是為了讓部分研發知曉：“噢，日志原來也是要像代碼一樣不斷優化的啊”。
前言
日志用來記錄用戶操作、系統運行狀態等，是一個系統的重要組成部分。然而，由於日志通常不屬於系統的核心功能，所以常常不被團隊成員所重視，在出現問題需要通過日志來定位時，才發現日志還存在很多問題；日志記錄的好壞直接關系到系統出現問題時定位的速度，同時通過對日志的監控和分析，可以提前發現系統可能的風險，避免線上事故的發生。
現階段我們的監控系統已經為我們的服務穩定性提供了較強的支撐，其中實時的異常大盤、日志的異常告警、日志的統一收集檢索以及日志和鏈路的串聯等功能為我們在微服務體系下問題的診斷提供了快速的排查方案。但隨着時間的推移，代碼中的日志質量持續降低（當項目變大時，項目的代碼也存在一樣的問題，越寫越亂）。隨着越來越多不規范的日志開始出現，除了會增加監控系統的承壓，還會對線上的問題定位、穩定性監控等造成干擾。所以，日志的優化則勢在必行，一方面監控系統降壓降本，另一方面增加線上服務的穩定性及故障快速定位的能力。
原創聲明：作者：陳咬金、 博客地址：https://www.cnblogs.com/zh94/
日志的分類
日志從功能來說，可分為診斷日志、統計日志、審計日志。
診斷日志， 典型的有：
- 請求入口和出口
- 外部服務調用和返回
- 資源消耗操作: 如讀寫文件等
- 容錯行為：如雲硬盤的副本修復操作
- 程序異常： 如數據庫無法連接
- 后台操作：定期執行刪除的線程啟動、關閉、配置加載
統計日志：
- 用戶訪問統計：用戶IP、上傳下載的數據量，請求耗時等。（常用的Log Metric 則是統計日志）
審計日志：
- 管理操作、系統安全事件、非法訪問記錄等
需要避免的日志記錄方式
在寫代碼的過程中，統計和審計日志是帶有強烈目的性、功能性的，比如：用戶訪問統計的圖表，非法訪問的記錄等。
但是針對診斷日志則不然，由於我們無法確定系統在具體哪行代碼中會出現異常，所以診斷日志的添加也就因人而異，不同研發的風格，喜歡在不同的代碼處增加診斷日志。
比如：有些研發同學喜歡在方法的入口處增加日志，有些研發則是在可能會出現不確定性的判斷體中增加日志。這些都沒問題，畢竟某塊代碼哪里最容易出現問題，最需要診斷日志，這些只有具體的研發才知曉。
但是我們需要約束並避免的情況是：
1、日志中不要記錄無用的信息
如下圖中的服務日志：單條日志的長度已經超出了5000的長度，並已經觸發了服務端的日志截斷操作。（既然是診斷日志，應該是診斷該方法內的部分屬性，或者可能出現問題的屬性，而不應該是全部輸出）
2、不要記錄無用的日志（不利於問題分析診斷的日志）
如下圖中：日志Msg為 “threadLocal進行清除”這段日志，如果說這段日志有沒有意義？“有的”，這段日志表示 threadLocal被清除了，很直接明了。但是如果說這段日志對問題的分析診斷有沒有作用？作用極小。
假設這里 ThreadLocal remove() 的操作執行前是有 If 判斷，判斷為 true 時，則執行ThreadLocal 清除，那么對應的日志應該是添加到 else 代碼塊中，如果判斷條件為 false，則 else 代碼中輸出 WARN 日志，或者 ERROR 日志，表示此處存在風險或者異常需要進行關注，而不是在此處增加 INFO 日志，告知對應的研發或者測試同學 “ThreadLocal 清除成功了”。
ThreadLocal remove() 這個代碼塊被執行，是一個必然為真的操作，如果存在對應清除失敗的情況，應該最終是會體現在對應的異常當中。所以針對這樣一個必然為真的代碼一定要增加對應的日志，那么最好的方式是調整日志級別為DEBUG。
3、能夠放在一條日志中的信息，盡量放在一條日志當中，而不要放在多條日志中進行輸出。
4、日志內容中不能包含敏感性信息
原創聲明：作者：陳咬金、 博客地址：https://www.cnblogs.com/zh94/
日志的持續優化
理想中的日志應該是不多不少的狀態，太多的信息則是噪音，太少的信息又不夠充分，我們需要在實際的運維過程中，結合線上問題的定位，不斷地進行優化。最關鍵的一點是，團隊要重視日志優化這件事情，不要讓日志的質量持續降低。
此處推薦如下幾個較好的實踐：
- 在定位問題的過程中完善日志，如果定位問題花費了很長時間，那就說明系統日志還存在問題，需要進一步完善和優化；
- 需要思考是否可以通過優化日志，來提前預判該問題是否可能發生（如某種資源耗盡而導致的錯誤，可以對資源的使用情況進行記錄）
- 定義好整個團隊記錄日志的規范，保證每個開發記錄的日志格式統一；特別需要說明的是，對於DEBUG/TRACE級別的日志，也需要定義好清晰的格式，而不是由研發人員自由發揮；
- 整個團隊（包括開發，運維和測試）定期對記錄的日志內容進行Review；
- 開發做運維、測試，通過在查問題的過程來優化日志記錄的方式；
- 測試在日志中發現的問題，都需要及時向開發人員反映；
1、輸出日志時要考慮日志的使用者，例如如果日志需要由系統的測試人員來看，那就不能輸出：
2022-03-01 14:08:16.244 WARN [http-nio-20959-exec-86] com.ymm.ability.IdentifyValidateAbility ErrorCode:1426
至少應該是：
2022-03-01 14:08:16.244 WARN [http-nio-20959-exec-86] com.ymm.ability.IdentifyValidateAbility ErrorCode:1426, Message: callback request (to http://example.com/callback) failed due to socket timeout
這樣測試人員一眼就能清楚問題的原因，而不需要再通過開發來查看ErrorCode對應的具體錯誤。
2、日志的記錄信息要完整，尤其是針對異常的日志而言，如：
- 在持久化數據修改時記錄修改前和修改后的值。
- 記錄關鍵參數，出錯時的關鍵原因等。
- 記錄對應的異常代碼執行前的上下文信息。
關於日志級別
-
FATAL — 表示需要立即被處理的系統級錯誤。當該錯誤發生時，表示服務已經出現了某種程度的不可用，系統管理員需要立即介入。這屬於最嚴重的日志級別，因此該日志級別必須慎用，如果這種級別的日志經常出現，則該日志也失去了意義。通常情況下，一個進程的生命周期中應該只記錄一次FATAL級別的日志，即該進程遇到無法恢復的錯誤而退出時。當然，如果某個系統的子系統遇到了不可恢復的錯誤，那該子系統的調用方也可以記入FATAL級別日志，以便通過日志報警提醒系統管理員修復；
-
ERROR — 該級別的錯誤也需要馬上被處理，但是緊急程度要低於FATAL級別。當ERROR錯誤發生時，已經影響了用戶的正常訪問。從該意義上來說，實際上ERROR錯誤和FATAL錯誤對用戶的影響是相當的。FATAL相當於服務已經掛了，而ERROR相當於好死不如賴活着，然而活着卻無法提供正常的服務，只能不斷地打印ERROR日志。特別需要注意的是，ERROR和FATAL都屬於服務器自己的異常，是需要馬上得到人工介入並處理的。而對於用戶自己操作不當，如請求參數錯誤等等，是絕對不應該記為ERROR日志的；
-
WARN — 該日志表示系統可能出現問題，也可能沒有，這種情況如網絡的波動等。對於那些目前還不是錯誤，然而不及時處理也會變為錯誤的情況，也可以記為WARN日志，例如一個存儲系統的磁盤使用量超過閥值，或者系統中某個用戶的存儲配額快用完等等。對於WARN級別的日志，雖然不需要系統管理員馬上處理，也是需要及時查看並處理的。因此此種級別的日志也不應太多，能不打WARN級別的日志，就盡量不要打；
-
INFO — 該種日志記錄系統的正常運行狀態，例如某個子系統的初始化，某個請求的成功執行等等。通過查看INFO級別的日志，可以相對較快的對系統中出現的 WARN,ERROR,FATAL錯誤進行定位。INFO日志不宜過多，通常情況下，INFO級別的日志應該不大於TRACE日志的10%；
-
DEBUG OR TRACE — 這兩種日志具體的規范應該由團隊自己定義，該級別日志的主要作用是對系統每一步的運行狀態進行精確的記錄。通過該種日志，可以查看某一個操作每一步的執 行過程，可以准確定位是何種操作，何種參數，何種順序導致了某種錯誤的發生。可以保證在不重現錯誤的情況下，也可以通過DEBUG（或TRACE）級別的日志對問題進行診斷。需要注意的是，DEBUG日志也需要規范日志格式，應該保證除了記錄日志的開發人員自己外，其他的如運維，測試人員等也可以通過 DEBUG（或TRACE）日志來定位問題；
原創聲明：作者：陳咬金、 博客地址：https://www.cnblogs.com/zh94/
INFO和DEBUG
了解了上述日志級別的含義后，可能仍然會存在的一個問題是，INFO和DEBUG到底如何區分？我覺得這個日志既可以是INFO也可以是DEBUG？如何處理？
此處簡單給出一些參考：
對於業務系統來說，INFO 日志應該看起來像一本書。它應該告訴你發生了什么，而不一定是如何發生的，比如：
INFO | 發送用戶注冊郵件通知。[user="Thomas", email="thomas@tuhrig.de"]
INFO | 郵件發送給用戶 [user="Thomas"]
INFO | 發送用戶取消關注郵件通知。[user="Thomas", email="thomas@tuhrig.de"]
而對於系統當中的技術細節，則通常更應該使用DEBUG日志，DEBUG 日志可以更詳細地了解該過程的工作方式
DEBUG | 將用戶信息發送進MQ通知列表。[user="Thomas", email="thomas@tuhrig.de"]
INFO | 發送用戶注冊通知 [user="Thomas", email="thomas@tuhrig.de"]
DEBUG | 開始發送當天郵件通知的定時任務。 [subscribers=24332]
INFO | 郵件發送給用戶 [user="Thomas"]
INFO | 發送用戶取消關注郵件通知。 [user="Thomas", email="thomas@tuhrig.de"]
想象一下，你在瀏覽INFO日志的時候，是在查看該系統的運行狀態，此時看INFO日志更關注的是系統的運行指標，而並非那些技術上的細節是否執行成功。對應的技術細節是否執行成功應該是體現在對應的DEBUG日志當中，通過瀏覽DEBUG日志以此來對系統的運行進行精確的記錄和診斷。
所以，類似於上面最初所提到的“ threadLocal 清除成功”這種日志，如果有必須存在的意義，則應該是添加到DEBUG級別當中更為合適。
而對於技術類系統來說，比如中間件，工具類，公共服務等來說，INFO級別的日志同樣應該是告訴你發生了什么，而不是對應的技術細節。
比如：
- 遠程加載了對應的配置文件，那么此時 INFO 輸出該配置文件的內容則沒有問題。
- JVM啟動成功后，會有一個INFO級別的 Started Application in 35.499 seconds (JVM running for 45.536) 來表示JVM啟動成功，但JVM是不會把類的加載過程 INFO 輸出出來，因為對於INFO日志來說，並不關注這個。
- MVC的服務在服務啟動后，同樣會使用INFO級別的日志，將加載成功的Controller接口輸出出來，而並不會通過INFO來告知使用方Controller的加載細節。
2022-03-01 15:18:03,553 INFO [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping] [main] Mapped "{[/nondestructive/release/health/check],methods=[POST],consumes=[application/json;charset=UTF-8],produces=[application/json;charset=UTF-8]}"
所以基於上述的一些內容，我們可以得到一些共性的認知，INFO級別的日志更應該關注的是系統中發生了什么較為重要的事件，需要讓日志的查看者關注到這些信息。而不是技術的執行細節上執行了那些流程。執行細節應該是由DEBUG日志來進行輸出。
所以對於在線下DEV和QA環境進行日志診斷、問題排查時，應該更多的是查看DEBUG日志來進行問題的排查，而不應該過多的依賴 INFO 日志。
對於線上環境則應該屏蔽掉DEBUG日志的輸出，僅需要觀察INFO，WARN，ERROR日志，來觀察服務的運行狀態。
在項目中日志優化應該是比代碼、架構優化更為頻繁的操作，我們應該隨着問題的排查來不斷的優化我們的日志輸出。
同時，從日志的功能分類上我們也可以得知，日志的最重要的一個特性是：診斷日志，我們在不斷優化日志的同時，也是對自己項目深入診斷的過程，在優化診斷日志的過程中，如果可以提前預判到某些問題的發生，如：連接池的耗盡，對象等資源的加載統計，而提前增加了診斷日志。這將會對於我們后續故障時的問題定位有着非常好的參考作用。
參考資料
Log4j2 Articles and Tutorials
Logging best practices to get the most out of application level logging
The Art of Test Driven Development: Understanding Logging
中小企業運維需要重視日志分析
王健：最佳日志實踐