滬江CCtalk視訊地址：www.cctalk.com/v/151149238…

log 日誌中介軟體

最困難的事情就是認識自己。

在一個真實的專案中，開發只是整個投入的一小部分，版本迭代和後期維護佔了極其重要的部分。專案上線運轉起來之後，我們如何知道專案運轉的狀態呢？如何發現線上存在的問題，如何及時進行補救呢？記錄日誌就是解決困擾的關鍵方案。正如我們每天寫日記一樣，不僅能夠記錄專案每天都做了什麼，便於日後回顧，也可以將做錯的事情記錄下來，進行自我反省。完善的日誌記錄不僅能夠還原問題場景，還有助於統計訪問資料，分析使用者行為。

日誌的作用

• 顯示程式執行狀態
• 幫助開發者排除問題故障
• 結合專業的日誌分析工具（如 ELK ）給出預警

關於編寫 log 中介軟體的預備知識

log4js

本專案中的 log 中介軟體是基於 log4js 2.x 的封裝，Log4js 是 Node.js 中一個成熟的記錄日誌的第三方模組，下文也會根據中介軟體的使用介紹一些 log4js 的使用方法。

日誌分類

日誌可以大體上分為訪問日誌和應用日誌。訪問日誌一般記錄客戶端對專案的訪問，主要是 http 請求。這些資料屬於運營資料，也可以反過來幫助改進和提升網站的效能和使用者體驗；應用日誌是專案中需要特殊標記和記錄的位置列印的日誌，包括出現異常的情況，方便開發人員查詢專案的執行狀態和定位 bug 。應用日誌包含了debug、info、warn 和 error等級別的日誌。

日誌等級

log4js 中的日誌輸出可分為如下7個等級：

在應用中按照級別記錄了日誌之後，可以按照指定級別輸出高於指定級別的日誌。

日誌切割

當我們的專案線上上環境穩定執行後，訪問量會越來越大，日誌檔案也會越來越大。日益增大的檔案對檢視和跟蹤問題帶來了諸多不便，同時增大了伺服器的壓力。雖然可以按照型別將日誌分為兩個檔案，但並不會有太大的改善。所以我們按照日期將日誌檔案進行分割。比如：今天將日誌輸出到 task-2017-10-16.log 檔案，明天會輸出到 task-2017-10-17.log 檔案。減小單個檔案的大小不僅方便開發人員按照日期排查問題，還方便對日誌檔案進行遷移。

程式碼實現

安裝 log4js 模組

npm i log4js -S
複製程式碼

log4js 官方簡單示例

在 middleware/ 目錄下建立 mi-log/demo.js，並貼入官方示例程式碼：

var log4js = require('log4js');
var logger = log4js.getLogger();
logger.level = 'debug';
logger.debug("Some debug messages");

複製程式碼

然後在 /middleware/mi-log/ 目錄下執行：

cd ./middleware/mi-log/ && node demo.js
複製程式碼

可以在終端看到如下輸出：

[2017-10-24 15:45:30.770] [DEBUG] default - Some debug messages
複製程式碼

一段帶有日期、時間、日誌級別和呼叫 debug 方法時傳入的字串的文字日誌。實現了簡單的終端日誌輸出。

log4js 官方複雜示例

替換 mi-log/demo.js 中的程式碼為如下：

const log4js = require('log4js');
log4js.configure({
  appenders: { cheese: { type: 'file', filename: 'cheese.log' } },
  categories: { default: { appenders: ['cheese'], level: 'error' } }
});

const logger = log4js.getLogger('cheese');
logger.trace('Entering cheese testing');
logger.debug('Got cheese.');
logger.info('Cheese is Gouda.');
logger.warn('Cheese is quite smelly.');
logger.error('Cheese is too ripe!');
logger.fatal('Cheese was breeding ground for listeria.');
複製程式碼

再次在 /middleware/mi-log/ 目錄下執行：

node demo.js
複製程式碼

執行之後，在當前的目錄下會生成一個日誌檔案 cheese.log檔案，檔案中有兩條日誌並記錄了 error 及以上級別的資訊，也就是如下內容：

