日誌規範總結篇

什麼是日誌

日誌用來記錄用戶操做、系統運行狀態等，是一個系統的重要組成部分。然而，因爲日誌一般不屬於系統的核心功能，因此經常不被團隊成員所重視。對於一些簡單的小程序，可能並不須要在如何記錄日誌的問題上花費太多精力。可是對於做爲基礎平臺爲不少產品提供服務的後端程序，就必需要考慮如何依靠良好的日誌來保證系統可靠的運行了。

好的日誌能夠幫助系統的開發和運維人員：
1. 瞭解線上系統的運行狀態
2. 快速準肯定位線上問題
3. 發現系統瓶頸
4. 預警系統潛在風險
5. 挖掘產品最大價值

日誌分類

診斷日誌

• 請求入口和出口
• 外部服務調用和返回
• 資源消耗操做:打開文件,IO等
• 容錯行爲
• 程序異常,Exception
• 後臺操做:多線程等
• 關鍵程序的啓動、關閉、配置加載

統計日誌

• 用戶訪問統計
• 下單、支付日誌

審計日誌

• 管理操做

日誌中記錄什麼？

日誌應該很少很多，可以從日誌中獲得全部須要的信息。在實踐中常常發生日誌不夠的狀況，例如：1）請求出錯時不能經過日誌直接來定位問題，而須要開發人員再臨時增長日誌並要求請求的發送者從新發送一樣的請求才能定位問題；2）沒法肯定服務中的後臺任務是否按照指望執行；3）沒法肯定服務的內存數據結構的狀態；4）沒法肯定服務的異常處理邏輯（如重試）是否正確執行；5）沒法肯定服務啓動時配置是否正確加載；
示例：
[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, ErrorCode:1426, Message: callback request (to http://example.com/callback) failed due to socket timeout


容易遺漏的日誌：

1. 系統的配置參數：系統在啓動過程當中一般會首先讀啓動參數，能夠在系統啓動後將這些參數輸出到日誌中，方便確認系統是按照指望的參數啓動的；
2. 後臺按期執行的任務：如按期更新緩存的任務，能夠記錄任務開始時間，任務結束時間，更新了多少條緩存配置等等，這樣能夠掌握按期執行的任務的狀態；
3. 異常處理邏輯：如對於分佈式存儲系統來講，當系統在一個存儲節點上讀數據失敗時，須要去另外一個數據節點上進行重試，能夠將讀數據失敗這件事情記錄下來，以後能夠經過對日誌的分析確認是否某些節點的磁盤可能存在故障。再好比，若是系統須要請求一個外部資源，能夠將請求這個外部資源偶爾失敗又重試成功這件事情記錄下來，具體來講：

 

 

 

 

 

[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) timeout ... 1 try    

[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) timeout ... 2 try  

[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) success

要好於:[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth request (to http://auth1.example.com/v2) success

 

 

由於前者可讓咱們預判被依賴的服務器服務質量有風險，也許須要進行擴容；日誌中須要記錄關鍵參數，出錯時的關鍵緣由等。

 

 

 

 

[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth failed

[INFO] RequestID:b1946ac92492d2347c6235b4d2611185, content digest does not match

[INFO] RequestID:b1946ac92492d2347c6235b4d2611186, request ip not in whitelist

就不如：

[INFO] RequestID:b1946ac92492d2347c6235b4d2611184, auth failed due to token expiration

[INFO] RequestID:b1946ac92492d2347c6235b4d2611185, content digest does not match, expect 7b3f050bfa060b86ba781151c563c953, actual f60645e7107917250a6408f2f302d048

[INFO] RequestID:b1946ac92492d2347c6235b4d2611186, request ip(=202.17.34.1) 

 

 

日誌級別

• 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）日誌來定位問題；

關於RequestId

一個系統一般經過RequestID來對請求進行惟一的標記，目的是能夠經過RequestID將一個請求在系統中的執行過程串聯起來。該RequestID一般會隨着響應返回給調用者，若是調用出現問題，調用者也能夠經過提供RequestID幫助服務提供者定位問題

RequestId的生成:

• 簡單系統,簡單隨機數便可
  RequestID = md5(time.Now() + random.Int())
• 分佈式環境須要創建全局惟一ID,參照twitter

慢操做日誌

• 服務在接收到一個請求的時候，記錄請求的接收時間（T1），在請求處理完成待發送的時候，會記錄請求發送時間（T2），一般一個請求的日誌都記爲INFO級別，然而當出現請求處理時間（T2-T1）超過必定時間（如10s）時，能夠將該日誌提高爲WARN級別。經過該方法，能夠預先發現系統可能存在的一些問題。
• 一樣的慢操做日誌還能夠用來記錄系統一些外部依賴的處理時間，如一個服務可能依賴外部認證服務器來進行認證受權。經過記錄每次認證請求的時間並將超出預期時間的請求日誌採用WARN級別輸出，能夠儘早發現認證服務器是否是須要擴容等問題。
• 慢日誌的時間閾值應該是能夠動態調整的，這樣在進行系統優化時，能夠將該報警時間閾值逐漸調小，不斷地對系統進行優化