【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 掉阻塞進程優先恢復生產，定位到服務中的死鎖代碼后，通過修改配置和服務代碼的實現來徹底解決問題。
- 優化連接池配置，增加連接數并檢測連接泄漏；
- 調整目標任務使用線程池的配置，避免其將數據庫連接池資源耗盡，并給該服務其它模塊數據庫連接留余量；