[2017-10-24 15:51:30.770] [ERROR] cheese - Cheese is too ripe!
[2017-10-24 15:51:30.774] [FATAL] cheese - Cheese was breeding ground for listeria.
複製程式碼

注意： 日誌檔案產生的位置就是當前啟動環境的位置。

分析以上程式碼就會發現，configure 函式配置了日誌的基本資訊

{
  /**
   * 指定要記錄的日誌分類 cheese
   * 展示方式為檔案型別 file
   * 日誌輸出的檔名 cheese.log
   */
  appenders: { cheese: { type: 'file', filename: 'cheese.log' } },

  /**
   * 指定日誌的預設配置項
   * 如果 log4js.getLogger 中沒有指定，預設為 cheese 日誌的配置項
   * 指定 cheese 日誌的記錄內容為 error 及 error 以上級別的資訊
   */
  categories: { default: { appenders: ['cheese'], level: 'error' } }
}
複製程式碼

改寫為log中介軟體

建立 /mi-log/logger.js 檔案，並增加如下程式碼：

const log4js = require('log4js');
module.exports = ( options ) => {
  return async (ctx, next) => {
    const start = Date.now()
    log4js.configure({
      appenders: { cheese: { type: 'file', filename: 'cheese.log' } },
      categories: { default: { appenders: ['cheese'], level: 'info' } }
    }); 
    const logger = log4js.getLogger('cheese');
    await next()
    const end = Date.now()
    const responseTime = end - start;
    logger.info(`響應時間為${responseTime/1000}s`);
  }
}
複製程式碼

建立 /mi-log/index.js 檔案，並增加如下程式碼：

const logger = require("./logger")
module.exports = () => {
   return logger()
}
複製程式碼

修改 middleware/index.js 檔案，並增加對 log 中介軟體的註冊， 如下程式碼：

const path = require('path')
const bodyParser = require('koa-bodyparser')
const nunjucks = require('koa-nunjucks-2')
const staticFiles = require('koa-static')

const miSend = require('./mi-send')
// 引入日誌中介軟體
const miLog = require('./mi-log')
module.exports = (app) => {
  // 註冊中介軟體
  app.use(miLog())

  app.use(staticFiles(path.resolve(__dirname, "../public")))
  app.use(nunjucks({
    ext: 'html',
    path: path.join(__dirname, '../views'),
    nunjucksConfig: {
      trimBlocks: true
    }
  }));
  app.use(bodyParser())
  app.use(miSend())
}
複製程式碼

開啟瀏覽器並訪問 http://localhost:3000， 來傳送一個http 請求。

如上，按照前幾節課程中講解的中介軟體的寫法，將以上程式碼改寫為中介軟體。 基於 koa 的洋蔥模型，當 http 請求經過此中介軟體時便會在 cheese.log 檔案中列印一條日誌級別為 info 的日誌並記錄了請求的響應時間。如此，便實現了訪問日誌的記錄。

實現應用日誌，將其掛載到 ctx 上

若要在其他中介軟體或程式碼中通過 ctx 上的方法列印日誌，首先需要在上下文中掛載 log 函式。開啟 /mi-log/logger.js 檔案：

const log4js = require('log4js');
const methods = ["trace", "debug", "info", "warn", "error", "fatal", "mark"]

module.exports = () => {
  const contextLogger = {}
  log4js.configure({
    appenders: { cheese: { type: 'file', filename: 'cheese.log' } },
    categories: { default: { appenders: ['cheese'], level: 'info' } }
  }); 
 
  const logger = log4js.getLogger('cheese');
  
  return async (ctx, next) => {
  	 // 記錄請求開始的時間
    const start = Date.now()
	 // 迴圈methods將所有方法掛載到ctx 上
    methods.forEach((method, i) => {
	   contextLogger[method] = (message) => {
	     logger[method](message)
	   }
    })
    ctx.log = contextLogger;

    await next()
    // 記錄完成的時間 作差 計算響應時間
    const responseTime = Date.now() - start;
    logger.info(`響應時間為${responseTime/1000}s`);
  }
}

