Node 开发过程中,线上问题的排查往往令人沮丧。如果有堆栈倒还好,能从日志的堆栈中看出一丝端倪,进而在堆栈中跟进排查,还能发现问题。而如果系统没有出现任何错误的输出,但从服务上来看,系统确实出现问题,这种情况,我们需要怎么排查呢?

很可惜,我们没法在线上打断点进行单步调试,只能依靠日志去分析。然而,对于我们来说,其实大部分情况使用 Node 也只是当一个工具,各种 console.log 充当日志的情况可谓是满天飞。然而,要真正地在线上使用 Node 进行服务开发,一个合理的日志记录显然是必要的。

日志的使用

这就引发了我们想探讨的第一个话题,即 Node 开发中,日志记录需要怎么规范化地使用?

对于我来说,模块级别的日志,最常使用的一种是 debug。用法如下:

1
2
3
4
// app.js
const debug = require('debug')('my-namespace')
const name = 'my-app'
debug('booting %s', name)

使用 DEBUG=my-namespace node app.js 运行后即可输出该模块的相关日志。事实上,debug 模块的使用十分广泛,在 express、Koa 等比较知名的 Node 项目中被大量使用。

而对于应用级的 Node 代码,则需要使用专门的日志模块了。

一个合理的日志模块需要满足什么条件呢?首先,日志格式应该是统一的;其次,日志模块应该可以提供日志分级的能力,并可以按文件等方式输出。如 Node 社区里几个比较主流的日志模块主要有:winston、bunyan 和 log4js。关于它们的比较,可以看 strongloop 技术博客上的这篇文章。而对我们来说,按需求选定好其中一个就行了。下面以 log4js 为例,创建一个 logger 对象如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
log4js.configure({
appenders: [{
type: 'dateFile',
filename: path.join(config.logPath, 'app.log'),
pattern: "-yyyy-MM-dd.log",
alwaysIncludePattern: false,
category: 'app'
}]
})
const logger = log4js.getLogger('app')
logger.debug("user id: %s", 'xyz');
logger.info('start server at port', 1001);
logger.error('unable to parse the query string');
logger.fatal('unable to parse the query string');

日志分级机制,这样可以把要输出的内容都输出,但正常情况下只开启一定级别以上的输出。

什么情况下应该记录日志呢?个人的理解是,最底层异常捕获需要加日志记录 logger.error,而对于有必要记录的请求参数,可以使用 logger.info 进行简单的参数记录。最重要的是,代码函数中,可以问问自己,如果这里出问题了,需要记录什么信息可以最快速的定位到问题。

错误处理

下一个问题,我们探讨的是 Node 中错误处理,与其说 Node,倒不如说是 JavaScript 中的错误处理。

一般而言,异常可以粗略地分为两类:

  • 预期的异常:参数不合法、或者断言不满足
  • 非预期的异常:JavaScript 引擎的运行时异常

显然,预期的异常我们是会在代码中处理掉并返回对应状态的,如参数不匹配可能我们就直接返回一个对应的参数不合法状态了。而这里,我们指的也更多是非预期的异常。

对于那些非预期的异常,比如代码中有一段 foo.bar(),如果没有对 foo 进行判断,很可能会出现异常了。如果我们的代码中出现了问题,是立即处理,还是向上抛出?对于同步代码,使用 try-catch 进行异常的处理,而面对异步的代码,JavaScript 可以提供了诸多处理机制,如事件、Node 风格的回调、Promise、generator 函数及 async/await 众多异步机制。

对于事件的错误处理,如 http 中的很多方法,提供了 on('error') 事件的监听,我们可以在这里进行错误的处理及日志的记录。

而对于 Node 风格的回调,第一个参数为 err 对象,我们每次调用都需要进行在回调中先进行 if (err) { ... } 的处理,显然,这是非常麻烦的。

对于 Promise,它提供了 then 方法,其中第二个参数回调当错误发生时会被触发。而且 Promise 可以使用链式调用,对于其中的异常处理,我们只需要在链式的最后使用 catch 进行捕获即可。如下:

1
2
3
4
5
6
7
Promise.resolve()
.then()
.then()
...
.catch(err => {
logger.error(err);
})

值得注意的是,在整个调用链的中间 then 中,如果出现了异常并没有进行处理(即没有通过 reject 传递到下一个 Promise),很有可能会导致整个调用链的中断,这种情况下,catch 是没法捕获异常的。

再看一下 async/await 或 generator 函数的处理,和写平时的同步代码很一致。以 generator 为例:

1
2
3
4
5
6
7
8
9
10
11
function* foo() {
try {
yield bar();
...
// this will trigger undefined is not a function error
haha();
} catch (err) {
//
}
}

不管同步,还是异常里的错误,都能被 catch 住了。前面说的 Promise 调用链中间异常未被处理的情况,对于 generator 函数依然适用。

其它

在周会的最后,大家讨论了一个很有趣的问题,具体的代码已经不记得了,不过可以简单地抽象如下:

1
2
3
4
5
6
7
8
9
10
11
function fn(filename) {
return fs.readFile(filename, 'utf8', (err, content) => {
if (err) return Promise.reject(err);
return Promise.resolve(content);
});
}
Promise.all(['package.json', 'hello.js', 'app.js'].map(fn)).then(function () {
console.log('I am triggerred');
}).catch(() => {
console.log('opps...');
});

上面的代码中,如果 fn 中有一个会出现 err,opps... 是否会被输出呢?这里可以供大家思考一下。关于 Promise,可以参考这篇文章

参考