服务端开发博客 | 后端架构 · 高并发 · 性能优化 · 微服务实战
文章 585
评论 5
浏览 226854
© 2026 服务端开发博客 | 后端架构 · 高并发 · 性能优化 · 微服务实战
鄂ICP备2024042559号-1
Powered by Bolo
Theme bolo-nexmoe by InkDP
「踩坑日记」002：凌晨三点 CPU 飙到 100%——一条慢 SQL 引发的连锁血案

「踩坑日记」002：凌晨三点 CPU 飙到 100%——一条慢 SQL 引发的连锁血案

2026-07-12/2026-07-19 7 浏览 踩坑日记 MySQL 慢SQL日志

一、凌晨三点的告警

凌晨 03:15，手机突然震动。

【告警】服务 CPU 使用率达到 99.8%
实例：order-service-01
时间：2026-07-11 03:15:32
持续：已超过 5 分钟

我猛地从床上坐起来，打开笔记本电脑。凌晨三点，应该是定时任务在跑。登录到服务器，看到监控面板上 CPU 红线像心电图一样笔直。

问题已经发生了，现在需要冷静分析。

二、Arthas 排查：定位热线程

登录服务器，启动 Arthas：

$ java -jar arthas-boot.jar
* [1]: 12345 order-service.jar

选择进程 1，进入 Arthas 控制台。

2.1 dashboard：全局视图

$ dashboard
ID   NAME                   STATE      %CPU   TIME   INTERRUPTED DAEMON
1    main                   RUNNABLE   0.0    0:01   false       true
2    GC task thread#0       RUNNABLE   0.0    0:00   false       true
...
25   pool-1-thread-1        BLOCKED    0.0    0:45   false       false
26   pool-1-thread-2        BLOCKED    0.0    0:43   false       false
27   pool-1-thread-3        BLOCKED    0.0    0:41   false       false
...
100  pool-2-thread-1        BLOCKED    0.0    0:38   false       false

关键发现：大量线程处于 BLOCKED 状态，而不是 RUNNABLE。这说明线程在等待某个锁或资源，而不是在执行计算。

为什么 CPU 会高？ —— 虽然 BLOCKED 线程本身不消耗 CPU，但 156 个线程的上下文切换开销、加上频繁的 GC 尝试回收线程栈中的局部变量，导致了 CPU 使用率飙升。

2.2 thread -b：查找阻塞线程

$ thread -b
"pool-1-thread-1" Id=25 BLOCKED on java.util.concurrent.locks.ReentrantLock$NonfairSync@12345678
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1234)
    at com.example.order.service.OrderService.queryOrders(OrderService.java:45)
    at com.example.order.task.DailyReportTask.run(DailyReportTask.java:30)

Blocked by: "pool-3-thread-5" Id=42 RUNNABLE
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1050)
    at com.alibaba.druid.pool.DruidPooledPreparedStatement.executeQuery(DruidPooledPreparedStatement.java:294)
    at com.example.order.service.OrderService.queryOrders(OrderService.java:45)

定位到问题：线程 pool-3-thread-5 持有连接池锁并在执行 SQL 查询，其他线程都在等待获取连接。

2.3 thread --state BLOCKED：查看所有阻塞线程

$ thread --state BLOCKED
"pool-1-thread-1" Id=25 BLOCKED
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1234)
    ...

"pool-1-thread-2" Id=26 BLOCKED
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1234)
    ...

"pool-2-thread-1" Id=100 BLOCKED
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1234)
    ...

确认：共有 156 个线程被阻塞，都在等待获取数据库连接。

三、Druid 连接池分析

3.1 查看连接池状态

$ curl http://localhost:8080/druid/datasource.json
{
    "name": "dataSource",
    "activeCount": 20,
    "maxActive": 20,
    "poolingCount": 0,
    "waitThreadCount": 156,
    "notEmptyWaitCount": 89,
    "emptyWaitCount": 67
}

连接池已满：activeCount=20，maxActive=20，poolingCount=0。所有连接都被占用，没有空闲连接可用。

3.2 查看正在执行的 SQL

$ curl http://localhost:8080/druid/sql.json
{
    "sql": "SELECT o.id, o.order_no, o.amount, u.name FROM orders o JOIN users u ON o.user_id = u.id WHERE o.created_at >= ? AND o.created_at < ?",
    "runningCount": 18,
    "runningMaxTime": 120000,
    "dataSource": "dataSource"
}

18 条相同的 SQL 在同时执行，最长已经跑了 120 秒！

四、数据库端排查

4.1 SHOW PROCESSLIST

登录 MySQL：