複製程式碼

建立 contextLogger 物件，將所有的日誌級別方法賦給對應的 contextLogger 物件方法。在將迴圈後的包含所有方法的 contextLogger 物件賦給 ctx 上的 log 方法。

開啟 /mi-send/index.js 檔案， 並呼叫 ctx 上的 log 方法：

module.exports = () => {
  function render(json) {
      this.set("Content-Type", "application/json")
      this.body = JSON.stringify(json)
  }
  return async (ctx, next) => {
      ctx.send = render.bind(ctx)
      // 呼叫ctx上的log方法下的error方法列印日誌
      ctx.log.error('ikcamp');
      await next()
  }
}
複製程式碼

在其他中介軟體中通過呼叫 ctx 上的 log 方法，從而實現列印應用日誌。

const log4js = require('log4js');
const methods = ["trace", "debug", "info", "warn", "error", "fatal", "mark"]

module.exports = () => {
  const contextLogger = {}
  const config = {
    appenders: {
    	cheese: {
	     type: 'dateFile', // 日誌型別 
	     filename: `logs/task`,  // 輸出的檔名
	     pattern: '-yyyy-MM-dd.log',  // 檔名增加字尾
	     alwaysIncludePattern: true   // 是否總是有字尾名
	   }
    },
    categories: {
      default: {
        appenders: ['cheese'],
        level:'info'
      }
    }
  }

  const logger = log4js.getLogger('cheese');

  return async (ctx, next) => {
    const start = Date.now()

    log4js.configure(config)
    methods.forEach((method, i) => {
      contextLogger[method] = (message) => {
        logger[method](message)
      }
    })
    ctx.log = contextLogger;

    await next()
    const responseTime = Date.now() - start;
    logger.info(`響應時間為${responseTime/1000}s`);
  }
}

複製程式碼

修改日誌型別為日期檔案，按照日期切割日誌輸出，以減小單個日誌檔案的大小。這時候開啟瀏覽器並訪問 http://localhost:3000，這時會自動生成一個 logs 目錄，並生成一個 cheese-2017-10-24.log 檔案， 中介軟體執行便會在其中中記錄下訪問日誌。

├── node_modules/
├── logs/ 
│     ├── cheese-2017-10-24.log 
├── ……
├── app.js
複製程式碼

抽出可配置量

const log4js = require('log4js');
const methods = ["trace", "debug", "info", "warn", "error", "fatal", "mark"]

// 提取預設公用引數物件
const baseInfo = {
  appLogLevel: 'debug',  // 指定記錄的日誌級別
  dir: 'logs',		// 指定日誌存放的目錄名
  env: 'dev',   // 指定當前環境，當為開發環境時，在控制檯也輸出，方便除錯
  projectName: 'koa2-tutorial',  // 專案名，記錄在日誌中的專案資訊
  serverIp: '0.0.0.0'		// 預設情況下伺服器 ip 地址
}

const { env, appLogLevel, dir } = baseInfo
module.exports = () => {
  const contextLogger = {}
  const appenders = {}
  
  appenders.cheese = {
    type: 'dateFile',
    filename: `${dir}/task`,
    pattern: '-yyyy-MM-dd.log',
    alwaysIncludePattern: true
  }
  // 環境變數為dev local development 認為是開發環境
  if (env === "dev" || env === "local" || env === "development") {
    appenders.out = {
      type: "console"
    }
  }
  let config = {
    appenders,
    categories: {
      default: {
        appenders: Object.keys(appenders),
        level: appLogLevel
      }
    }
  }

  const logger = log4js.getLogger('cheese');

  return async (ctx, next) => {
    const start = Date.now()

    log4js.configure(config)
    methods.forEach((method, i) => {
      contextLogger[method] = (message) => {
        logger[method](message)
      }
    })
    ctx.log = contextLogger;

    await next()
    const responseTime = Date.now() - start;
    logger.info(`響應時間為${responseTime/1000}s`);
  }
}

複製程式碼

