2. Console日志基础：从console.log到堆栈追踪

说起Node.js调试，大家最先接触的肯定是console。我刚开始写Node.js那会儿，console.log就是我的救命稻草。没有它，我可能连第一个接口都调不通。今天咱们就好好聊聊console家族的那些事儿。

2.1 console.log / console.error / console.warn：日志三兄弟

这三个方法，说白了就是往控制台输出信息。但它们的区别，可不仅仅是颜色不同。

核心区别：

  • console.log：标准输出，打印普通信息
  • console.error：错误输出，打印错误信息（stderr）
  • console.warn：警告输出，打印警告信息（stderr）

你可能会问：「不都是打印吗？有啥区别？」嗯，这里有个坑。我在生产环境排查问题时，就吃过这个亏。

// 普通日志
console.log('用户登录成功：', userId);

// 错误日志
console.error('数据库连接失败：', err.message);

// 警告日志
console.warn('接口响应时间超过阈值：', responseTime);

为什么要把error和warn输出到stderr？因为生产环境里，我们通常会把stdout和stderr分开重定向。比如：

node app.js >> app.log 2>> error.log

这样，普通日志和错误日志就分开了。我曾经见过一个团队，所有日志都用console.log，结果排查线上问题的时候，错误信息淹没在茫茫日志海里，找得人想哭。

我的习惯：

  • 业务逻辑用 console.log
  • 异常捕获用 console.error
  • 性能告警用 console.warn

2.2 console.time：性能测量的利器

「这段代码到底跑了多久？」——这是每个开发者都会问的问题。console.time就是专门干这个的。

// 开始计时
console.time('数据库查询');

// 模拟数据库查询
setTimeout(() => {
  // 结束计时
  console.timeEnd('数据库查询');
}, 1500);

// 输出：数据库查询: 1.502s

我个人习惯用console.time来快速验证性能假设。比如，我怀疑某个接口慢是因为数据库查询太慢，就会在查询前后加上time和timeEnd。

这里有个小技巧：你可以同时启动多个计时器，只要标签不同就行。

console.time('总耗时');
console.time('步骤1');

// 步骤1
setTimeout(() => {
  console.timeEnd('步骤1');  // 步骤1: 1.002s
  
  console.time('步骤2');
  // 步骤2
  setTimeout(() => {
    console.timeEnd('步骤2');  // 步骤2: 0.503s
    console.timeEnd('总耗时');  // 总耗时: 1.508s
  }, 500);
}, 1000);

注意：console.time和console.timeEnd的标签必须完全一致，否则会报错。我曾经手滑打错了标签，排查了半天才发现是这个问题。

2.3 console.trace：堆栈追踪的艺术

「这个函数是谁调用的？」——console.trace就是回答这个问题的。

说白了，console.trace会打印当前代码的执行堆栈。这在调试复杂调用链时特别有用。

function getUser(id) {
  console.trace('getUser被调用');
  return { id, name: '张三' };
}

function handleRequest(req) {
  const user = getUser(req.params.id);
  return user;
}

handleRequest({ params: { id: 1 } });

输出结果会显示完整的调用链：

Trace: getUser被调用
    at getUser (app.js:2:11)
    at handleRequest (app.js:7:20)
    at Object.<anonymous> (app.js:11:1)

你看，从getUser一路追溯到入口文件，清清楚楚。我在项目中遇到过一个问题：某个中间件莫名其妙地修改了请求对象。用console.trace一查，立马就找到了罪魁祸首。

什么时候用console.trace？

  • 函数被多次调用，想知道调用来源
  • 事件监听器被触发，想追踪触发链
  • 对象属性被意外修改，想找到修改者

2.4 格式化输出：让日志更清晰

console还支持类似C语言的格式化输出，这个功能很多人不知道。

const name = 'Node.js';
const version = '18.0.0';

// 格式化输出
console.log('当前环境：%s %s', name, version);
// 输出：当前环境：Node.js 18.0.0

// 对象格式化
const user = { id: 1, name: '张三' };
console.log('用户信息：%j', user);
// 输出：用户信息：{"id":1,"name":"张三"}

// 数字格式化
console.log('百分比：%d%%', 85);
// 输出：百分比：85%

格式化占位符一览：

占位符 说明 示例
%s 字符串 console.log('名称：%s', '张三')
%d 数字（整数） console.log('数量：%d', 100)
%i 数字（整数） console.log('ID：%i', 123)
%f 数字（浮点数） console.log('价格：%f', 19.99)
%j JSON对象 console.log('数据：%j', {a:1})
%o 对象（展开） console.log('详情：%o', obj)
%O 对象（完整展开） console.log('完整：%O', obj)

小建议：格式化输出在拼接复杂日志时特别好用。我一般会在记录请求参数时用%j，这样能保证JSON格式完整，不会因为特殊字符导致日志解析出错。

2.5 避坑指南：console的陷阱

用了这么多年console，我总结了几条血泪教训：

我曾经踩过的坑：

  • 不要在生产环境滥用console.log：console.log是同步操作，大量日志会阻塞事件循环。我见过一个项目因为日志太多，QPS直接掉了30%。
  • console.log是异步的？：嗯，这个问题有点复杂。在Node.js中，console.log在终端输出时是同步的，但在管道重定向时可能是异步的。别依赖它的执行顺序。
  • 对象引用问题：console.log打印对象时，显示的是引用。如果你在打印后修改了对象，控制台显示的可能不是打印时的状态。
// 坑：对象引用问题
const obj = { count: 1 };
console.log(obj);  // 显示：{ count: 2 } 而不是 { count: 1 }
obj.count = 2;

// 正确做法：打印快照
console.log(JSON.parse(JSON.stringify(obj)));

说白了，console是开发调试的好帮手，但别把它当成生产日志系统。生产环境还是得用专业的日志框架，比如winston、pino这些。不过那是后面章节的内容了，咱们先打好基础。

记住一句话：console.log是你的朋友，但不是你的全部。用好它，但别依赖它。

← 上一章 📖 返回目录 下一章 →