深刻解析 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