Node.js在Ubuntu日志中显示慢查询怎么办

当你的Node.js应用在Ubuntu服务器上运行，突然发现日志里频繁出现“慢查询”的警告，这感觉就像汽车的仪表盘亮起了故障灯。别慌，这通常不是系统要崩溃的信号，而是一个明确的性能优化入口。接下来，我们就按部就班地来排查和解决这个问题。

一 快速定位慢请求

第一步，当然是找到“病根”。慢请求可能藏在海量日志里，我们需要一些高效的工具和方法来定位它。

• 确认日志路径与输出方式：首先，得知道日志记在哪里、记了什么。检查应用的配置文件或代码，确认日志文件的路径、记录级别，以及是否包含了响应时间、请求路径、状态码这些关键信息。没有这些，后续分析就无从谈起。
• 实时查看尾部日志：一个快速上手的方法是直接查看最新的日志输出。使用tail -n 200 /var/log/yourapp.log这样的命令，可以迅速看到最近发生的请求，有没有明显的异常或超时记录。
• 关键词检索：如果日志里已经标记了“slow query”或类似字样，那就简单了。直接用grep命令配合时间阈值进行过滤，比如：grep -i "slow query" /var/log/yourapp.log | grep -i "100ms"，就能把耗时超过100毫秒的慢查询都揪出来。
• 结构化日志分析：如果应用输出的是JSON格式的结构化日志，那分析起来就优雅多了。借助jq这样的工具，可以轻松地按字段筛选。例如：jq 'select(.duration > 100)' combined.log，就能直接列出所有耗时大于100毫秒的请求。
• 命令行聚合统计：想了解整体情况？awk命令是命令行下的统计利器。通过它，你可以计算平均响应时间、P95、P99等百分位延迟。一个典型的命令示例如下：awk '{sum+=$2; count++; arr[NR]=$2} END {asort(arr); p95=arr[int(count*0.95)]; print "a vg:", sum/count, "ms; p95:", p95, "ms"}' combined.log。这能让你对接口的性能瓶颈有一个量化的认识。
• 集中化分析：对于长期运行或复杂的系统，建议将日志接入ELK Stack（Elasticsearch, Logstash, Kibana）或Graylog这类集中化日志平台。它们能提供强大的可视化、搜索和告警功能，让你可以按时间、接口、状态码、耗时等多个维度进行钻取分析，效率远高于手动查日志。

二 在 Node.js 中准确记录耗时

如果现有的日志信息不够详细，或者你想更精确地度量性能，就需要在代码层面进行埋点。

• HTTP 中间件埋点：对于Web应用，最通用的方法是在请求处理链的开头记录时间戳，在响应结束时计算耗时。下面是一个使用Express框架的示例：

  const express = require('express');
  const app = express();
  
  app.use((req, res, next) => {
    const start = Date.now();
    res.on('finish', () => {
      const duration = Date.now() - start;
      if (duration > 100) { // 这里可以设置你的慢请求阈值，比如100ms
        console.log(`Slow request: ${req.method} ${req.url} - ${duration}ms`);
      }
    });
    next();
  });
  
  app.listen(3000);

• 使用日志库输出结构化日志：直接使用console.log不利于后续分析。推荐集成像winston或pino这样的专业日志库，它们能输出结构化的JSON日志，方便被日志系统解析。结合morgan这样的HTTP请求日志中间件，可以更优雅地实现：

  const express = require('express');
  const morgan = require('morgan');
  const winston = require('winston');
  
  const logger = winston.createLogger({
    level: 'info',
    format: winston.format.json(),
    transports: [
      new winston.transports.File({ filename: 'error.log', level: 'error' }),
      new winston.transports.File({ filename: 'combined.log' })
    ]
  });
  
  app.use(morgan('combined', { stream: { write: msg => logger.info(msg.trim()) } }));

