【译】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