程式碼中，我們指定了幾個常量以方便後面提取，比如 appLogLevel、dir、env 等。 。並判斷當前環境為開發環境則將日誌同時輸出到終端， 以便開發人員在開發是檢視執行狀態和查詢異常。

豐富日誌資訊

在 ctx 物件中，有一些客戶端資訊是我們資料統計及排查問題所需要的，所以完全可以利用這些資訊來豐富日誌內容。在這裡，我們只需要修改掛載 ctx 物件的 log 函式的傳入引數：

logger[method](message)
複製程式碼

引數 message 是一個字串，所以我們封裝一個函式，用來把資訊與上下文 ctx 中的客戶端資訊相結合，並返回字串。

增加日誌資訊的封裝檔案 mi-log/access.js：

module.exports = (ctx, message, commonInfo) => {
  const {
    method,  // 請求方法 get post或其他
    url,		  // 請求連結
    host,	  // 傳送請求的客戶端的host
    headers	  // 請求中的headers
  } = ctx.request;
  const client = {
    method,
    url,
    host,
    message,
    referer: headers['referer'],  // 請求的源地址
    userAgent: headers['user-agent']  // 客戶端資訊 裝置及瀏覽器資訊
  }
  return JSON.stringify(Object.assign(commonInfo, client));
}
複製程式碼

注意： 最終返回的是字串。

取出 ctx 物件中請求相關資訊及客戶端 userAgent 等資訊並轉為字串。

在 mi-log/logger.js 檔案中呼叫：

const log4js = require('log4js');
// 引入日誌輸出資訊的封裝檔案
const access = require("./access.js");
const methods = ["trace", "debug", "info", "warn", "error", "fatal", "mark"]

const baseInfo = {
  appLogLevel: 'debug',
  dir: 'logs',
  env: 'dev',
  projectName: 'koa2-tutorial',
  serverIp: '0.0.0.0'
}
const { env, appLogLevel, dir, serverIp, projectName } = baseInfo
// 增加常量，用來儲存公用的日誌資訊
const commonInfo = { projectName, serverIp }
module.exports = () => {
  const contextLogger = {}
  const appenders = {}

  appenders.cheese = {
    type: 'dateFile',
    filename: `${dir}/task`,
    pattern: '-yyyy-MM-dd.log',
    alwaysIncludePattern: true
  }
  
  if (env === "dev" || env === "local" || env === "development") {
    appenders.out = {
      type: "console"
    }
  }
  let config = {
    appenders,
    categories: {
      default: {
        appenders: Object.keys(appenders),
        level: appLogLevel
      }
    }
  }

  const logger = log4js.getLogger('cheese');

  return async (ctx, next) => {
    const start = Date.now()

    log4js.configure(config)
    methods.forEach((method, i) => {
      contextLogger[method] = (message) => {
       // 將入參換為函式返回的字串
        logger[method](access(ctx, message, commonInfo))
      }
    })
    ctx.log = contextLogger;

    await next()
    const responseTime = Date.now() - start;
    logger.info(access(ctx, {
      responseTime: `響應時間為${responseTime/1000}s`
    }, commonInfo))
  }
}
複製程式碼

重啟伺服器並訪問 http://localhost:3000 就會發現，日誌檔案的記錄內容已經變化。程式碼到這裡，已經完成了大部分的日誌功能。下面我們完善下其他功能：自定義配置引數和捕捉錯誤。

專案自定義內容

安裝依賴檔案 ip:

npm i ip -S
複製程式碼

修改 middleware/index.js 中的呼叫方法

const path = require('path')
const ip = require('ip')
const bodyParser = require('koa-bodyparser')
const nunjucks = require('koa-nunjucks-2')
const staticFiles = require('koa-static')

