深刻解析 Node.js 的 console.log[每日前端夜話0x73]

深刻解析 Node.js 的 console.log[每日前端夜話0x73]

前端先鋒 前端先鋒

每日前端夜話0x73
每日前端夜話，陪你聊前端。
天天晚上18:00準時推送。
正文共：4477 字
預計閱讀時間： 12 分鐘
翻譯：瘋狂的技術宅
來源：twilio

當你開始用 JavaScript 進行開發時，可能學到的第一件事就是如何用 console.log 將內容記錄到控制檯。若是你去搜索如何調試 JavaScript，會發現數百篇博文和 StackOverflow 文章都會簡單的告訴你用 console.log。由於這是一種很常見的作法，咱們甚至會在代碼中使用像 no-console 這樣的 linter 規則來確保不會留下意外的日誌信息。可是若是咱們真的想要去記錄某些內容呢？

在本文中，咱們將梳理各類狀況下要記錄的日誌信息，Node.js 中 console.log 和console.error之間的區別是什麼，以及如何在不發生混亂的狀況下把你庫中的日誌記錄輸出到用戶控制檯。

1console.log(`Let's go!`);

理論先行：Node.js 的重要細節

雖然你能夠在瀏覽器和 Node.js 中使用 console.log 或 console.error，但在使用 Node.js 時要記住一件重要的事。當你在 Node.js 中將如下代碼寫入名爲 index.js 的文件中時：

1console.log('Hello there');
2console.error('Bye bye');

並用 node index.js 在終端中執行它，你會直接看到二者的輸出：

在終端中執行 node index.js 的結果
雖然它們看起來可能同樣，但實際上系統對它們的處理方式是不一樣的。若是你查閱 Node.js 文檔的 console部分，會看到 console.log 是輸出到 stdout 而 console .error 用的是 stderr。

