【譯】Node.js 日誌打印指南

當你開始使用JavaScript開發時，可能要學習的第一個技能就是如何使用 console.log將內容打印到控制檯。若是你搜索如何調試JavaScript，將會發現數百篇博客和StackOverflow文章指向 console.log。由於這是一種很常見的方法，咱們甚至開始使用像 no-console這樣的linter規則來確保咱們不會在生產代碼中留下意外的日誌語句。可是若是咱們真的想經過打印一些東西來提供更多的信息呢?

在這篇文章中，咱們將探討各類須要打印信息的場景；Node.js中console.log和console.error之間有什麼區別；以及如何在不擾亂用戶控制檯的狀況下在庫中記錄日誌。

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

首要理論：Node.js的重要細節

假如咱們能在瀏覽器或者Node.js中使用console.log或console.error，那麼在使用Node.js時，有一件重要的事情是要記住的。在一個名爲index.js的文件中使用Node.js編寫如下代碼時:

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

並在終端使用node index.js執行它，你會看到它們並排輸出了:

然而，儘管這二者看起來相同，但實際上系統對它們的處理是不一樣的。查看Node.js文檔關於console的介紹，咱們能夠看到，console.log輸出到stdout，console.error輸出到stderr。

每一個進程默認有三個可使用的流：stdin, stdout和stderr。stdin流處理進入程序的輸入。例如，按鈕按下或重定向輸出(咱們稍後會講到)。stdout流用於應用程序的輸出。最後，stderr用於錯誤消息。若是你想了解爲何存在stderr以及什麼時候使用它，請參閱這篇文章。

簡而言之，咱們可使用重定向(>)和管道(|)操做符將應用程序的錯誤和診斷信息結果分離顯示。>操做符容許咱們將stdout的輸出重定向到文件中，而2>容許咱們將stderr的輸出重定向到文件中。例如，這個命令將「Hello there」導入一個名爲Hello.log的文件，並將「Bye Bye」導入一個名爲error.log的文件。

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

什麼狀況下咱們須要log?

既然咱們已經瞭解了一些關於日誌的底層技術方面的知識，那麼接下來讓咱們來討論一下可能須要記錄日誌的場景。一般這些場景包含如下類別:

• 開發過程當中快速調試異常
• 基於瀏覽器的日誌記錄，用於分析或診斷
• 記錄服務應用日誌，以記錄傳入的請求以及可能發生的任何故障
• 庫的可選調試日誌，以協助用戶排查問題
• 經過CLI打印進度、確認信息或錯誤

下面的內容咱們將跳過的前兩個場景，重點介紹跟Node.js有關的後面三個場景。

服務應用日誌

在服務器上記錄日誌的緣由可能有不少。例如，經過記錄傳入的請求咱們能夠用來作信息統計，好比用戶遇到有多少404請求，這些請求多是什麼，或者正在使用什麼User-Agent。咱們也想知道何時出了問題，緣由是什麼。

若是你想嘗試本文下面內容，請建立一個新的項目目錄。在項目目錄中建立index.js用於編寫代碼的程序運行入口。運行如下代碼初始化項目並安裝express:

npm init -y
npm install express
複製代碼

讓咱們設置一個帶有console.log的中間件的服務器。將如下內容放入index.js文件中:

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('$0',req)用於記錄整個對象。console.log底層使用util.format方法支持%O佔位符。詳細信息能夠在Node.js官方文檔中瞭解。

當執行node index.js來執行服務器並訪問http://localhost:3000時，你會注意到它將打印出許多咱們並不真正須要的信息。

即便咱們將其更改成console.log('%s', req)不打印整個對象，也不會獲得太多有用的信息。

咱們能夠寫咱們本身的log函數，只輸出咱們關心的東西。可是在此以前，咱們先討論下一般須要關心什麼。雖然太多信息分散咱們注意力的集中，但實際上咱們也須要充分的信息。如:

• 時間戳——知道事情發生的時間
• 計算機/服務器名稱——若是你正在運行一個分佈式系統
• 進程ID——若是你正在使用相似pm2的東西運行多個節點進程
• 消息——包含一些內容的實際消息
• 堆棧跟蹤——用於記錄錯誤的場景
• 其餘一些額外的變量/信息

此外，既然咱們已經知道全部內容都將進入stdout和stderr流，那麼咱們能夠藉助它們實現不一樣級別的日誌，以及根據它們配置和篩選日誌的能力。

咱們能夠經過訪問進程的各個部分並編寫一堆JavaScript來實現全部這些功能，但Node.js最棒的一點是，擁有npm生態系統，並且已經有各類庫可供咱們使用。例如:

• pino
• winston
• roarr
• bunyan (注意：這個已經兩年沒有更新了)

我我的喜歡pino，由於它速度快，生態也很好。讓咱們看看如何使用pino幫助咱們進行日誌記錄。奇妙的是已經有一個express-pino-logger包，咱們可使用它來記錄請求。

安裝pino和express-pino-logger:

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

而後更新index.js文件，使用日誌記錄器和中間件:

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);
});
複製代碼

在這個代碼片斷中，咱們建立了一個pino的日誌程序實例，並將其傳遞到express-pino-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，咱們能夠調整日誌級別顯示debug類型的日誌。

在此以前，讓咱們先討論這樣一個事實:如今的輸出實際上可讀性不好。然而這是故意的。pino遵循一種原則，即更高的性能。咱們也能夠經過管道(使用|)將全部進程的日誌移動到一個單獨的進程中，用於提升其可讀性或將數據上載到雲服務器。這個過程叫作http://www.javashuo.com/tag/transports。查看關於transports的文檔，還能夠了解爲何pino中的錯誤沒有被寫入stderr。