const miSend = require('./mi-send')
const miLog = require('./mi-log/logger')
module.exports = (app) => {
  // 將配置中介軟體的引數在註冊中介軟體時作為引數傳入
  app.use(miLog({
    env: app.env,  // koa 提供的環境變數
    projectName: 'koa2-tutorial',
    appLogLevel: 'debug',
    dir: 'logs',
    serverIp: ip.address()
  }))

  app.use(staticFiles(path.resolve(__dirname, "../public")))

  app.use(nunjucks({
    ext: 'html',
    path: path.join(__dirname, '../views'),
    nunjucksConfig: {
      trimBlocks: true
    }
  }));

  app.use(bodyParser())
  app.use(miSend())
}
複製程式碼

再次修改 mi-log/logger.js 檔案：

const log4js = require('log4js');
const access = require("./access.js");
const methods = ["trace", "debug", "info", "warn", "error", "fatal", "mark"]

const baseInfo = {
  appLogLevel: 'debug',
  dir: 'logs',
  env: 'dev',
  projectName: 'koa2-tutorial',
  serverIp: '0.0.0.0'
}

module.exports = (options) => {
  const contextLogger = {}
  const appenders = {}
  
  // 繼承自 baseInfo 預設引數
  const opts = Object.assign({}, baseInfo, options || {})
  // 需要的變數解構 方便使用
  const { env, appLogLevel, dir, serverIp, projectName } = opts
  const commonInfo = { projectName, serverIp }
	
  appenders.cheese = {
    type: 'dateFile',
    filename: `${dir}/task`,
    pattern: '-yyyy-MM-dd.log',
    alwaysIncludePattern: true
  }
  
  if (env === "dev" || env === "local" || env === "development") {
    appenders.out = {
      type: "console"
    }
  }
  let config = {
    appenders,
    categories: {
      default: {
        appenders: Object.keys(appenders),
        level: appLogLevel
      }
    }
  }

  const logger = log4js.getLogger('cheese');

  return async (ctx, next) => {
    const start = Date.now()

    log4js.configure(config)
    methods.forEach((method, i) => {
      contextLogger[method] = (message) => {
        logger[method](access(ctx, message, commonInfo))
      }
    })
    ctx.log = contextLogger;

    await next()
    const responseTime = Date.now() - start;
    logger.info(access(ctx, {
      responseTime: `響應時間為${responseTime/1000}s`
    }, commonInfo))
  }
}
複製程式碼

將專案中自定義的量覆蓋預設值，解構使用。以達到專案自定義的目的。

對日誌中介軟體進行錯誤處理

對於日誌中介軟體裡面的錯誤，我們也需要捕獲並處理。在這裡，我們提取一層進行封裝。

開啟 mi-log/index.js 檔案，修改程式碼如下：

const logger = require("./logger")
module.exports = (options) => {
  const loggerMiddleware = logger(options)

  return (ctx, next) => {
    return loggerMiddleware(ctx, next)
    .catch((e) => {
        if (ctx.status < 500) {
            ctx.status = 500;
        }
        ctx.log.error(e.stack);
        ctx.state.logged = true;
        ctx.throw(e);
    })
  }
}
複製程式碼

如果中介軟體裡面有丟擲錯誤，這裡將通過 catch 函式捕捉到並處理，將狀態碼小於 500 的錯誤統一按照 500 錯誤碼處理，以方便後面的 http-error 中介軟體顯示錯誤頁面。 呼叫 log 中介軟體列印堆疊資訊並將錯誤丟擲到最外層的全域性錯誤監聽進行處理。

到這裡我們的日誌中介軟體已經制作完成。當然，還有很多的情況我們需要根據專案情況來繼續擴充套件，比如結合『監控系統』、『日誌分析預警』和『自動排查跟蹤機制』等。可以參考一下官方文件。

下一節中，我們將學習下如何處理請求錯誤。

上一篇：iKcamp新課程推出啦～～～～～iKcamp｜基於Koa2搭建Node.js實戰（含視訊）☞ 處理靜態資源

推薦： 翻譯專案Master的自述：

1. 乾貨｜人人都是翻譯專案的Master

2. iKcamp出品微信小程式教學共5章16小節彙總(含視訊)

---

2019年，iKcamp原創新書《Koa與Node.js開發實戰》已在京東、天貓、亞馬遜、噹噹開售啦！