【BUG】生产环境死锁问题定位排查解决全过程

- - 生产环境死锁问题定位排查解决过程
  - - 0. 表面现象
    - 1. 问题分析
    - - （1）数据库连接池资源耗尽
      - （2）数据库锁竞争
      - (3) 代码实现问题
    - 2. 分析解决
    - - (0) 分析过程
      - （1）优化数据库连接池配置
      - （2）优化数据库锁争用
      - （3）优化应用程序
    - 3. 总结

生产环境死锁问题定位排查解决过程

背景：访问项目的生产页面，发现页面上数据加载卡顿，没一会儿有很多接口超时的错误，通过查看服务日志和数据库日志，可以确定是生产数据库死锁了，以下是定位分析并解决死锁的全过程。

根据提供的报错信息和数据库日志，当前服务异常的原因可能是 数据库连接池资源耗尽 和 数据库锁争用。以下是详细分析和解决方案：

0. 表面现象

页面上所有该微服务的请求都无法响应，都是超时失败；

1. 问题分析

（1）数据库连接池资源耗尽

报错信息：

Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 20, maxActive 20, creating 0, runningSqlCount 10

active 20, maxActive 20：当前连接池中的所有连接（20 个）都被占用。
wait millis 60000：应用程序在等待 60 秒后仍未获取到连接，最终超时。
runningSqlCount 10：当前有 10 条 SQL 正在执行。

原因：
- 连接池的最大连接数（maxActive）设置过小，无法满足高并发请求。
- 某些 SQL 查询执行时间过长，导致连接被长时间占用。
- 可能存在连接泄漏（未正确关闭连接）。

（2）数据库锁竞争

数据库日志：

00000: 2025-03-24 09:58:55 CST [4101193]: [5-1] user = postgres,db = card_online,remote = 10.246.194.141(45236) app = PostgreSQL JDBC Driver
DETAIL:  Process holding the lock: 4094261. Wait queue: 4094260, 4094259, 4094258, 4101188, 4094257, 4101189, 4101191, 4101190, 4101192, 4101193, 4101194, 4101195, 4101197, 4101196, 4101198, 4101199, 4101200, 4101201, 4101202.

Process holding the lock：某个进程（PID: 4094261）持有锁。
Wait queue：大量进程（如 4094260、4094259 等）在等待锁。

原因：
- 某个长时间运行的事务或查询持有锁，导致其他事务被阻塞。
- 锁争用进一步加剧了连接池资源的耗尽。

(3) 代码实现问题

导致数据库死锁所使用的线程池代码

@EnableAsync
@Configuration
public class AsyncPoolConfig implements AsyncConfigurer {/*** 核心线程池大小*/private static final int CORE_POOL_SIZE = Runtime.getRuntime().availableProcessors() * 2;/*** 最大可创建的线程数*/private static final int MAX_POOL_SIZE = CORE_POOL_SIZE * 5;/*** 队列最大长度*/private static final int QUEUE_CAPACITY = 1000;/*** 线程池维护线程所允许的空闲时间*/private static final int KEEP_ALIVE_SECONDS = 300;private static final Logger log = LoggerFactory.getLogger(AsyncPoolConfig.class);// 创建线程池@Bean(name = "threadPoolTaskExecutor")public ThreadPoolTaskExecutor threadPoolTaskExecutor() {ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();executor.setMaxPoolSize(MAX_POOL_SIZE);executor.setCorePoolSize(CORE_POOL_SIZE);executor.setQueueCapacity(QUEUE_CAPACITY);executor.setKeepAliveSeconds(KEEP_ALIVE_SECONDS);// 线程池对拒绝任务(无线程可用)的处理策略executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());executor.setThreadNamePrefix("async-task-");return executor;}.....
}

2. 分析解决

业务背景：涉及到的目标模块是一个每天上午10点执行的定时任务，该任务大概内容是从数据库中根据条件查询出相应数据，然后批量插入到另一个数据库表中，涉及到的数据库表数据量大概在 3000w ~ 5000W，原来该定时任务执行的太慢了，后面重构后改为使用线程池并发执行。

(0) 分析过程

根据AsyncPoolConfig 类中的实现，因为服务器是48核的，所以按照代码中的计算公式可得：

CORE_POOL_SIZE = 96
MAX_POOL_SIZE = 480

但是该微服务使用 Druid 管理数据库连接池，最多才20个连接，定时任务开始运行后，线程池中所有线程火力全开，数据库连接池瞬间就被打满了，再加上该微服务其它模块也有数据库连接使用的需求，导致数据库死锁。

（1）优化数据库连接池配置

增加连接池大小：
在 application.yml 中调整 Druid 连接池的配置：

spring:datasource:druid:max-active: 50  # 增加最大连接数initial-size: 10min-idle: 10max-wait: 30000  # 减少等待超时时间

