NodeJS 日志记录，从初学者到专家。

本文最初发表于此处。

在本教程中，我们将讨论如何在 NodeJS 上正确执行日志记录。我们将从简单的控制台日志开始，逐步过渡到更高级的功能。读完本教程后，您将能够使用 Winston npm 库创建自定义日志记录器，并添加用于传输日志的传输协议。您还将学习如何添加一些高级功能，例如请求跟踪，以及如何实施额外的安全预防措施，让您晚上睡得安稳。

我建议你从我的Github 仓库克隆代码，因为这是一个很长的教程，这样更容易理解步骤。让我们一起实现它吧！

_{^{温馨提示：本教程将指导您从使用 console.log 进行简单的日志记录到高级日志记录功能。您可以跳过任何您认为过于基础、超出您经验的部分。请根据您的应用程序规模、需求等，决定以下哪种日志记录实践最适合您的情况。您可以在任何您认为足以满足自身需求的步骤停止学习。为了简单起见，我在所有示例中都使用了 ExpressJS。大多数 NodeJS 开发者一生中至少使用过一次 ExpressJS，并且有大量的文档可供参考。}}

NodeJS 日志记录的最简单形式，控制台对象

我们已经设置好了 ExpressJS API，并希望开始将日志添加到我们的 Web 应用程序中。假设我们要从数据库中检索一篇文章，然后通过 API 返回其数据。



app.get('/post/:id', function (req, res) {
  // We have created a fake model class with a function that returns a post in case id === 1, or null in all other cases

  // In a real world example we would use async await 
  // or use a promise based structure
  const post = Post.find(req.params.id); 
  return res.json({post});
});

一切准备就绪。让我们在 API 调用中添加一些日志。我们将为未找到帖子的情况添加一条信息日志，并为与数据库的连接引发异常的情况添加一条错误日志。

对于下面的例子，我们必须提到id 2返回null。id 3在伪造的Post模型中抛出了异常。



app.get('/post/:id', function (req, res) {
  try {
    const id = req.params.id;
    const post = Post.find(id); // We assume that we have some kind of ORM in the app.

    if (!post) {
      console.log(`Post with id ${id} was not found`);
      return res.status(404).json({error: 'Post not found'});
    }

    return res.json({post});
  } catch(e) {
    console.log(e);
    return res.status(500).json({error: 'Something went wrong'});
  }
});

我们将代码封装在 try-catch 子句中，并通过记录错误来处理数据库异常。我们还处理了指定 ID 的帖子不存在的情况，并打印了一条信息日志。

这样，我们就有了第一个日志机制。当我们使用 console.log 时，我们会得到一个简单的日志，例如“未找到 id 为 2 的帖子”。当我们尝试检索 id 为 3 的帖子时，我们会收到一个错误及其堆栈跟踪，并以字符串“Error:”为前缀。



Error: Database unreachable
    at .......

现在，让我们将 NodeJS 日志记录提升到一个新的水平。

使用专用的 NodeJS npm 日志库

我们已经取得了一些进展，只需一步就能从无日志记录变为有日志记录。我们还发现了如何使用 JavaScript 控制台函数设置不同的日志级别。但如果我们还想了解更多呢？

我们可以创建一个 NodeJS 模块来暴露 console.log 函数，或许还可以使用类似的模块chalk来为这些日志的输出着色。但是，如果我们需要在生产服务器上仅显示基于级别特定的日志，该怎么办？我们不想在生产系统上显示调试日志。我们可以创建一个函数，根据日志级别进行过滤。那么格式化怎么办？算了，这太麻烦了。我们可以做的，而且在大多数情况下应该做的，是使用专业的库来执行日志记录。在以下示例中，我将使用 Winston npm 日志库。

安装

那么，让我们构建一个 NodeJS 日志模块。首先，我们必须安装 Winston。我们可以在终端中运行以下命令来完成此操作：



npm install --save winston

基本设置

然后，我们必须为记录器创建一个类。我们之所以创建类（或者函数，随便你怎么称呼）而不是直接使用记录器，是因为它赋予了我们扩展和覆盖其功能的能力。



const winston = require('winston');

class Logger {
  constructor(name) {
    this.logger = winston.createLogger({
        level: 'info',
        defaultMeta: { service: name }
    });
  }

  // We expose four levels of logging for this tutorial

  debug(log, metadata) {
    this.logger.debug(log, metadata);
  }

  info(log, metadata) {
    this.logger.info(log, metadata);
  }

