滬江CCtalk視頻地址：https://www.cctalk.com/v/15114923883523

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

在一個真實的項目中，開發(fā)只是整個投入的一小部分，版本迭代和后期維護占了極其重要的部分。項目上線運轉(zhuǎn)起來之后，我們?nèi)绾沃理椖窟\轉(zhuǎn)的狀態(tài)呢？如何發(fā)現(xiàn)線上存在的問題，如何及時進行補救呢？記錄日志就是解決困擾的關(guān)鍵方案。正如我們每天寫日記一樣，不僅能夠記錄項目每天都做了什么，便于日后回顧，也可以將做錯的事情記錄下來，進行自我反省。完善的日志記錄不僅能夠還原問題場景，還有助于統(tǒng)計訪問數(shù)據(jù)，分析用戶行為。

顯示程序運行狀態(tài)

幫助開發(fā)者排除問題故障

結(jié)合專業(yè)的日志分析工具（如 ELK ）給出預(yù)警

本項目中的 log 中間件是基于 log4js 2.x 的封裝，Log4js 是 Node.js 中一個成熟的記錄日志的第三方模塊，下文也會根據(jù)中間件的使用介紹一些 log4js 的使用方法。

日志可以大體上分為訪問日志和應(yīng)用日志。訪問日志一般記錄客戶端對項目的訪問，主要是 http 請求。這些數(shù)據(jù)屬于運營數(shù)據(jù)，也可以反過來幫助改進和提升網(wǎng)站的性能和用戶體驗；應(yīng)用日志是項目中需要特殊標記和記錄的位置打印的日志，包括出現(xiàn)異常的情況，方便開發(fā)人員查詢項目的運行狀態(tài)和定位 bug 。應(yīng)用日志包含了debug、info、warn 和 error等級別的日志。

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

在應(yīng)用中按照級別記錄了日志之后，可以按照指定級別輸出高于指定級別的日志。

當我們的項目在線上環(huán)境穩(wěn)定運行后，訪問量會越來越大，日志文件也會越來越大。日益增大的文件對查看和跟蹤問題帶來了諸多不便，同時增大了服務(wù)器的壓力。雖然可以按照類型將日志分為兩個文件，但并不會有太大的改善。所以我們按照日期將日志文件進行分割。比如：今天將日志輸出到 task-2017-10-16.log 文件，明天會輸出到 task-2017-10-17.log 文件。減小單個文件的大小不僅方便開發(fā)人員按照日期排查問題，還方便對日志文件進行遷移。

npm i log4js -S

在 middleware/ 目錄下創(chuàng)建 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

一段帶有日期、時間、日志級別和調(diào)用 debug 方法時傳入的字符串的文本日志。實現(xiàn)了簡單的終端日志輸出。

替換 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 及以上級別的信息，也就是如下內(nèi)容：

[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.

注意： 日志文件產(chǎn)生的位置就是當前啟動環(huán)境的位置。

分析以上代碼就會發(fā)現(xiàn)，configure 函數(shù)配置了日志的基本信息

{
  /**
   * 指定要記錄的日志分類 cheese
   * 展示方式為文件類型 file
   * 日志輸出的文件名 cheese.log
   */
  appenders: { cheese: { type: "file", filename: "cheese.log" } },

  /**
   * 指定日志的默認配置項
   * 如果 log4js.getLogger 中沒有指定，默認為 cheese 日志的配置項
   * 指定 cheese 日志的記錄內(nèi)容為 error 及 error 以上級別的信息
   */
  categories: { default: { appenders: ["cheese"], level: "error" } }
}

創(chuàng)建 /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(`響應(yīng)時間為${responseTime/1000}s`);
  }
}

創(chuàng)建 /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， 來發(fā)送一個http 請求。

如上，按照前幾節(jié)課程中講解的中間件的寫法，將以上代碼改寫為中間件。 基于 koa 的洋蔥模型，當 http 請求經(jīng)過此中間件時便會在 cheese.log 文件中打印一條日志級別為 info 的日志并記錄了請求的響應(yīng)時間。如此，便實現(xiàn)了訪問日志的記錄。

若要在其他中間件或代碼中通過 ctx 上的方法打印日志，首先需要在上下文中掛載 log 函數(shù)。打開 /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()
     // 循環(huán)methods將所有方法掛載到ctx 上
    methods.forEach((method, i) => {
       contextLogger[method] = (message) => {
         logger[method](message)
       }
    })
    ctx.log = contextLogger;

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

創(chuàng)建 contextLogger 對象，將所有的日志級別方法賦給對應(yīng)的 contextLogger 對象方法。在將循環(huán)后的包含所有方法的 contextLogger 對象賦給 ctx 上的 log 方法。

打開 /mi-send/index.js 文件， 并調(diào)用 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)
      // 調(diào)用ctx上的log方法下的error方法打印日志
      ctx.log.error("ikcamp");
      await next()
  }
}

