Node.js 诊断指南 第一弹

290次阅读  |  发布于3年以前

TL;DR

本文介绍的诊断小技巧有:调试环境变量、进程退出码、废弃 API 警告、识别同步 I/O 和处理 Unhandled Promise Rejection。

调试环境变量

以笔者最初使用的 Node.js 版本 v0.10.x 来说,当时内置的 util 还没有提供 util.debuglog 方法,只有一个的 util.debug 效果等同于 console.error,而在当时已经开始要流行的是使用 TJ 的 debug 包,例如:

var debug = require('debug')('http')
  , http = require('http')
  , name = 'My App';

// fake app

debug('booting %o', name);

http.createServer(function(req, res){
  debug(req.method + ' ' + req.url);
  res.end('hello\n');
}).listen(3000, function(){
  debug('listening');
});

通过 DEBUG 环境变量指定了 http 这个 label,就可以把代码中 label 为 http 的调试日志输出:

在 TJ 的设想里,只要开发者所写的所有模块及其依赖的模块都使用这种方式,那么调试的时候大家都可以使用 DEBUG 这个 env 来过滤和开启所有人的 debug 日志。

由于 TJ 的这个模块出来实在是太早了(10年前),所以基本上已经成为了社区的一个默认约定,大部分流行的 npm 包内部都会使用这个模块来输出调试日志(而不是 util.debuglog)。

以国内的 eggjs 框架为例,我们直接启动的日志如下:

通过 DEBUG 环境变量可以开启指定模块的内部调试日志:

PS: 通过 DEBUG=* 就可以开启所有的日志。

实际上 Node.js 也内置了类似的机制,不过目前普遍认为 Node.js 内置的环境变量主要是用来排查 Node.js 内置的代码和模块用的。这里主要有两个环境变量分别对应了 Node.js 内置的 JavaScript 层以及 C++ 层的调试日志,分别是:

常见的 NODE_DEBUG 开关:

以上文中的 http 代码为例,同时开启 DEBUG 和 NODE_DEBUG 效果:

上图中,我们开启了 Node.js 内置的 net 模块的日志初始,之后每次 http 请求进来,net 模块的 debug 日志都会详细输出(由于日志内容比较多所以没有放出来请求的例子图,大家可以自行测试)。

进程退出码

有的时候我们的 Node.js 进程直接退出了,如果没有收集到足够错误日志,可以根据进程的退出码辅助判断错误情况。下面引用 Node.js 文档中的内容:

在没有更多异步操作的时候,Node.js 会直接 0 状态代码退出。在其他情况下使用以下状态代码:

完整参见 https://nodejs.org/api/process.html#process_exit_codes。

我们来举个例子:

// arr-crash.js
process.on('uncaughtException', () => {
  console.error('Ya!');
});

const arr = [];
while(true) arr.push(1);

然后测试:

在 Node.js 进程 crash 之后我们通过 echo $? 可以输出之前进程崩溃之后的退出码,上例中为 134。根据上文中的文档,我们可以知道 134 = 128 + 6 即导致进程退出的异常类型为 6,参考文档:

虽然无法根据错误码知道本例中的进程 crash 的异常是什么,但是可以知道 crash 的时候进程是被强行 SIGKILL 或 SIGHUP 退出的,并且此时 V8 连默认的异常处理器都用不了了(内存爆了啥都做不了了)。

再来一个测试列子:

// uncaught-exception.js
process.on('uncaughtException', () => {
  throw new Error('there..')
});

throw new Error('here..')

测试情况:

根据错误码,我们可以找到文档:

可以发现跟我们测试的情况吻合 —— 在执行致命异常处理器(uncaughtException handler)的时候抛错导致异常无法处理然后进程退出。

废弃 API 警告

Node.js 提供了官方的废弃(deprecate)标记,开发者也可以通过 util.deprecate 方法,将某些接口标记为废弃状态,例如:

const util = require('util');

exports.mergeData = util.deprecate(() => {
  // 之前的代码
}, 'mergeData() 已废弃. 请使用 merge() ');

我们也可以通过 --no-deprecations 来关闭平常使用过程中碰到的 deprecate 警告(不过不是很推荐)。

有时候我们想找到抛这个警告的代码位置在哪,那么可以使用 --trace-deprecation 来开启 trace 错误栈,这样在警告出来的时候就会附上具体的代码 stack。如果更严格一些不希望代码中出现使用废弃版本的情况,那么可以考虑使用 --throw-deprecations 标志,这样使用废弃 API 的地方会直接 throw error,例如:

识别同步 I/O 操作

由于 Node.js 是单线程的,在使用提供服务的时候,如果出现了耗时过长的同步 I/O 操作,那么期间就会 block 住整个线程。为了避免这种情况我们可以使用 --trace-sync-io 标志开启 Node.js 内置的同步 I/O 追踪检测功能。

const { readFileSync } = require('fs');

setImmediate(() => readFileSync(__filename));

测试效果:

Unhandled Promise Rejection

测试代码:

const p = new Promise((resolve, reject) => {
  // throw new Error(111); // 与下一行等效
  reject(new Error(111));
});

测试效果

(node:10142) UnhandledPromiseRejectionWarning: Error: 111
    at /Users/lellansinhuang/workspace/midwayjs-tutorial/tmp/reject.js:4:10
    at new Promise (<anonymous>)
    at Object.<anonymous> (/Users/lellansinhuang/workspace/midwayjs-tutorial/tmp/reject.js:2:11)
    at Module._compile (internal/modules/cjs/loader.js:1147:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1167:10)
    at Module.load (internal/modules/cjs/loader.js:996:32)
    at Function.Module._load (internal/modules/cjs/loader.js:896:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
    at internal/main/run_main_module.js:17:47
(node:10142) UnhandledPromiseRejectionWarning: Unhandled promise rejection. Th

JavaScript 的 Promise 有三种状态,分别是 pending、fulfilled 和 rejected。当一个 promise 的 rejected 状态没有后续处理的时候就会触发上述报错。也就是说如果上面的代码加上,如 p.catch(console.log) 这样的捕获异常逻辑就不会出现 UnhandledPromiseRejectionWarning 警告。

Unhandled Promise Rejection 是在 Node.js v12 时引入的新特性。不处理 Promies 的这种状态在浏览器中一种可以接受的行文,但是在服务端则不然,因为这种报错可能导致内存泄漏。为了避免这种问题,可以了解一下 --unhandled-rejections 的几种设置:

我们将上文中的测试改为使用 strict 模式,则可以得到如下报错:

$ node --unhandled-rejections=strict reject.js
/Users/lellansinhuang/workspace/midwayjs-tutorial/tmp/reject.js:4
  reject(new Error(111));
         ^

Error: 111
    at /Users/lellansinhuang/workspace/midwayjs-tutorial/tmp/reject.js:4:10
    at new Promise (<anonymous>)
    at Object.<anonymous> (/Users/lellansinhuang/workspace/midwayjs-tutorial/tmp/reject.js:2:11)
    at Module._compile (internal/modules/cjs/loader.js:1147:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1167:10)
    at Module.load (internal/modules/cjs/loader.js:996:32)
    at Function.Module._load (internal/modules/cjs/loader.js:896:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
    at internal/main/run_main_module.js:17:47

通过 strict 让进程直接 crash 或者流程报错 block 住,这是一种 let it crash 的思想。

Copyright© 2013-2020

All Rights Reserved 京ICP备2023019179号-8