Node 框架接入 ELK 實踐總結

咱們都有過上機器查日誌的經歷，當集羣數量增多的時候，這種原始的操做帶來的低效率不只給咱們定位現網問題帶來極大的挑戰，同時，咱們也沒法對咱們服務框架的各項指標進行有效的量化診斷，更無從談有針對性的優化和改進。這個時候，構建具有信息查找，服務診斷，數據分析等功能的實時日誌監控系統尤其重要。

ELK （ELK Stack: ElasticSearch, LogStash, Kibana, Beats） 是一套成熟的日誌解決方案，其開源及高性能在各大公司普遍使用。而咱們業務所使用的服務框架，如何接入 ELK 系統呢？

業務背景
咱們的業務框架背景：

業務框架是基於 NodeJs 的 WebServer
服務使用 winston 日誌模塊將日誌本地化
服務產生的日誌存儲在各自機器的磁盤上
服務部署在不一樣地域多臺機器
接入步驟
咱們將整個框架接入 ELK 簡單概括爲下面幾個步驟：

日誌結構設計：由傳統的純文本日誌改爲結構化對象並輸出爲 JSON.
日誌採集：在框架請求生命週期的一些關鍵節點輸出日誌
ES 索引模版定義：創建 JSON 到 ES 實際存儲的映射
1、日誌結構設計
傳統的，咱們在作日誌輸出的時候，是直接輸出日誌的等級（level）和日誌的內容字符串（message）。然而咱們不只關注什麼時間，發生了什麼，可能還須要關注相似的日誌發生了多少次，日誌的細節與上下文，以及關聯的日誌。 所以咱們不僅是簡單地將咱們的日誌結構化一下爲對象，還要提取出日誌關鍵的字段。

1. 將日誌抽象爲事件

咱們將每一條日誌的發生都抽像爲一個事件。事件包含：

事件元字段
事件發生時間：datetime, timestamp
事件等級：level， 例如: ERROR, INFO, WARNING, DEBUG
事件名稱: event, 例如：client-request
事件發生的相對時間（單位：納秒）：reqLife, 此字段爲事件相對請求開始發生的時間（間隔）
事件發生的位置: line，代碼位置; server, 服務器的位置
請求元字段
請求惟一ID: reqId, 此字段貫穿整個請求鏈路上發生的全部事件
請求用戶ID: reqUid, 此字段爲用戶標識，能夠跟蹤用戶的訪問或請求鏈路
數據字段
不一樣類型的事件，須要輸出的細節不盡相同，咱們將這些細節（非元字段）統一放到d -- data，之中。使咱們的事件結構更加清晰，同時，也能避免數據字段對元字段形成污染。

e.g. 如 client-init事件，該事件會在每次服務器接收到用戶請求時打印，咱們將用戶的 ip, url等事件獨有的統一歸爲數據字段放到 d 對象中

舉個完整的例子

{
    "datetime":"2018-11-07 21:38:09.271",
    "timestamp":1541597889271,
    "level":"INFO",
    "event":"client-init",
    "reqId":"rJtT5we6Q",
    "reqLife":5874,
    "reqUid": "999793fc03eda86",
    "d":{
        "url":"/",
        "ip":"9.9.9.9",
        "httpVersion":"1.1",
        "method":"GET",
        "userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.77 Safari/537.36",
        "headers":"*"
    },
    "browser":"{"name":"Chrome","version":"70.0.3538.77","major":"70"}",
    "engine":"{"version":"537.36","name":"WebKit"}",
    "os":"{"name":"Mac OS","version":"10.14.0"}",
    "content":"(Empty)",
    "line":"middlewares/foo.js:14",
    "server":"127.0.0.1"
}

一些字段，如：browser, os, engine爲何在外層 有時候咱們但願日誌儘可能扁平（最大深度爲2），以免 ES 沒必要要的索引帶來的性能損耗。在實際輸出的時候，咱們會將深度大於1的值輸出爲字符串。而有時候一些對象字段是咱們關注的，因此咱們將這些特殊字段放在外層，以保證輸出深度不大於2的原則。

通常的，咱們在打印輸出日誌的時候，只須關注事件名稱及數據字段便可。其餘，咱們能夠在打印日誌的方法中，經過訪問上下文統一獲取，計算，輸出。

1. 日誌改造輸出

前面咱們提到了如何定義一個日誌事件， 那麼，咱們如何基於已有日誌方案作升級，同時，兼容舊代碼的日誌調用方式。

升級關鍵節點的日誌

// 改造前
logger.info('client-init => ' + JSON.stringfiy({
    url,
    ip,
    browser,
    //...
}));

// 改造後
logger.info({
    event: 'client-init',
    url,
    ip,
    browser,
    //...
});

兼容舊的日誌調用方式
logger.debug('checkLogin');
由於 winston 的 日誌方法自己就支持 string 或者 object 的傳入方式, 因此對於舊的字符串傳入寫法，formatter 接收到的其實是{ level: 'debug', message: 'checkLogin' }。formatter 是 winston 的日誌輸出前調整日誌格式的一道工序， 這一點使咱們在日誌輸出前有機會將這類調用方式輸出的日誌，轉爲一個純輸出事件 -- 咱們稱它們爲raw-log事件，而不須要修改調用方式。

改造日誌輸出格式
前面提到 winston 輸出日誌前，會通過咱們預約義的formatter，所以除了兼容邏輯的處理外，咱們能夠將一些公共邏輯統一放在這裏處理。而調用上，咱們只關注字段自己便可。