讓咱們使用工具pino-pretty查看更具可讀性的日誌版本。在終端執行一下命令:

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

如今，使用|操做符，全部的日誌將經過管道傳輸到pino-pretty，你的輸出應該變得清晰，包含了關鍵信息而且被着色。再次訪問http://localhost:3000，還應該能看到debug級別的消息。

有許多現成的傳輸工具能夠美化或轉換日誌。你甚至能夠用pino-colada工具使其支持表情符號的顯示。這些將對你本地的開發很是有用。在生產環境中運行服務器以後，你可能但願將日誌導入到另外一個傳輸中，使用>將日誌寫入磁盤，以便稍後處理它們，或者使用tee之類的命令進行處理。

官方文檔還介紹關於日誌文件歸檔、過濾和將日誌寫入不一樣文件等內容。

你的庫日誌

既然咱們已經瞭解瞭如何爲服務器應用程序高效地編寫日誌，爲何不爲咱們編寫的庫使用相同的技術呢?

問題是，咱們但願打印出庫用於調試的內容，但也不能混淆使用者的應用程序。若是須要調試某些東西，使用者應該可以啓用日誌。你的庫在默認狀況下應該是靜默的，並將是否打印日誌留給使用者決定。

express就是一個很好的例子。express的底層作了不少事情，在調試應用程序時，你可能想了解一下底層的狀況。若是咱們查閱express文檔，便會注意到啓動相關日誌只須要在命令前加上DEBUG=express:*:

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

使用現有的應用程序運行該命令，你將看到許多額外的輸出，這些輸出將幫助你調試問題。

若是沒有啓用調試日誌記錄，就不會看到這些。這是是經過一個名爲debug的包來實現的。它容許咱們在指定「名稱空間」下編寫消息，若是庫的使用者在調試環境變量中包含與之匹配的名稱空間或通配符，它將輸出這些消息。

要使用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的新調試日誌實例，其打印了兩條消息。讓咱們在上一章的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，它將打印咱們的「庫」的調試日誌。

有趣的是，若是你的庫使用者但願將此調試信息放入他們的pino日誌中，他們可使用pino團隊提供的pino-debug庫來正確格式化這些日誌。

使用如下方法安裝庫:

npm install pino-debug
複製代碼

在第一次使用debug以前，須要初始化pino-debug。最簡單的方法是在啓動腳本以前使用Node.js的-r或——require標誌來引入模塊。使用以下命令從新運行服務器(假設已經安裝了pino-colada):

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

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

CLI(命令行界面)輸出

在這篇文章中，咱們將討論的最後一種狀況是CLIs而不是庫的特殊日誌記錄狀況。個人原則是將邏輯日誌與CLI輸出的「日誌」分開。對於任何邏輯日誌，都應該使用debug之類的庫。這樣，你或其餘人就能夠重用邏輯，而不受CLI特定用例的限制。

當你的Node.js應用採用CLI構建時，你可能但願經過添加顏色、標記或以一種特定的具備視覺吸引力的方式格式化內容，使其看起來更漂亮。然而，在使用CLI構建時，你應該記住如下幾個場景。

一種場景是，你的CLI可能在持續集成(CI)系統的上下文中使用，所以你可能但願刪除顏色或任何花哨的裝飾輸出。一些CI系統設置了一個稱爲CI的環境標誌。若是你想更安全地檢查你是否在CI中，可使用is-CI這樣的包，它已經支持許多CI系統。

一些庫，如chalk，已經爲你檢測是否CI環境併爲你刪除顏色。接下來讓咱們一塊兒看下使用它以後的樣子。

使用npm安裝chalk並建立一個名爲clip .js的文件。放入如下代碼:

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

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

可是若是你用CI=true node clip .js運行它，你會看到顏色被抑制了:

你要記住的另外一個場景是，若是你的stdout運行在終端模式中，表示內容寫入終端。若是是這種狀況，咱們可使用boxen之類的東西來顯示全部漂亮的輸出。若是不是，極可能輸出被重定向到文件或管道的某個地方。

你能夠經過檢查相應流上的isTTY屬性來檢查stdin、stdout或stderr是否處於終端模式,例如:process.stdout.isTTY。TTY表明「teletypewriter(電傳打字機)」，在本例中特指終端。

根據Node.js進程的啓動方式，這三個流的值可能有所不一樣。你能夠在Node.js文檔的「process I/O」部分了解更多。

讓咱們看看process.stdout的值。isTTY在不一樣的狀況下是不一樣的。更新你的clil.js文件，以檢查它:

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

如今在你的終端中運行node clip.js，你會看到true後面跟着咱們的彩色消息。

以後運行相同的東西，但重定向輸出到一個文件，並檢查內容後運行:

node clip .js > output.log
cat output.log
複製代碼

你將看到，這一次它打印的是undefined，後面跟着一條純色的消息，由於stdout的重定向關閉了stdout的終端模式。chalk使用了support-color檢查相應流上是否支持TTY。

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

總結

開始使用JavaScript並使用console.log記錄第一行代碼很是快，可是當你將代碼投入生產時，你應該考慮更多關於日誌的內容。這篇文章僅僅介紹了各類方法和可用的日誌解決方案。但它不包含你須要知道的一切。我建議你查看一些你最感興趣的開源項目，瞭解它們如何解決日誌記錄問題以及使用哪些工具。如今去記錄全部的信息,而不是僅僅打印日誌吧😉。

原文：A Guide to Node.js Logging