每一個進程都有三個可用的默認 stream。那些是 stdin，stdout 和 stderr。 stdin 流用來在處理進程的輸入。例如按下按鈕或重定向輸出。 stdout 流用於程序的輸出。最後 stderr 用於錯誤消息。若是你想了解爲何會有 stderr 存在，以及應該在何時使用它，能夠查看這篇文章(https://www.jstorimer.com/blogs/workingwithcode/7766119-when-to-use-stderr-instead-of -stdout)。

簡而言之，這容許咱們在 shell 中使用重定向（>）和管道（|）來處理錯誤和診斷信息，它們是與程序的實際輸出結果是分開的。雖然 > 容許咱們將命令的輸出重定向到文件中，可是 2> 容許咱們將 stderr 的輸出重定向到文件中。例如，下面這個命令會將 「Hello there」 傳給一個名爲 hello.log 的文件並把 「Bye bye」 傳到一個名爲 error.log 的文件中。

1node index.js > hello.log 2> error.log

錯誤輸出被重定向到不一樣的文件

應該在何時記錄日誌？

如今咱們已經瞭解了日誌記錄的底層技術，接下來讓咱們談談應該在什麼狀況下記錄日誌內容。一般應該是如下狀況之一：

• 在開發過程當中快速調試意外行爲
• 基於瀏覽器的分析或診斷日誌記錄
• 記錄你服務器上傳入的請求，以及全部可能發生的故障
• 使用庫的日誌調試選項來幫助用戶解決問題
• 在 CLI 輸出進度、確認消息或錯誤信息
  咱們將跳過前兩種狀況，並重點介紹基於 Node.js 的後三點。

服務器程序日誌

可能你在服務器上記錄日誌的緣由有多種。例如記錄傳入的請求並容許你從中提取諸如統計信息之類的內容，好比有多少用戶在點擊時發生了 404 錯誤，或者用戶瀏覽器的 User-Agent。你也想知道在何時由於什麼出錯了。

若是你想編碼嘗試下面的內容，請先建立一個新的項目目錄。在目錄中建立一個 index.js 並運行如下命令來初始化項目並安裝 express：

1npm init -y
2npm install express

讓咱們設置一個帶有中間件的服務器，每一個請求只需用 console.log進行輸出。將如下內容複製到 index.js 文件中：

1const express = require('express');
 2
 3const PORT = process.env.PORT || 3000;
 4const app = express();
 5
 6app.use((req, res, next) => {
 7 console.log('%O', req);
 8 next();
 9});
10
11app.get('/', (req, res) => {
12 res.send('Hello World');
13});
14
15app.listen(PORT, () => {
16 console.log('Server running on port %d', PORT);
17});

在這裏用 console.log('%O', req) 來記錄整個對象的信息。 console.log 在底層使用了 util.format 來支持 ％O 佔位符。你能夠在 Node.js 文檔中查閱它們的細節。

當你運行 node index.js 來啓動你的服務器並導航到 http://localhost:3000 時，會發現它會打印出不少咱們確實須要但不知道的信息。

在終端中輸出的 request 對象信息
若是將其更改成 console.log('%s', req) 不打印整個對象，咱們就不會得到更多信息。

在終端中輸出的 request 對象信息
能夠經過編寫本身的日誌函數只輸出咱們關心的東西，可是先等等，談談咱們一般關心的東西。雖然這些信息常常成爲咱們關注的焦點，但實際上可能還須要其餘信息：

• 時間戳 - 知道事情什麼時候發生
• 計算機/服務器名稱 - 若是你運行的是分佈式系統
• 進程ID - 若是你用了 pm2 來運行多個Node進程
• 消息 - 包含某些內容的實際消息
• 可能會須要的其它變量或信息
  既然一切都會被轉到 stdout 和 stderr，那麼咱們可能會想要不一樣的日誌級別，還有配置和過濾日誌的能力。

咱們能夠經過依賴 process 的各個部分並編寫一堆 JavaScript 來得到全部這些，但關於 Node.js 的好消息是有 npm 這個生態系統，裏面已經有了各類各樣的庫供咱們使用。其中一些是：

• pino
• winston
• roarr
• bunyan（請注意，這個已經 2 年沒有更新了）
  我更喜歡pino，由於它速度很快。接下來看看怎樣使用 pino 來幫助咱們記錄日誌。同時咱們能夠用 express-pino-logger 包來記錄請求。

安裝 pino 和 express-pino-logger：

1npm install pino express-pino-logger

用下面的代碼更新你的 index.js文件以使用 logger 和中間件：

1const express = require('express');
 2const pino = require('pino');
 3const expressPino = require('express-pino-logger');
 4
 5const logger = pino({ level: process.env.LOG_LEVEL || 'info' });
 6const expressLogger = expressPino({ logger });
 7
 8const PORT = process.env.PORT || 3000;
 9const app = express();
10
11app.use(expressLogger);
12
13app.get('/', (req, res) => {
14 logger.debug('Calling res.send');
15 res.send('Hello World');
16});
17
18app.listen(PORT, () => {
19 logger.info('Server running on port %d', PORT);
20});

在這段代碼中，咱們建立了一個 pino 的實例 logger，並將其傳給 express-pino-logger 建立一個新的 logger中間件來調用 app.use。另外，咱們用 logger.info 替換了服務器啓動時的 console.log，並在路由中添加了一個額外的 logger.debug 來顯示不一樣的日誌級別。

再次運行 node index.js 從新啓動服務器，你會看到一個徹底不一樣的輸出，它每一行打印一個 JSON。再次導航到 http://localhost:3000 ，你會看到添加了另外一行JSON。

若是你檢查這些 JSON，將看到它包含全部前面所提到的信息，例如時間戳等。你可能還會注意到 logger.debug 語句沒有打印出來。那是由於咱們必須修改默認日誌級別才能看到。當咱們建立 logger 實例時，將值設置爲 process.env.LOG_LEVEL，這意味着咱們能夠經過它修改值，或接受默認的 info。經過執行 LOG_LEVEL = debug node index.js，就能夠調整日誌級別。

在這以前要先解決一個問題，即如今的輸出不適合人類閱讀。pino 遵循一種理念，爲了提升性能，你應該經過管道（使用 |）將輸出的任何處理移動到一個單獨的進程中。這包括使其可讀或將其上傳到雲主機。這些被稱爲 transports。能夠經過查看 transports 文檔瞭解爲何 pino 中的錯誤不會寫入 stderr。

讓咱們用工具 pino-pretty 來查看更易閱讀的日誌版本。在你的終端中運行：

1npm install --save-dev pino-pretty
2LOG_LEVEL=debug node index.js | ./node_modules/.bin/pino-pretty

如今全部的日誌都被用 | 運算符輸入給 pino-pretty 命令，你的輸出應該會通過美化，而且還會包含一些關鍵信息，並且應該是彩色的。若是再次請求 http://localhost:3000 ，你還應該看到debug消息。

被美化過的pino日誌輸出
有各類各樣的 transports 來美化或轉換你的日誌。你甚至能夠用 pino-colada 顯示 emoji。這些對你的本地開發頗有用。在生產中運行服務器以後，你可能但願將日誌傳輸到另外一個 transports，再用 > 或者用像 tee 這樣的命令將它們寫入磁盤以便稍後處理。

這個文檔 中還將包含有關輪換日誌文件、過濾和把日誌寫入不一樣文件等內容的信息。

庫的日誌

如今討論一下怎樣有效地爲咱們的服務器程序編寫日誌，爲何不對咱們的庫使用相同的技術呢？

問題是你的庫可能但願經過記錄日誌來進行調試，可是不該該與使用者的程序相混淆。若是須要調試某些內容，使用者應該可以啓用日誌。默認狀況下，你的庫應該是靜默的，並將是否輸出日誌的決策權留給用戶。

一個很好的例子是 express。 express 的底層有不少東西，你可能想在調試本身的程序時偷看它。若是咱們查閱 express 文檔，就會注意到你能夠在本身的命令以前添加 DEBUG=express:*，以下所示：

1DEBUG=express:* node index.js

若是你運行這個命令，將看到許多其餘的輸出，這些可幫助你調試程序中的問題。

express debug logs
若是你沒有啓用調試日誌記錄，則不會看到任何此類日誌。這是經過一個稱爲 debug 的包來完成的。它容許咱們在「命名空間」下編寫日誌消息，若是庫的用戶包含該命名空間或在 DEBUG 環境變量 中匹配了它的通配符，就會輸出這些。要使用 debug 庫，首先要安裝它：

1npm install debug

讓咱們經過建立一個名爲 random-id.js 的新文件來模擬咱們的庫，並將如下代碼複製到其中：

1const debug = require('debug');
 2
 3const log = debug('mylib:randomid');
 4
 5log('Library loaded');
 6
 7function getRandomId() {
 8 log('Computing random ID');
 9 const outcome = Math.random()
10   .toString(36)
11   .substr(2);
12 log('Random ID is "%s"', outcome);
13 return outcome;
14}
15
16module.exports = { getRandomId };

這將建立一個帶有命名空間 mylib:randomid 的新 debug 記錄器，而後將兩條消息輸出到日誌。讓咱們在前面的 index.js 中使用它：

1const express = require('express');
 2const pino = require('pino');
 3const expressPino = require('express-pino-logger');
 4
 5const randomId = require('./random-id');
 6
 7const logger = pino({ level: process.env.LOG_LEVEL || 'info' });
 8const expressLogger = expressPino({ logger });
 9
10const PORT = process.env.PORT || 3000;
11const app = express();
12
13app.use(expressLogger);
14
15app.get('/', (req, res) => {
16 logger.debug('Calling res.send');
17 const id = randomId.getRandomId();
18 res.send(`Hello World [${id}]`);
19});
20
21app.listen(PORT, () => {
22 logger.info('Server running on port %d', PORT);
23});

若是用 DEBUG=mylib:randomid node index.js 從新運行咱們的服務器，它會打印前面「庫」的調試日誌。

自定義調試日誌
若是你的庫的用戶想要將這個調試信息放到他們的 pino 日誌中，他們能夠用 pino 團隊開發的名爲 pino-debug 的庫來正確的格式化這些日誌。

用如下命令安裝庫：

1npm install pino-debug

在咱們第一次使用debug以前，須要初始化pino-debug。最簡單的方法是在啓動 javascript 腳本的命令以前使用 Node.js 的 -r 或 --require 標誌來 require 模塊。使用以下命令從新運行你的服務器（假設你安裝了pino-colada）：

1DEBUG=mylib:randomid node -r pino-debug index.js | ./node_modules/.bin/pino-colada

你如今將用與程序日誌相同的格式查看庫的調試日誌。

使用pino和pino-colada的調試日誌

CLI 輸出

本文介紹的最後一個案例是針對 CLI 進行日誌記錄的特殊狀況。個人理念是將「邏輯日誌」與 CLI 的輸出 「日誌」 分離。對於全部的邏輯日誌，你應該用像 debug 這樣的庫。這樣你或其餘人就能夠從新使用該邏輯，而不受 CLI 的特定用例的約束。

當你用 Node.js 構建 CLI 時，可能但願添加一些看上去很漂亮顏色，或者用有視覺吸引力的方式格式化信息。可是，在構建 CLI 時，應該記住如下這幾種狀況。

一種狀況是你的 CLI 可能會在持續集成（CI）系統的上下文中使用，所以你可能但願刪除顏色和花哨的裝飾輸出。一些 CI 系統設置了一個名爲 CI 的環境標誌。若是你想更安全地檢查本身是否在 CI 中，那就是使用像 is-ci 這樣的包去支持一堆 CI 系統。

像 chalk 這樣的庫已經爲你檢測了CI 併爲你刪除了顏色。咱們來看看它的樣子。

使用 npm install chalk 安裝 chalk 並建立一個名爲 cli.js 的文件。將如下內容複製到其中：

1const chalk = require('chalk');
2
3console.log('%s Hi there', chalk.cyan('INFO'));
Now if you would run this script using node cli.js you'll see colored output.

如今若是你用 node cli.js 運行這個腳本，將會看到彩色輸出。

顯示彩色CLI輸出
可是若是你用 CI=true node cli.js 運行它，你會看到顏色被消除了：

啓用CI模式顯示沒有顏色的CLI輸出
你要記住的另外一個場景是 stdout 是否以終端模式運行，也就是將內容寫入終端。若是是這種狀況，咱們可使用 boxen 之類的東西顯示全部漂亮的輸出。若是不是，則可能會將輸出重定向到文件或用管道傳輸到某處。

你能夠經過檢查相應流上的 isTTY 屬性來檢查 stdin、stdout 或 stderr 是否處於終端模式。例如：process.stdout.isTTY。 TTY 的意思是 「電傳打印機（teletypewriter）」，在這種狀況下專門用於終端。

根據 Node.js 進程的啓動方式，這三個流每一個流的值可能不一樣。你能夠在 Node.js 文檔的"process I/O" 這一部分中詳細瞭解它。

讓咱們來看看 process.stdout.isTTY 的值在不一樣狀況下是如何變化的。先更新你的 cli.js ：

1const chalk = require('chalk');
2
3console.log(process.stdout.isTTY);
4console.log('%s Hi there', chalk.cyan('INFO'));

在終端中運行 node cli.js，你會看到輸出的 true 被着色了。

在控制檯輸出被上色的 "true"
以後運行相同的內容，可是將輸出重定向到一個文件，而後檢查內容：

1node cli.js > output.log
2cat output.log

你會看到此次它打印了 undefined 後面跟着一個簡單的無色消息，由於 stdout 的重定向關閉了它的終端模式。由於 chalk 用了 supports-color，它們會在相應的流上檢查 isTTY。

單色CLI輸出
像 chalk這樣的工具已經爲你處理了這種行爲，可是在開發 CLI 時，你應該始終了解 CLI 可能在 CI 模式下運行或重定向輸出的狀況。它還能夠幫助你進一步得到 CLI 的體驗。例如你能夠在終端中以漂亮的方式排列數據，若是isTTY 是 undefined ，你能夠切換到更容易解析的方式。

總結

剛開始用 JavaScript 開發時用 console.log 記錄你的第一行日誌確實很快，可是當你將代碼投入生產環境時，應該考慮更多關於日誌記錄的內容。本文純粹是對各類方式和可用的日誌記錄解決方案的介紹。我建議你去看一些本身喜歡的開源項目，看看它們是怎樣解決日誌記錄問題的，還有它們所用到的工具。

若是你知道或找到了我沒有說起的工具，或者有什麼疑問，請留言。

原文：https://www.twilio.com/blog/guide-node-js-logging