• 数据库查询耗时埋点：很多时候，慢请求的罪魁祸首是数据库。在每次数据库查询前后记录时间，能帮你精准定位慢SQL：

  const { Pool } = require('pg');
  const pool = new Pool();
  
  const start = Date.now();
  pool.query('SELECT * FROM users WHERE id = $1', [userId], (err, res) => {
    const duration = Date.now() - start;
    if (err) return logger.error(`Query failed: ${err.stack}`);
    logger.info(`Query ${duration}ms: SELECT * FROM users WHERE id = $1`, [userId]);
  });

• 高精度计时：对于需要纳秒级精度的性能分析场景，Node.js提供了process.hrtime()函数，它比Date.now()精度更高：

  const start = process.hrtime();
  // ... 这里是你要测量的代码块
  const [s, ns] = process.hrtime(start);
  const ms = s * 1000 + ns / 1e6;
  console.log(`Execution time: ${ms.toFixed(2)} ms`);

• 性能分析辅助：如果代码逻辑复杂，难以定位热点函数，可以使用Node.js内置的性能分析器。通过node --inspect启动应用，然后用Chrome DevTools进行CPU和内存分析；或者使用node --prof生成性能报告文件，再用工具分析，从而找到最耗时的函数调用。

三 数据库侧慢查询排查与优化

应用层的日志指向了数据库？那我们就得深入数据库内部看看了。

• 开启数据库慢查询日志：这是最直接的方法。以PostgreSQL为例，可以通过设置log_min_duration_statement参数（比如设为1000，单位毫秒），让数据库自动将所有执行时间超过1秒的SQL语句记录到日志中。MySQL也有类似的slow_query_log配置。
• 使用pg_stat_statements识别最耗时的语句：PostgreSQL的pg_stat_statements扩展是一个神器。它记录了所有SQL语句的执行统计信息。启用后，运行类似下面的查询，就能立刻找到总耗时最高的“元凶”：

  CREATE EXTENSION IF NOT EXISTS pg_stat_statements;
  
  SELECT query, calls, total_time, rows, 
         100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
  FROM pg_stat_statements
  ORDER BY total_time DESC
  LIMIT 10;

• 优化手段：找到慢SQL后，常见的优化思路包括：为WHERE条件、JOIN字段、ORDER BY字段添加合适的索引；重写过于复杂的查询，分解成多个简单步骤；对于大数据集查询，使用分页或游标避免一次性拉取过多数据；以及对热点数据（如用户信息、配置项）使用Redis等缓存中间件，直接减轻数据库压力。

四 监控告警与持续优化

解决了一次慢查询问题并非终点，建立持续的监控和优化机制才是关键。

• 建立可视化与告警：将应用的指标（如P50/P95/P99延迟、请求吞吐量、错误率）接入Grafana或Kibana，构建实时监控仪表盘。更重要的是，设置合理的告警规则（例如，P99延迟连续5分钟超过500ms），这样问题一出现你就能第一时间知道，而不是依赖事后查日志。
• 进程与性能监控：对于Node.js进程本身，可以使用PM2这样的进程管理工具。它不仅能让应用常驻后台，其pm2 monit命令还能提供一个简单的终端仪表盘，实时观察CPU、内存使用情况以及事件循环的延迟，非常直观。
• 日志轮转与容量管理：日志文件会不断增长，必须做好管理。使用Linux系统自带的logrotate工具，可以自动对日志进行切割、压缩和清理。一个典型的Node.js应用日志轮转配置可能长这样：

  sudo nano /etc/logrotate.d/nodejs
  
  /path/to/your/nodejs/logs/*.log {
      daily
      rotate 7
      missingok
      notifempty
      compress
      delaycompress
      sharedscripts
  }

• 持续优化闭环：性能优化是一个持续的过程。建议定期（比如每周或每两周）复盘慢请求Top N列表，分析其模式。优化顺序上，通常优先处理数据库查询和外部API调用，然后是应用内部的计算密集型任务。结合缓存策略、异步处理和代码重构，形成一个“发现-分析-优化-验证”的完整闭环，才能让系统性能保持在一个健康的状态。