  warn(log, metadata) {
    this.logger.warn(log, metadata);
  }

  error(log, metadata) {
    this.logger.error(log, metadata);
  }

  log(level, log, metadata) {
      const metadataObject = {}
      if (metadata) metadataObject.metadata = metadata

      this.logger[level](log, metadataObject)
  }
}

// We want our logger to have a name, like 'logging-tutorial'
module.exports = new Logger(process.env.APP_NAME)

// We will also expose a function if we want
// to use the logger with custom parameters
module.getLogger = (name) => {
  return new Logger(name);
}

我们创建了四个函数，每个严重程度级别对应一个。此外，我们还创建了一个通用日志函数，以便从这些函数中调用。该函数是通用的，它将包含记录器的所有逻辑。文本或对象可以作为第一个参数传递，也可以将包含元数据的对象作为第二个参数传递。

创建控制台传输和格式化日志

我们的记录器已设置完毕，现在让我们尝试一下，看看它会生成什么日志。在本例中，我们将使用以下测试 API：



app.get('/logger', function(req, res) {
  logger.info('I am an info log', {name: 'George', tutorial: 'Logging tutorial'});
  return res.json({logged: true});
});

如果我们尝试调用此 API，我们将得到以下内容：



[winston] Attempt to write logs with no transports {"service":"logging-tutorial","level":"info","message":"I am an info log"}

这是因为我们还没有配置记录器使用任何传输协议。没有传输协议，Winston 就不知道该把日志发送到哪里。所以，让我们添加第一个传输协议。我们需要将构造函数的代码改成这样：