元字段提取及處理
字段長度控制
兼容邏輯處理
如何提取元字段，這裏涉及上下文的建立與使用，這裏簡單介紹一下 domain 的建立與使用。

//--- middlewares/http-context.js
const domain = require('domain');
const shortid = require('shortid');

module.exports = (req, res, next) => {
    const d = domain.create();
    d.id =  shortid.generate(); // reqId;
    d.req = req;
    
    //...

    res.on('finish', () => process.nextTick(() => {
        d.id = null;
        d.req = null;
        d.exit();
    });

    d.run(() => next());
}

//--- app.js
app.use(require('./middlewares/http-context.js'));

//--- formatter.js
if (process.domain) {
    reqId = process.domain.id;
}

這樣，咱們就能夠將 reqId 輸出到一次請求中全部的事件, 從而達到關聯事件的目的。

2、日誌採集
如今，咱們知道怎麼輸出一個事件了，那麼下一步，咱們該考慮兩個問題：

咱們要在哪裏輸出事件？
事件要輸出什麼細節？
換句話說，整個請求鏈路中，哪些節點是咱們關注的，出現問題，能夠經過哪一個節點的信息快速定位到問題？除此以外，咱們還能夠經過哪些節點的數據作統計分析？

結合通常常見的請求鏈路（用戶請求，服務側接收請求，服務請求下游服務器/數據庫（*屢次），數據聚合渲染，服務響應），以下方的流程圖

那麼，咱們能夠這樣定義咱們的事件：

用戶請求
client-init: 打印於框架接收到請求（未解析）， 包括：請求地址，請求頭，Http 版本和方法，用戶 IP 和 瀏覽器
client-request: 打印於框架接收到請求（已解析），包括：請求地址，請求頭，Cookie, 請求包體
client-response: 打印於框架返回請求，包括：請求地址，響應碼，響應頭，響應包體
下游依賴
http-start: 打印於請求下游起始：請求地址，請求包體，模塊別名（方便基於名字聚合並且域名）
http-success: 打印於請求返回 200：請求地址，請求包體，響應包體(code & msg & data)，耗時
http-error: 打印於請求返回非 200，亦即鏈接服務器失敗：請求地址，請求包體，響應包體(code & message & stack)，耗時。
http-timeout: 打印於請求鏈接超時：請求地址，請求包體，響應包體(code & msg & stack)，耗時。
字段這麼多，該怎麼選擇？ 一言以蔽之，事件輸出的字段原則就是：輸出你關注的，方便檢索的，方便後期聚合的字段。

一些建議
請求下游的請求體和返回體有固定格式， e.g. 輸入：{ action: 'getUserInfo', payload: {} } 輸出: { code: 0, msg: '', data: {}} 咱們能夠在事件輸出 action，code 等，以便後期經過 action 檢索某模塊具體某個接口的各項指標和聚合。
一些原則
保證輸出字段類型一致 因爲全部事件都存儲在同一個 ES 索引， 所以，相同字段不論是相同事件仍是不一樣事件，都應該保持一致，例如：code不該該既是數字，又是字符串，這樣可能會產生字段衝突，致使某些記錄（document）沒法被衝突字段檢索到。
ES 存儲類型爲 keyword, 不該該超過 ES mapping 設定的 ignore_above 中指定的字節數（默認4096個字節）。不然一樣可能會產生沒法被檢索的狀況
3、ES 索引模版定義
這裏引入 ES 的兩個概念，映射(Mapping)與模版(Template)。

首先，ES 基本的存儲類型大概枚舉下，有如下幾種

String: keyword & text
Numeric: long, integer, double
Date: date
Boolean: boolean

通常的，咱們不須要顯示指定每一個事件字段的在ES對應的存儲類型，ES 會自動根據字段第一次出現的document中的值來決定這個字段在這個索引中的存儲類型。但有時候，咱們須要顯示指定某些字段的存儲類型，這個時候咱們須要定義這個索引的 Mapping, 來告訴 ES 這此字段如何存儲以及如何索引。

e.g.

還記得事件元字段中有一個字段爲 timestamp ？實際上，咱們輸出的時候，timestamp 的值是一個數字，它表示跟距離 1970/01/01 00:00:00 的毫秒數，而咱們指望它在ES的存儲類型爲 date 類型方便後期的檢索和可視化, 那麼咱們建立索引的時候，指定咱們的Mapping。

PUT my_logs
{
  "mappings": {
    "_doc": { 
      "properties": { 
        "title":    {
            "type": "date",
            "format": "epoch_millis"
         }, 
      }
    }
  }
}

但通常的，咱們可能會按日期自動生成咱們的日誌索引，假定咱們的索引名稱格式爲 my_logs_yyyyMMdd （e.g. my_logs_20181030）。那麼咱們須要定義一個模板（Template），這個模板會在（匹配的）索引建立時自動應用預設好的 Mapping。

PUT _template/my_logs_template
{
  "index_patterns": "my_logs*",
  "mappings": {
    "_doc": { 
      "properties": { 
        "title":    {
            "type": "date",
            "format": "epoch_millis"
         }, 
      }
    }
  }
}

提示：將全部日期產生的日誌都存在一張索引中，不只帶來沒必要要的性能開銷，也不利於按期刪除比較久遠的日誌。

小結至此，日誌改造及接入的準備工做都已經完成了，咱們只須在機器上安裝 FileBeat -- 一個輕量級的文件日誌Agent, 它負責將日誌文件中的日誌傳輸到 ELK。接下來，咱們即可使用 Kibana 快速的檢索咱們的日誌。