【譯】A Guide to Node.js Logging

譯文出自：閃電礦工翻譯組

原文地址：A Guide to Node.js Logging

原文做者：DOMINIK KUNDEL

倉庫原文連接：A Guide to Node.js Logging

譯者：icepy

當你開始使用 JavaScript 作開發時，你可能學習到的第一件事情就是如何使用 console.log 將內容打印到控制檯。若是你搜索如何調試 JavaScript，你會發現數百個博客文章和 StackOverflow 的文章都指向簡單的 console.log 。由於這是一種常見的作法，咱們甚至可使用 no-console 這樣的規則來確保生產環境不會留下日誌。可是，若是咱們真的想要記錄這些信息呢？

在這篇博文中，咱們將介紹你想要記錄信息的各類狀況，Node.js 中的 console.log 和 console.error 之間的區別是什麼，以及如何在不使用戶控制檯混亂的狀況下在庫中發送日誌記錄。

console.log(`Let's go!`);
複製代碼

Theory First: Important Details for Node.js

雖然你能夠在瀏覽器和 Node.js 環境中使用 console.log 和 console.error，但在 Node.js 中使用時必定要記住一件重要的事情。

將以下代碼寫入到 index.js 文件中，並在 Node.js 環境裏執行：

console.log('Hello there');
console.error('Bye bye');
複製代碼

如圖：

雖然這兩個輸出看起來可能同樣，但系統實際上對它的處理方式有不一樣。若是你檢查一下 console section of the Node.js documentation 你會發現 console.log 使用 stdout 打印而 console.error 則使用 stderr。

每個進程都有三個可使用的默認 streams，它們是 stdin ，stdout 和 stderr。 stdin 能夠處理進程的輸入，例如按下按鈕或重定向輸出。stdout 能夠用於處理進程的輸出。最後 stderr 則用於錯誤消息。若是你想了解 stderr 爲何存在以及什麼時候使用它，能夠訪問：When to use STDERR instead of STDOUT。

簡而言之，這容許咱們使用重定向 > 和管道 | 運算符來處理與應用程序的實際結果分開的錯誤和診斷信息。而 > 容許咱們將命令的輸出重定向到文件，2> 容許咱們將 stderr 的輸出重定向到文件。咱們來看一個例子，它會將 Hello there 重定向輸出到 hello.log ，Bye bye 重定向輸出到 error.log。：

$ node index.js > hello.log 2> error.log
複製代碼

如圖：

When Do You Want to Log?

如今咱們已經瞭解了日誌記錄的基礎技術，那麼讓咱們來談談你可能想要記錄某些內容的不一樣例子，一般這些例子都屬於如下類別之一：

• 快速調試開發階段的意外行爲
• 基於瀏覽器的分析和診斷日誌記錄
• 記錄服務器應用程序傳入的請求以及可能發生的任何故障
• 某些庫的可選調試日誌
• CLI的進度輸出

咱們將跳過本博文中的前兩篇文章，並將重點介紹基於Node.js的三篇文章。

Your Server Application Logs

你但願在服務器上記錄內容的緣由可能有多種，例如：記錄傳入的請求，統計信息，有多少404用戶正在訪問，另外你也想知道何時出錯以及爲何。

初始化項目：

$ npm init -y
$ npm install express
複製代碼

讓咱們設置一個帶有中間件的服務器，只須要 console.log 爲你的請求提供打印：

const express = require("express");

const PORT = process.env.PORT || 3000;
const app = express();

app.use((req,res,next) => {
  console.log('%o', req);
  next();
});

app.get('/', (req,res) => {
  res.send('hello world');
});

app.listen(PORT, () => {
  console.log('Server running on port %d', PORT);
});
複製代碼

這裏咱們使用 console.log('%o', req); 來記錄整個對象。

當你運行 node index.js 並訪問 http://localhost:3000 你會注意到打印的不少信息並非咱們須要的。

若是將起更改成 console.log（'％s'，req） 咱們也不會獲取太多的信息。

咱們能夠編寫本身的日誌功能，只打印咱們關心的信息。但讓咱們先退一步，談談咱們一般關心的事情。雖然這些信息常常成爲咱們關注的焦點，但實際上咱們可能須要其餘信息，例如：