mysql> SHOW PROCESSLIST;
+--------+--------+-----------+------------+---------+------+------------+----------------------------------------------------+
| Id     | User   | Host      | db         | Command | Time | State      | Info                                               |
+--------+--------+-----------+------------+---------+------+------------+----------------------------------------------------+
| 12345  | app    | 10.0.1.2  | order_db   | Query   | 120  | Sending data| SELECT o.id, o.order_no, o.amount, u.name FROM ... |
| 12346  | app    | 10.0.1.2  | order_db   | Query   | 118  | Sending data| SELECT o.id, o.order_no, o.amount, u.name FROM ... |
| ...    | ...    | ...       | ...        | ...     | ...  | ...        | ...                                                |
+--------+--------+-----------+------------+---------+------+------------+----------------------------------------------------+

数据库 CPU 使用率：

$ top -p $(pgrep -d',' mysqld)
PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
1234 mysqld    20   0  2.5g  500m   10m S  99.9  6.2  25:30.12 mysqld

数据库 CPU 也被打满了！

4.2 EXPLAIN 分析慢 SQL

mysql> EXPLAIN SELECT o.id, o.order_no, o.amount, u.name 
       FROM orders o 
       JOIN users u ON o.user_id = u.id 
       WHERE o.created_at >= '2026-07-10 00:00:00' 
         AND o.created_at < '2026-07-11 00:00:00';

+----+-------------+-------+------------+--------+---------------+---------+---------+------------------+----------+----------+-------------+
| id | select_type | table | partitions | type   | possible_keys | key     | key_len | ref              | rows     | filtered | Extra       |
+----+-------------+-------+------------+--------+---------------+---------+---------+------------------+----------+----------+-------------+
|  1 | SIMPLE      | o     | NULL       | ALL    | NULL          | NULL    | NULL    | NULL             | 20000000 |    10.00 | Using where |
|  1 | SIMPLE      | u     | NULL       | eq_ref | PRIMARY       | PRIMARY | 8       | order_db.o.user_id|        1 |   100.00 | NULL        |
+----+-------------+-------+------------+--------+---------------+---------+---------+------------------+----------+----------+-------------+

根因确认：

  1. type=ALL：orders 表进行了全表扫描
  2. possible_keys=NULL：没有可用的索引
  3. rows=20000000：扫描了 2000 万行数据

五、事故连锁反应

┌──────────────────────┐
                    │  凌晨定时任务触发      │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  慢 SQL 全表扫描      │
                    │  orders 表 2000 万行  │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  数据库 CPU 打满      │
                    │  SQL 执行超时        │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  数据库连接长时间占用  │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  Druid 连接池耗尽     │
                    │  activeCount = max   │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  应用线程 BLOCKED     │
                    │  等待获取连接        │
                    └──────────┬───────────┘
                               │
                    ┌──────────▼───────────┐
                    │  应用 CPU 飙升        │
                    │  线程调度开销增大    │
                    └──────────────────────┘

六、紧急修复

6.1 终止慢 SQL

mysql> KILL QUERY 12345;
mysql> KILL QUERY 12346;
-- ... 终止所有慢查询

6.2 添加索引

mysql> ALTER TABLE orders ADD INDEX idx_created_at (created_at);
Query OK, 20000000 rows affected (2 min 30 sec)
Records: 20000000  Duplicates: 0  Warnings: 0

6.3 验证索引效果

mysql> EXPLAIN SELECT o.id, o.order_no, o.amount, u.name 
       FROM orders o 
       JOIN users u ON o.user_id = u.id 
       WHERE o.created_at >= '2026-07-10 00:00:00' 
         AND o.created_at < '2026-07-11 00:00:00';

+----+-------------+-------+------------+--------+-----------------+-----------------+---------+------------------+---------+----------+-------+
| id | select_type | table | partitions | type   | possible_keys   | key             | key_len | ref              | rows    | filtered | Extra |
+----+-------------+-------+------------+--------+-----------------+-----------------+---------+------------------+---------+----------+-------+
|  1 | SIMPLE      | o     | NULL       | range  | idx_created_at  | idx_created_at  | 5       | NULL             | 1500000 |   100.00 | NULL  |
|  1 | SIMPLE      | u     | NULL       | eq_ref | PRIMARY         | PRIMARY         | 8       | order_db.o.user_id|       1 |   100.00 | NULL  |
+----+-------------+-------+------------+--------+-----------------+-----------------+---------+------------------+---------+----------+-------+

优化效果：

  • type 从 ALL 变为 range
  • rows 从 2000 万变为 150 万
  • 查询时间从 120+ 秒降到 0.5 秒以内

七、长期优化方案

7.1 Druid 连接池配置优化

spring:
  datasource:
    druid:
      url: jdbc:mysql://localhost:3306/order_db
      username: app
      password: ${DB_PASSWORD}
      driver-class-name: com.mysql.cj.jdbc.Driver
      
      # 连接池大小
      initial-size: 5
      min-idle: 5
      max-active: 20
      
      # 关键：获取连接超时时间，防止线程无限等待
      max-wait: 60000
      
      # 连接空闲回收
      min-evictable-idle-time-millis: 300000
      max-evictable-idle-time-millis: 900000
      
      # 连接泄漏检测
      remove-abandoned: true
      remove-abandoned-timeout: 300
      log-abandoned: true
      
      # SQL 执行超时
      query-timeout: 60