监控连接池状态：
使用 Druid 的监控功能，检查连接池的使用情况：
```
spring:datasource:druid:stat-view-servlet:enabled: trueurl-pattern: /druid/*login-username: adminlogin-password: admin
```
访问 http://<your-service>/druid，查看连接池的活跃连接、等待连接等信息。
检查连接泄漏：
确保所有数据库连接在使用后正确关闭。可以通过 Druid 的 removeAbandoned 配置检测泄漏连接：
```
spring:datasource:druid:remove-abandoned: trueremove-abandoned-timeout: 300  # 超过 300 秒未关闭的连接会被回收
```

（2）优化数据库锁争用

查找持有锁的进程：
在 PostgreSQL 中运行以下查询，查找当前持有锁的进程和等待锁的进程：

SELECTblocked_locks.pid AS blocked_pid,blocked_activity.usename AS blocked_user,blocking_locks.pid AS blocking_pid,blocking_activity.usename AS blocking_user,blocked_activity.query AS blocked_query,blocking_activity.query AS blocking_query
FROMpg_catalog.pg_locks blocked_locks
JOIN pg_catalog.pg_stat_activity blocked_activityON blocked_activity.pid = blocked_locks.pid
JOIN pg_catalog.pg_locks blocking_locksON blocking_locks.locktype = blocked_locks.locktypeAND blocking_locks.database IS NOT DISTINCT FROM blocked_locks.databaseAND blocking_locks.relation IS NOT DISTINCT FROM blocked_locks.relationAND blocking_locks.page IS NOT DISTINCT FROM blocked_locks.pageAND blocking_locks.tuple IS NOT DISTINCT FROM blocked_locks.tupleAND blocking_locks.virtualxid IS NOT DISTINCT FROM blocked_locks.virtualxidAND blocking_locks.transactionid IS NOT DISTINCT FROM blocked_locks.transactionidAND blocking_locks.classid IS NOT DISTINCT FROM blocked_locks.classidAND blocking_locks.objid IS NOT DISTINCT FROM blocked_locks.objidAND blocking_locks.objsubid IS NOT DISTINCT FROM blocked_locks.objsubidAND blocking_locks.pid != blocked_locks.pid
JOIN pg_catalog.pg_stat_activity blocking_activityON blocking_activity.pid = blocking_locks.pid
WHERENOT blocked_locks.granted;

终止阻塞进程：
如果发现某个进程长时间持有锁，可以终止该进程。可通过临时 kill 掉阻塞进程快速恢复生产。要彻底解决掉死锁，还是需要着手业务代码，修改实现，破坏掉构成死锁的条件。
```
SELECT pg_terminate_backend(<blocking_pid>);
```
优化慢查询：
检查并优化执行时间较长的 SQL 查询，减少锁持有时间。可以通过以下查询查找慢查询。或者如果你的数据库打开了慢SQL 记录日志，也可以通过数据库日志结合服务日志，根据相应的执行时间查找对应的慢SQL。
```
SELECTpid,usename,query,state,now() - query_start AS duration
FROMpg_stat_activity
WHEREstate != 'idle'AND now() - query_start > interval '5 minutes'
ORDER BYduration DESC;
```

（3）优化应用程序

调整线程池参数：

为该任务专门创建了一个线程池，其实现与原来使用的公共线程池基本相同，只是核心线程数、最大线程数、等待队列这3个参数根据服务器配置和Druid 数据库连接池配置进行了调整。

因为该任务是一个定时任务，只是在每天的一个固定时间执行，大部分时间核心线程处于闲置状态，所以核心线程数过大会消耗不必要的资源，因此 CORE_POOL_SIZE 设置成5；

当定时任务开始执行时会有大量的数据查询任务被丢进线程池，所以最大线程数可以设置的稍大些但一定不能超过数据库连接池内的连接数（避免相同情况下继续死锁），同时也要给该微服务的其它模块留数据库操作的余量，因此MAX_POOL_SIZE 设置成数据库连接池的一半大小。

因为执行任务所反问的数据表数据量大概在 4000万 这个级别，使用线程池进行并发执行，每个线程批量插入时的 BATCH_SIZE 为 5000，为保证整个任务执行过程不丢失数据，于是将任务队列的大小设置成 QUEUE_CAPACITY = 10000。
```
CORE_POOL_SIZE = 5
MAX_POOL_SIZE = 20
QUEUE_CAPACITY = 10000
```

3. 总结

根本原因：

定时任务使用连接池线程数设置过大，导致定时任务执行时，数据库连接池资源耗尽，数据库锁竞争造成死锁导致大量请求被阻塞。
解决方案：
先 kill 掉阻塞进程优先恢复生产，定位到服务中的死锁代码后，通过修改配置和服务代码的实现来彻底解决问题。
- 优化连接池配置，增加连接数并检测连接泄漏；
- 调整目标任务使用线程池的配置，避免其将数据库连接池资源耗尽，并给该服务其它模块数据库连接留余量；