constructor(name) {
    this.logger = winston.createLogger({
        level: 'debug',
        defaultMeta: { service: name },
        transports: [
            new winston.transports.Console({
                format: winston.format.combine(
                    winston.format.timestamp(),
                    winston.format.metadata({fillExcept: ['timestamp', 'service', 'level', 'message']}),
                    winston.format.colorize(),
                    this.winstonConsoleFormat()
               )
           })
    ]
});

我知道，我知道……信息量太大了。所以，我们来分解一下。首先，我们在 Winston 选项对象中添加了一个传输数组，从现在开始，它将包含 Winston 将使用的所有传输。我们在数组中添加了一个控制台传输，以便 Winston 可以登录到终端。我们还设置了以下格式。

Winston 格式说明

公开时间戳字段以供其他格式使用。
metadata()。公开元数据字段以供其他格式使用。我们还设置了选项 fillExcept，因为默认情况下，元数据包含时间戳、消息、服务和级别键。我们将以文本形式记录它们，因此我们不希望它们包含在元数据对象中。
colorize(). 对日志的特定部分进行着色，例如日志级别。
winstonConsoleFormat()。我们的自定义格式化程序，我们现在将解释它的代码。



winstonConsoleFormat() {
    return printf(({ timestamp, level, message, metadata }) => {
        const metadataString = metadata != null ? JSON.stringify(metadata) : '';

        return `[${timestamp}][${level}][${this.name}@${this.hostname}] ${message}. ${'metadata: ' + metadataString}`;
    })
}

我们只需将所有信息串联到一行中，并使用os.getHostname()内置 NodeJSos模块中的命令添加运行应用程序的主机名。我们的函数返回 printf 函数，这正是 Winston 所期望的。

通过测试此 API 调用，我们将在控制台中得到类似以下内容。



[2020-04-16T14:08:47.023Z][info][logging-tutorial@ubuntu] I am a log Metadata: {"author":"George","tutorial":"Logging tutorial"}

是不是很棒？现在，我们的日志包含了大量额外的信息，例如记录时间、主机名、记录器名称以及日志的严重级别。我们的日志也以一种易于阅读的格式呈现。此外，我们还可以传递额外的元数据，帮助我们更轻松地调试每个问题。

仅允许记录特定严重性级别

在前面的示例中，我们去掉了控制台日志，使用了专业的日志库，并解释了它的工作原理，以及如何以有意义的方式格式化日志。在这一步中，我们将展示如何设置日志记录器的最低日志级别，以及它的重要性。

首先，让我们深入研究代码。为了设置记录器的最低日志级别，我们将更改控制台传输，使其从变量中获取日志级别。我们将最低级别设置为“info”，这样就不会在生产服务器中收到烦人的调试消息。为此，我们将更改创建记录器的代码，使其如下所示：



this.logger = winston.createLogger({
        level: options.logLevel,
......

现在我们的记录器会做同样的事情，但我们现在可以通过选项对象传递严重性级别。让我们将“info”字符串移动到一个环境变量中，并在导出时将其传递给记录器。这样我们就可以在 .env 文件中定义它，方便将来更改。



module.exports = new Logger(process.env.APP_NAME, {
    logLevel: process.env.LOG_LEVEL
});

好吧，但为什么要这么做呢？有几个原因应该考虑在生产环境中不允许所有严重级别。

我们不想用烦人的调试或跟踪日志污染我们宝贵的日志流。
如果我们使用某种持久存储（我们将在本教程后面讨论），我们最终可能会导致大量日志占用服务器的太多空间。
尽管流式传输process.stdout是一个异步过程，但如果无限制地使用，则可能成为资源密集型操作。

将日志保存到文件中

在运行应用时，从终端查看日志非常有用。但有时我们可能需要检查旧日志，以调试几天前发生的事情。为此，我们必须将日志持久化到某种存储中。最常见的解决方案是将日志持久化到文件中。

Winston 允许我们定义传输协议，将日志流式传输到文件。通过定义文件传输协议，我们的日志将与终端一起写入该文件。我们不会使用 npm 模块来实现这一点，因为 Winston 自带了内置的文件流传输功能。

和之前一样，我们只需在传输数组中添加一个新条目即可。传输将如下所示。



new winston.transports.File({ 
    filename: './logs/' + name + '.log',
    format: winston.format.combine(
        winston.format.errors({ stack: true }),
        winston.format.metadata(),
        winston.format.json()
    )
})

我们将日志的文件名设置为 [name].log，这样我们就可以为每个运行的应用程序（例如每个微服务）创建单独的日志文件。如果您想在日志文件中添加当前日期作为后缀，请参阅 Winston 文档。

现在，日志也会被流式传输到 ./logs/logging-tutorial.log 文件中。请记住，您可以根据需要为每个流定义不同的日志级别。将日志记录到文件中非常重要，而且它是容错性最高的日志记录方式之一。除非磁盘空间不足或磁盘损坏，否则在流式传输过程中几乎不可能出现日志未写入文件的情况。

使用外部日志提供程序

有时我们希望日志可搜索，以便轻松跟踪错误、将问题分配给开发人员等等。我们可以通过使用外部日志提供程序来实现这一点，或者设置某种允许此类操作的存储，例如 Elasticsearch。在本部分中，我们将展示如何将日志记录器与 Sentry 集成。Sentry 是一款工具，它允许我们汇总所有日志、进行过滤、将日志分配给开发人员、将其标记为已解决并查找回归问题。

设置传输

我们将使用一个 npm 模块来实现 Sentry 传输（我们将在另一个教程中展示如何创建自定义传输）。该模块名为。我已经在Sentrywinston-sentry-log上创建了一个免费帐户，并将我创建的项目的 DSN 添加到我的 .env 文件中。DSN 是用于将日志发布到 Sentry 的 URL，您可以在您创建的项目下的 Sentry 仪表板中找到它。那么，让我们开始传输：



npm install --save winston-sentry-log

安装后winston-sentry-log，我们只需要在记录器中需要该模块，并将 Winston 传输添加到记录器的传输数组中。



// On top of logger file
const Sentry = require('winston-sentry-log');
....
....
// Inside the transports array
new Sentry({
    config: {
        dsn: process.env.SENTRY_DSN
    },
    level: "warn"
})

这听起来很神奇，但我们已经准备好了！你看，向 Winston 添加新的传输协议是多么简单吗？您可以从 npm 安装大量即插即用的传输协议。现在，我们的日志将无需任何额外操作即可发送到 Sentry。我选择只发送警告和错误日志，但您可以从选项对象中设置任何您喜欢的严重级别。

这就是我们在 Sentry UI 中得到的。

Sentry UI 中的信息日志，嗯，但是 author 字段怎么了？Sentry 内置了一些数据清理器，它认为 author 字段可能会泄露重要信息。所以它被过滤掉了。您可以禁用此功能并添加您自己的敏感字段。在本教程的后面，我们将尝试在日志记录器中实现类似的功能。

使用中间件抽象 NodeJS 日志的部分

到目前为止，我们已经取得了很大的进展。但有些地方我不太喜欢。让我们看下面的例子。



app.get('/automated-error-handling', function(req, res) {
    try {
        Post.find(3);
        return res.json({success: true})
    } catch(e) {
        logger.error(e);
        return res.status(500).json({error: 'Something went wrong'});
    }
});

你能看出这个例子中的问题所在吗？或者至少可以改进的地方？我们处理了无法避免的异常，例如数据库无法访问，记录了发生的错误，并始终在 API 中返回相同的 JSON 响应。我们可以在其他地方抽象这个逻辑吗？

当然，依我拙见，这是必须的。让我们把这个逻辑移到一个 Express 后置中间件中。



const logger = require('../libs/Logger')

module.exports = function(err, req, res, next){
    if (err) {
        logger.error(err);
    }

    return res.status(500).json({error: 'Something went wrong'});
}

是的，就这些。所有路由都注册完成后，我们就可以开始使用中间件了，如下所示：



app.use(require('./middlewares/postErrorHandler'))

这样，当路由或控制器内部没有捕获到错误时，错误就会被这个 post 中间件捕获，错误会被记录下来，API 也会返回一条消息，通知用户出现了问题。所以，我们之前的例子会变成这样：



app.get('/logging-tutorial/v2/automated-error-handling', function(req, res) {
    Post.find(3);
    return res.json({success: true})
});

基本上，通过抽象这些日志和 JSON 响应的部分，我们自动摆脱了负责处理我们无法通过编写额外代码来防止的错误（例如数据库连接问题）的每个 try-catch 子句。

跟踪我们的 NodeJS 日志顺序

假设我们在 API 中执行一个复杂的操作，并且包含多个步骤和多个信息日志。如果能够跟踪这些日志的顺序和上下文，岂不是很好？

为此，我们将使用 NodeJS 异步钩子。这是一个实验性的 NodeJS API，因此如果您决定使用它，请在部署前进行全面测试。现在，让我们创建 LocalStorage 库。我们将导出一个新的 NodeJS 本地存储实例。



const { AsyncLocalStorage } = require('async_hooks');
const asyncLocalStorage = new AsyncLocalStorage();

module.exports = asyncLocalStorage;

我们还将改变我们的日志函数以如下方式启动。



const store = LocalStorage.getStore();
const metadataObject = {};

if (store) {
    metadataObject.uniqueId = store.id;
}

现在，我们将检索当前存储，并在 metadataObject 中注入 store.id 字段。我们将在以下示例中展示如何为每个请求启动一个新存储。



app.get('/logging-tutorial/async-hook', function(req, res) {
    // We have installed a uuid module to produce unique ids
    const store = LocalStorage.enterWith({id: uuid()});
    logger.info('I am the first log');
    logger.info('I am the second log');
    logger.info('I am the third log');
    return res.json({});
})

通过使用 enterWith 函数并将 UUID 注入到存储区，该 UUID 将跟随请求直至结束。因此，即使我们通过调用其他文件中存在的服务来记录日志，metadataObject 中记录的 UUID 对于特定请求也始终相同。然后，我们可以根据 UUID 过滤日志，并按时间戳排序。

因此，通过运行这些日志我们将得到：



[2020-04-16T15:49:53.354Z][info][logging-tutorial@ubuntu] I am the first log. Metadata: {"uniqueId":"e8be59d6-2d44-46e5-8665-82759beadfee"}
[2020-04-16T15:49:53.357Z][info][logging-tutorial@ubuntu] I am the second log. Metadata: {"uniqueId":"e8be59d6-2d44-46e5-8665-82759beadfee"}
[2020-04-16T15:49:53.358Z][info][logging-tutorial@ubuntu] I am the third log. Metadata: {"uniqueId":"e8be59d6-2d44-46e5-8665-82759beadfee"}

如果我们重新运行该请求，我们将得到：



[2020-04-16T15:49:57.432Z][info][logging-tutorial@ubuntu] I am the first log. Metadata: {"uniqueId":"227899b6-efd5-4b52-92fb-a316d72c81ab"}
[2020-04-16T15:49:57.435Z][info][logging-tutorial@ubuntu] I am the second log. Metadata: {"uniqueId":"227899b6-efd5-4b52-92fb-a316d72c81ab"}
[2020-04-16T15:49:57.437Z][info][logging-tutorial@ubuntu] I am the third log. Metadata: {"uniqueId":"227899b6-efd5-4b52-92fb-a316d72c81ab"}

您还可以为 ExpressJS 创建一个预处理中间件，以便在每次请求中自动注入 uniqueId。通过将上下文绑定到日志，您可以通过 UUID 跟踪日志，检查最终错误发生之前打印的所有信息或警告日志，从而更轻松地调试错误。

允许手动记录堆栈跟踪

我们知道，当我们记录错误时，堆栈跟踪会自动记录下来。但有时，我们只想将当前的堆栈跟踪记录到信息日志中，仅用于调试目的。我们可能需要打印日志的文件名和行号，或者跟踪记录器是从哪个文件调用的。为此，我们可以在记录器中手动创建一个空的错误，并仅获取其堆栈跟踪。

为了实现这一点，我们将创建一个名为 logTrace 的自定义函数。



logTrace(level, log, metadata) {
    const stackTrace = new Error().stack;
    this.log(level, log, metadata, stackTrace);
}

因此，通过调用 logTrace，将创建一个错误，并且它将与传递给 logTrace 函数的所有数据（如级别、日志、元数据和堆栈跟踪）一起转发到日志函数。

然后，在日志函数中，我们将在元数据对象中注入堆栈跟踪，因此它将与日志一起打印。



if (stackTrace) metadataObject.stackTrace = stackTrace;

让我们的 NodeJS 记录器更安全一些

在之前的步骤中，我们看到 Sentry 过滤掉了元数据中的 author 字段。如果能够在控制台和文件传输中过滤我们的 metadataObject ，岂不是很酷？让我们进一步完善 NodeJS 日志模块。

我们要做的是在构造函数中注入我们认为敏感的顶级键列表。



if (options.sensitiveFields) {
    //eg ['password', 'creditCard']
    this.sensitiveFields= options.sensitiveFields;
    this.checkSensitiveFields = true;
}

现在在我们的日志功能中，我们可以在元数据对象内部执行检查，如果发现任何敏感字段，我们将记录警告而不是原始日志。



if (this.checkSensitiveFields) {
    const sensitiveFieldFound = Object.keys(metadataObject.metadata || {}).find(key => this.sensitiveFields.includes(key));
    if (sensitiveFieldFound) return this.logTrace('warn', `You tried to log the following sensitive key: "${sensitiveFieldFound}". Please check attached stack trace.`);
}

轰！！！我们成功了。现在，如果我们尝试在元数据中记录密码，就会收到以下警告日志。



// Removed stack trace to save space

You tried to log the following sensitive key: "password". Please check attached stack trace.. METADATA: {"stackTrace":"...."}

决定我们要使用的日志轮换策略

虽然 Winston 提供了用于日志轮转的传输方式，但我个人认为这并非日志记录器的责任。我更喜欢使用像 pm2 这样带有日志轮转扩展的工具，或者更好的是使用许多 UNIX 发行版提供的 log-rotate 工具。本节的技术部分就到这里，我不会详细介绍如何使用 pm2 或 Linux 进行日志轮转。

现在，您应该执行日志轮换有两个主要原因。

日志大小

如果您不执行系统性的日志轮换，迟早会遇到服务器中保存的日志占用大量空间的情况。确保将日志轮换作为 NodeJS 日志策略的第一步。

法律原因

在某些情况下，由于旧日志被视为可识别个人用户身份的数据，您必须删除它们。如果您所在国家/地区的法律允许，您可能需要将这些日志保存在其他类型的存储中。有关此类事宜，请咨询专业律师。

如何执行 NodeJS 日志记录？

在本文中，我尝试创建一个完整的 NodeJS 日志记录教程。上面提到的某些功能对于小型项目来说可能有些过度。另一方面，其他一些功能可能会降低 API 的性能。例如，每天处理数百万个请求并检查每个日志中的敏感字段。如果您认为这些功能中的任何一个会造成应用程序的瓶颈，可以将其移至其他层。一个很好的例子是请求日志记录，它可以在代理服务器中运行。

如果您喜欢我的 NodeJS 日志记录教程，欢迎分享到您喜欢的社交网络。我也很想了解您在个人或工作环境中执行 NodeJS 日志记录的方法。

下面您将找到一些与日志记录和 ExpressJS 相关的文章。我希望它们能帮助您将 NodeJS 日志记录提升到一个新的水平。

ExpressJS 中的中间件之前和之后

关于延续本地存储的精彩教程

ExpressJS 中的异步等待使用和全局错误处理

最后……

winston 官方文档

如果您发现这篇博文有用，您可以订阅我的时事通讯并第一时间了解任何新文章。

商业矢量由 fullvector 创建 – www.freepik.com

文章来源：https://dev.to/gkoniaris/nodejs-logging-from-beginner-to-expert-30a6