Node.js + ELK 日誌規範

人人貸大前端技術中心發表於2019-05-22
原文網址 : https://juejin.im/post/5ce4fb2cf265da1b8a4ef3a9
Node.js

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 中建立索引，方便定位各種問題。

  1. desc型別日誌，擴充套件欄位：TODO
  2. stat型別日誌，擴充套件欄位：{ perf: {rss: xxxx, cpu: xxx} }
  3. visit型別日誌，擴充套件欄位：
  4. 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，不是 ERROR
  • trace: 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'});
複製程式碼

參考資料

相關文章