• 時間戳-知道事情什麼時候發生
• 計算機/服務器名稱-若是你運行的是分佈式系統的話
• 進程ID-若是你使用 pm2 運行着多個 Node.js 進程
• 消息-包含某些內容的實際消息
• 堆棧追蹤
• 也許是一些額外的變量或信息

另外，既然咱們知道打印最後都會落到 stdout 和 stderr 上，那麼咱們可能想要不一樣日誌級別的記錄以及過濾它的能力。

咱們能夠經過訪問流程的各個部分並編寫一堆 JavaScript 代碼來獲取上述的信息，但 npm 生態已經給咱們提供了各類各樣的庫來使用，例如：

• pino
• winston
• roarr
• bunyan

我我的喜歡 pino，由於它速度快，生態全。那麼，讓咱們來看一看 pino 是如何幫助咱們記錄日誌的。

$ npm install pino express-pino-logger
複製代碼

const express = require("express");
const pino = require("pino");
const expressPino = require("express-pino-logger");

const logger = pino({ level: process.env.LOG_LEVEL || 'info'});
const expressLogger = expressPino({ logger });

const PORT = process.env.PORT || 3000;
const app = express();

app.use(expressLogger);

app.get('/', (req,res) => {
  logger.debug('Calling res.send')
  res.send('hello world');
});

app.listen(PORT, () => {
  logger.info('Server running on port %d', PORT);
});
複製代碼

運行 node index.js 並訪問 http://localhost:3000 你能夠看到一行一行的 JSON 輸出：

若是你檢查此 JSON ，你會看到前面提到的時間戳。你可能還注意到了咱們 logger.debug 語句並未打印，那是由於咱們必須更改默認日誌級別才能使其可見，試試 LOG_LEVEL=debug node index.js 來調整日誌級別。

在此以前咱們還須要解決一下日誌信息的可讀性，pino 遵循了一個理念，就是爲了性能，你應該經過管道將輸出的處理移動到單獨的進程中，你能夠去查看一下文檔，瞭解其中 pino 的錯誤爲何不會寫入 stderr。

讓咱們使用 pino-pretty 工具來查看更易讀的日誌：

$ npm install --save-dev pino-pretty
$ LOG_LEVEL=debug node index.js | ./node_modules/.bin/pino-pretty
複製代碼

運行 LOG_LEVEL=debug node index.js | ./node_modules/.bin/pino-pretty 並訪問 http://localhost:3000。

如圖：

另外還有各類各樣的庫能夠來美化你的日誌，甚至你可使用 pino-colada 用 emojis 來顯示它們。這些對於你的本地開發很是有用，在運行到生產服務器以後，你可能但願將日誌的管道轉移到另一個管道，使用 > 將它們寫入硬盤以便稍後處理它們。

好比：

$ LOG_LEVEL=debug node index.js | ./node_modules/.bin/pino-pretty | > success.log 2> s_error.log
複製代碼

Your Library Logs

既然咱們研究瞭如何有效的爲服務器應用程序編寫日誌，那麼爲何不能將它用在咱們的某些庫中呢？問題是，你的庫可能但願記錄用於調試的內容，但實際上不該該讓使用者的應用程序變得混亂。相反，若是須要調試某些東西，使用者應該可以啓動日誌。你的庫默認狀況下不會處理這些，並將輸入輸出的操做留給使用者。

express 就是一個很好的例子。

在 express 框架下有不少事情要作，在調試應用程序時，你可能但願瞭解一下框架的內容。若是咱們查詢文檔，你會注意到你能夠在命令行的前面加上 DEBUG=express:* 來啓動。

$ DEBUG=express:* node index.js
複製代碼

如圖：

若是你沒有啓動調試日誌，則不會看到任何這樣的日誌輸出。這是經過一個叫 debug 的包來完成的。

$ npm install debug
複製代碼

讓咱們建立一個新的文件 random-id.js 來使用它：

const debug = require("debug");
const log = debug("mylib:randomid");

log("Library loaded");

function getRandomId() {
  log('Computing random ID');
  const outcome = Math.random()
    .toString(36)
    .substr(2);
  log('Random ID is "%s"', outcome);
  return outcome;
}
module.exports = { getRandomId };
複製代碼