关键配置说明：

参数值作用
max-wait60000ms获取连接超时，防止线程无限等待
remove-abandonedtrue开启连接泄漏检测
remove-abandoned-timeout300s超过 5 分钟未归还的连接视为泄漏
query-timeout60sSQL 执行超时时间

7.2 慢 SQL 告警

@Configuration
public class SlowSqlConfig {
    
    @Bean
    public FilterRegistrationBean<WebStatFilter> webStatFilter() {
        FilterRegistrationBean<WebStatFilter> bean = new FilterRegistrationBean<>();
        bean.setFilter(new WebStatFilter());
        bean.addUrlPatterns("/*");
        bean.addInitParameter("exclusions", "*.js,*.gif,*.jpg,*.png,*.css,*.ico,/druid/*");
        return bean;
    }
    
    @Bean
    public ServletRegistrationBean<StatViewServlet> statViewServlet() {
        ServletRegistrationBean<StatViewServlet> bean = new ServletRegistrationBean<>();
        bean.setServlet(new StatViewServlet());
        bean.addUrlMappings("/druid/*");
        return bean;
    }
    
    // 自定义慢 SQL 监听器
    @Component
    public static class SlowSqlListener extends LogFilter {
        
        @Override
        protected void slowQuery(long sqlMillis, String sql) {
            if (sqlMillis > 500) {
                log.warn("[慢 SQL] 耗时: {}ms, SQL: {}", sqlMillis, sql);
                
                // 发送告警通知
                alertService.sendSlowSqlAlert(sqlMillis, sql);
            }
            super.slowQuery(sqlMillis, sql);
        }
    }
}

7.3 定时任务线程池隔离

@Configuration
public class TaskExecutorConfig {
    
    @Bean("taskExecutor")
    public ThreadPoolTaskExecutor taskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(2);
        executor.setMaxPoolSize(4);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("task-");
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();
        return executor;
    }
    
    @Bean("businessExecutor")
    public ThreadPoolTaskExecutor businessExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(10);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(1000);
        executor.setThreadNamePrefix("business-");
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();
        return executor;
    }
}

@Component
public class DailyReportTask {
    
    @Autowired
    @Qualifier("taskExecutor")
    private ThreadPoolTaskExecutor taskExecutor;
    
    @Scheduled(cron = "0 15 3 * * ?")
    public void execute() {
        taskExecutor.execute(() -> {
            // 定时任务逻辑
            orderService.generateDailyReport();
        });
    }
}

7.4 数据库连接池隔离

spring:
  datasource:
    # 业务连接池
    business:
      url: jdbc:mysql://localhost:3306/order_db
      username: app
      password: ${DB_PASSWORD}
      max-active: 15
    
    # 定时任务连接池
    task:
      url: jdbc:mysql://localhost:3306/order_db
      username: app
      password: ${DB_PASSWORD}
      max-active: 5

八、事故复盘

8.1 问题总结

环节问题影响
SQL 层面created_at 字段缺少索引全表扫描 2000 万行
数据库层面CPU 被打满，SQL 执行超时连接长时间占用
连接池层面无获取连接超时配置线程无限等待
线程池层面定时任务与业务共用线程池资源竞争导致雪崩

8.2 预防措施清单

✅ 慢 SQL 告警：设置 500ms 阈值，超过自动告警
✅ SQL 审核：上线前必须经过 EXPLAIN 分析
✅ 索引监控：定期检查索引使用率，清理无用索引
✅ 连接池超时：配置 max-wait 和 query-timeout
✅ 连接池隔离：业务和定时任务使用独立连接池
✅ 线程池隔离：不同类型任务使用独立线程池
✅ 熔断降级：对数据库查询设置超时和熔断
✅ 容量规划：定期评估数据库和连接池容量

8.3 反思

  1. 为什么没有索引？ —— 初期数据量小时未考虑，后期数据增长后没有及时添加
  2. 为什么没有告警？ —— 慢 SQL 告警阈值设置过高（2 秒），未能及时发现
  3. 为什么会雪崩？ —— 资源未隔离，单点故障引发连锁反应

九、总结

这次事故的教训是深刻的：一条慢 SQL 可以引发整个系统的雪崩。看似简单的问题，在高并发场景下会被无限放大。

核心原则：

  • 资源隔离：定时任务和业务流量必须使用独立的线程池和连接池
  • 超时控制：任何外部依赖调用都必须设置超时时间
  • 监控告警：慢 SQL、连接池状态、线程状态都需要实时监控

💡 互动话题：你遇到过类似的生产事故吗？当时是怎么排查和修复的？欢迎在评论区分享你的经历！

标题：「踩坑日记」002：凌晨三点 CPU 飙到 100%——一条慢 SQL 引发的连锁血案
作者：jiangyi
地址：http://jiangyi.space/articles/2026/07/12/1783751946438.html
公众号：服务端技术精选

服务端开发博客：后端架构、高并发、性能优化与微服务实战教程

取消