在其他中間件中通過調(diào)用 ctx 上的 log 方法，從而實現(xiàn)打印應(yīng)用日志。

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(`響應(yīng)時間為${responseTime/1000}s`);
  }
}

修改日志類型為日期文件，按照日期切割日志輸出，以減小單個日志文件的大小。這時候打開瀏覽器并訪問 http://localhost:3000，這時會自動生成一個 logs 目錄，并生成一個 cheese-2017-10-24.log 文件， 中間件執(zhí)行便會在其中中記錄下訪問日志。

├── node_modules/
├── logs/ 
│     ├── cheese-2017-10-24.log 
├── ……
├── app.js

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

// 提取默認公用參數(shù)對象
const baseInfo = {
  appLogLevel: "debug",  // 指定記錄的日志級別
  dir: "logs",        // 指定日志存放的目錄名
  env: "dev",   // 指定當前環(huán)境，當為開發(fā)環(huán)境時，在控制臺也輸出，方便調(diào)試
  projectName: "koa2-tutorial",  // 項目名，記錄在日志中的項目信息
  serverIp: "0.0.0.0"        // 默認情況下服務(wù)器 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
  }
  // 環(huán)境變量為dev local development 認為是開發(fā)環(huán)境
  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(`響應(yīng)時間為${responseTime/1000}s`);
  }
}

代碼中，我們指定了幾個常量以方便后面提取，比如 appLogLevel、dir、env 等。 。并判斷當前環(huán)境為開發(fā)環(huán)境則將日志同時輸出到終端， 以便開發(fā)人員在開發(fā)是查看運行狀態(tài)和查詢異常。

在 ctx 對象中，有一些客戶端信息是我們數(shù)據(jù)統(tǒng)計及排查問題所需要的，所以完全可以利用這些信息來豐富日志內(nèi)容。在這里，我們只需要修改掛載 ctx 對象的 log 函數(shù)的傳入?yún)?shù)：

logger[method](message)

參數(shù) message 是一個字符串，所以我們封裝一個函數(shù)，用來把信息與上下文 ctx 中的客戶端信息相結(jié)合，并返回字符串。

增加日志信息的封裝文件 mi-log/access.js：

module.exports = (ctx, message, commonInfo) => {
  const {
    method,  // 請求方法 get post或其他
    url,          // 請求鏈接
    host,      // 發(fā)送請求的客戶端的host
    headers      // 請求中的headers
  } = ctx.request;
  const client = {
    method,
    url,
    host,
    message,
    referer: headers["referer"],  // 請求的源地址
    userAgent: headers["user-agent"]  // 客戶端信息 設(shè)備及瀏覽器信息
  }
  return JSON.stringify(Object.assign(commonInfo, client));
}

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

取出 ctx 對象中請求相關(guān)信息及客戶端 userAgent 等信息并轉(zhuǎn)為字符串。

在 mi-log/logger.js 文件中調(diào)用：

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) => {
       // 將入?yún)Q為函數(shù)返回的字符串
        logger[method](access(ctx, message, commonInfo))
      }
    })
    ctx.log = contextLogger;

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

重啟服務(wù)器并訪問 http://localhost:3000 就會發(fā)現(xiàn)，日志文件的記錄內(nèi)容已經(jīng)變化。代碼到這里，已經(jīng)完成了大部分的日志功能。下面我們完善下其他功能：自定義配置參數(shù)和捕捉錯誤。

安裝依賴文件 ip:

npm i ip -S

修改 middleware/index.js 中的調(diào)用方法

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) => {
  // 將配置中間件的參數(shù)在注冊中間件時作為參數(shù)傳入
  app.use(miLog({
    env: app.env,  // koa 提供的環(huán)境變量
    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 默認參數(shù)
  const opts = Object.assign({}, baseInfo, options || {})
  // 需要的變量解構(gòu) 方便使用
  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: `響應(yīng)時間為${responseTime/1000}s`
    }, commonInfo))
  }
}

將項目中自定義的量覆蓋默認值，解構(gòu)使用。以達到項目自定義的目的。

對于日志中間件里面的錯誤，我們也需要捕獲并處理。在這里，我們提取一層進行封裝。

打開 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 函數(shù)捕捉到并處理，將狀態(tài)碼小于 500 的錯誤統(tǒng)一按照 500 錯誤碼處理，以方便后面的 http-error 中間件顯示錯誤頁面。 調(diào)用 log 中間件打印堆棧信息并將錯誤拋出到最外層的全局錯誤監(jiān)聽進行處理。

到這里我們的日志中間件已經(jīng)制作完成。當然，還有很多的情況我們需要根據(jù)項目情況來繼續(xù)擴展，比如結(jié)合『監(jiān)控系統(tǒng)』、『日志分析預(yù)警』和『自動排查跟蹤機制』等。可以參考一下官方文檔。

下一節(jié)中，我們將學(xué)習(xí)下如何處理請求錯誤。

上一篇：iKcamp新課程推出啦～～～～～iKcamp｜基于Koa2搭建Node.js實戰(zhàn)（含視頻）? 處理靜態(tài)資源