nodejs 日誌規範
一般前端開發同學，對日誌其實不太敏感，畢竟前端大多數情況下，不太關心日誌。即使有，也可能呼叫一些第三方的統計，比如百度統計或者別的等。在 Node.js(下文中簡稱node) 推進過程中，也發現我們平常打日誌太隨意，該打的日誌沒有打，打的一些關鍵日誌缺少必要上下文資訊，導致線上上定位問題的時候很困難。
本文主要梳理了目前我們團隊在nodejs開發中日誌方面存在的問題，以及通過統一日誌規範，希望達到什麼樣的效果。
問題
- node日誌不規範，打日誌太隨意
- 沒有良好的日誌格式、約定的欄位，在
ELK裡不能很好的解析&檢索 (PS:ELK文章在路上) - 由於node對接的後端服務化，呼叫鏈不清晰，定位問題困難
- 資料部門對node日誌的使用，沒有明確的記錄。node修改了日誌，導致統計資料異常
目標
- 規範日誌列印欄位&格式，便於
ELK檢索 - 增強node上下游(nginx/後端)日誌格式，加入惟一
requestId，方便微服務下定位問題 - 統計應用執行情況，效能資料
- 維護資料部門對node日誌的使用情況
實現方案
日誌型別
參考一些日誌的最佳實踐，目前將node日誌分為如下幾種型別(scope)：
desc: 系統啟動、執行過程中，打的日誌，表明系統的一些啟動日誌、啟動引數等，也包含在 不能 捕獲到http上下文的時候，打的日誌stat: 系統效能統計日誌，應用會定時收集一些效能資訊，便於查詢應用當前狀態visit: 每個http請求相關的日誌，會包含惟一的 requestId，定位該請求相關的所有日誌biz: 業務資料相關日誌，主要提供給資料統計使用
日誌級別
只使用 FATAL、ERROR、WARN、INFO 和 DEBUG 等級。
- FATAL - 導致程式退出的嚴重系統級錯誤，不可恢復，當錯誤發生時，系統管理員需要立即介入，一般應用程式碼 不 使用。
- ERROR - 執行時異常以及預期之外的錯誤，也需要立即處理，但緊急程度低於FATAL,當錯誤發生時，影響了程式的正確執行。需要注意的是這兩種級別屬於服務自己的錯誤，需要管理員介入，使用者輸入出錯不屬於此分類，請求後端、讀檔案、資料庫等超時、返回錯誤結構，屬於ERROR
- WARN - 預期之外的執行時狀況，表示系統可能出現問題。對於那些目前還不是錯誤，然而不及時處理也會變成錯誤的情況，也可以記為WARN，如磁碟過低。
- INFO - 有意義的事件資訊，記錄程式正常的執行狀態，比如收到請求，成功執行。通過檢視INFO,可以快速定位WARN，ERROR, FATAL。INFO不宜過多，通常情況下不超過 DEBUG 的10%。
- DEBUG - 與程式執行時的流程相關的詳細資訊以及當前變數狀態。
日誌格式/欄位
日誌格式統一採用 JSON ，便於 ELK 解析處理。
日誌中的各個欄位的值，都應該儘量使用 英文 ，不使用中文。
日誌具體欄位，分為 基礎資料 + 擴充套件資料。基礎資料，是底層日誌框架自帶的，所有日誌都會包含。擴充套件資料，不同型別的日誌，包含不同的欄位。
日誌基礎資料
目前使用的 node-bunyan 日誌庫，官方文件，基礎欄位包含如下：
- v: integer 。bunyan的日誌版本號
- level: integer。日誌級別對應的數字
- name: string。服務名
- hostname: string。主機名
- pid: integer。程式號
- time: string。UTC 格式的日期
- msg: string。日誌主體資訊
日誌擴充套件資料
下面定義的各個資料型別的擴充套件資料，不是 全部的欄位，僅包含該日誌型別下，必需的欄位。這些必需的擴充套件欄位，需要在 ELK 中建立索引，方便定位各種問題。
desc型別日誌，擴充套件欄位：TODOstat型別日誌，擴充套件欄位：{ perf: {rss: xxxx, cpu: xxx} }visit型別日誌，擴充套件欄位：biz
{
///////////// 基礎資料 ////////
v: 1,
level: 20,
///////////// 擴充套件欄位 ////////
// 標誌日誌型別
scope: "visit",
//事件型別：在 visit 的日誌型別下，還會細分不同的事件，比如 client-req、client-res、 普通trace、請求後端service-start, service-end, service-err等。
event: "trace",
//客戶端ID，追蹤使用者、裝置會話。在web端，可以是長期的cookie；在APP端，可以是device-id等
rrdid: "",
//本次請求的惟一ID，串聯本次請求的所有相關日誌
req_id: "some-uuid-for-request",
//本次請求的使用者ID
uid: "",
//本次請求的客戶端相關資料，通過 ctx.logger 打日誌時，自動加上
d: {
url: "/some/path?include-query",
//客戶端ip
ip: "10.138.10.1",
//客戶端的 userAgent
ua: ""
},
//本次node請求的處理時間，毫秒
tm: 500,
//該日誌相關的上下文資料，儘量拼成一個字串，放在 extra 裡
extra: "",
//ERROR 級別日誌，最好包含error相關資訊，比如請求後端相關引數等
err: {
msg: "",
stack: ""
},
//呼叫後端服務相關引數和響應
service_req: {
host: "",
path: "",
payload: ""
},
service_res: {
//http狀態碼
http_code: 200,
//響應時間
tm: 100,
//響應的body
body: "",
//異常資訊
err: ""
}
}
複製程式碼什麼時候打日誌
開發者目前只關心 visit 型別的日誌，即和某一次http請求相關聯的日誌。desc和stat型別的日誌，統一由開發框架封裝後實現，業務開發 不用 關心。下面講的，都是針對 visit 型別的日誌。
一次http請求，會打出一系列相關聯的日誌。在node層，通常一次請求，會進一步轉發給N個後端服務，然後對後端資料進行一些處理、合併等操作，最後渲染頁面或是輸出JSON。因此，一次請求相關的日誌，大體分為以下幾種 event：
client-req: client請求到達node層，統一由框架打日誌，開發 不 關心service-start: node對某個後端服務發起請求，由通用請求庫負責打日誌，開發 不 關心service-end: node請求某個後端服務結束，由通用請求庫負責打日誌，開發 不 關心service-err: node請求後端服務異常，由通用請求庫負責打日誌，開發 不 關心。呼叫後端服務異常，日誌級別為WARN，不是ERRORtrace: node中業務層打的日誌，如果異常，能幫助定位本次請求相關問題client-res: 結束client的請求，列印本次請求的http code，本次請求處理時間等，由框架統一打，開發 不 關心
開發同學在打日誌時，應該謹慎的選擇級別，INFO(含)級別以上，都應該能對定位問題、具體業務統計需求有要求，才能使用。大部分情況下，可以使用 DEBUG 級別，線上 不會 開啟DEBUG級別。
具體方法呼叫
針對列印 visit型別的日誌，呼叫 ctx.logger(基於Koa的框架) 屬性打日誌，推薦引數都傳遞 JSON，具體方法如下：
ctx.logger.debug({msg: "", "extra": "a=1 b=2 c=value"});
ctx.logger.info({msg: "xxx", "extra": "其他的額外欄位"});
ctx.logger.warn({msg: "xxx", "extra": "額外上下文資料"});
//ERROR級別日誌，應該提供 Error 物件
ctx.logger.error({msg: 'xxx', err: error, extra: ""});
複製程式碼注意1，額外的引數，推薦存放在 extra 欄位中，統一拼成 string；如果確實有必要單獨出每個欄位， 禁止 額外的引數佔用上述通用欄位名！！
注意2，基礎資料中的msg欄位，禁止 包含具體的上下文資料，和該日誌相關的上下文資料，應該拼成字串，放在單獨的 extra 欄位中。比如，某個使用者登入介面，希望統計呼叫次數，可以這樣列印:
ctx.logger.info({msg: "user login", "extra": 'mobile=18712387101 code=xxxx k3=value3'});
複製程式碼