這裏會建立一個帶有命名空間爲 mylib:randomid 的 debug 記錄器，而後會將這兩種消息記錄上去。

咱們能夠在 index.js 文件中引用它：

const express = require("express");
const pino = require("pino");
const expressPino = require("express-pino-logger");
const randomId = require("./random-id");

const logger = pino({ level: process.env.LOG_LEVEL || 'info'});
const expressLogger = expressPino({ logger });

const PORT = process.env.PORT || 3000;
const app = express();

app.use(expressLogger);

app.get('/', (req,res) => {
  logger.debug('Calling res.send')
  const id = randomId.getRandomId();
  res.send(`hello world [${id}]`);
});

app.listen(PORT, () => {
  logger.info('Server running on port %d', PORT);
});
複製代碼

而後使用 DEBUG=mylib:randomid node index.js 來從新運行你的 index.js 文件，如圖：

有意思的是，若是你的庫使用者想把這些調試信息集成到本身的 pino 日誌中去，那麼他們可使用一個叫 pino-debug 的庫來正確的格式化這些日誌。

$ npm install pino-debug
複製代碼

pino-debug 在咱們第一次使用以前須要初始化一次 debug，最簡單的方法就是在啓動以前使用 Node.js 的 -r 或 --require 命令來初始化。

$ DEBUG=mylib:randomid node -r pino-debug index.js | ./node_modules/.bin/pino-colada
複製代碼

如圖：

Your CLI Output

我將在這篇博文中介紹最後一個案例，針對 CLI 的日誌記錄。個人理念是將邏輯日誌和你的 CLI 輸出分開。對於任何邏輯日誌來講，你應該使用相似 debug 這樣的包。這樣你或其餘人就能夠重寫邏輯，而不受 CLI 的約束。

一種狀況是你的 CLI 在持續集成的系統中被使用，所以你可能但願刪除各類花裏胡哨的輸出。有些 CI 系統設置了一個被稱爲 CI 的環境標誌。若是你想更安全的檢查本身是否在 CI 系統中，你可使用 is-ci 這個庫。

有些庫例如 chalk 已經爲你檢查了 CI 並幫你刪除了顏色。

$ npm install chalk
複製代碼

const chalk = require("chalk");

console.log('%s Hi there', chalk.cyan('INFO'));
複製代碼

運行 node cli.js，如圖：

當你運行 CI=true node cli.js，如圖：

你要記住的是另一個場景 stdout 可否在終端模式中運行。若是是這種狀況，咱們可使用相似 boxen 的東西來顯示全部漂流的輸出。但若是不是，則可能會將輸出重定向到文件或輸出到其餘地方。

你可使用 isTTY 來檢查 stdout，stdin，stderr 是否在終端模式。

如：

process.stdout.isTTY
複製代碼

根據 Node.js 的啓動方式，這個三個的值可能不一樣。你能夠在文檔中找到更多關於它的信息。

讓咱們看看 process.stdout.isTTY 在不一樣狀況下的變化：

const chalk = require("chalk");
console.log(process.stdout.isTTY);
console.log('%s Hi there', chalk.cyan('INFO'));
複製代碼

而後運行 node index.js ，如圖：

以後運行相同的內容，但將其輸出重定向到一個文件中，此次你會看見它會打印一個 undefined 後面跟着一個簡單的無色消息。

這是由於 stdout 關閉了終端模式下 stdout 的重定向。

chalk 使用了 supports-color ，它會在引擎裏檢查各個流的 isTTY。

像 chalk 這樣的庫已經幫你處理了這些行爲，但在開發 CLI 的過程當中仍是要注意，在 CI 模式下運行或輸出被重定向的問題。

例如，你能夠在終端以一種漂亮的方式來排列數據，若是 isTTY 爲 undefined 時，則切換到更容易解析的方式上。

In Summary

在 JavaScript 中使用 console.log 是很是快的，但當你將代碼部署到生產環境時，你應該要考慮更多關於記錄的內容。

本文僅僅是介紹了各類方法和可用的日誌記錄解決方案，它不包含你須要知道的一切。

所以我建議你多看一看你喜歡的開源項目，看看它們是如何解決日誌記錄問題以及它們所使用的工具。