故障解析丨一次死鎖問題的解決

来源:https://www.cnblogs.com/greatsql/p/18079727
-Advertisement-
Play Games

背景 業務端遇到報錯為"Deadlock found when trying to get lock; try restarting transaction"則表明有死鎖發生 名稱 配置 資料庫版本 GreatSQL 8.0.26 隔離級別 Read-Commited innodb status 日 ...


背景

業務端遇到報錯為"Deadlock found when trying to get lock; try restarting transaction"則表明有死鎖發生

名稱 配置
資料庫版本 GreatSQL 8.0.26
隔離級別 Read-Commited

innodb status 日誌

greatsql> show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
2024-01-28 16:55:38 140737023727360 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 14 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 41 srv_active, 0 srv_shutdown, 17830 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
-------------
RW-LATCH INFO
-------------
Total number of rw-locks 132361
OS WAIT ARRAY INFO: reservation count 11180
OS WAIT ARRAY INFO: signal count 11177
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-01-28 16:53:40 140735053358848
*** (1) TRANSACTION:
TRANSACTION 37616, ACTIVE 8 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1192, 1 row lock(s), undo log entries 1
MySQL thread id 16, OS thread handle 140737023432448, query id 652 127.0.0.1 root update
insert into info values (50,11)

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 26 page no 5 n bits 80 index uk_name of table `apple`.`info` trx id 37616 lock mode S waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000000b; asc     ;;
 1: len 4; hex 80000028; asc    (;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 26 page no 5 n bits 80 index uk_name of table `apple`.`info` trx id 37616 lock mode S waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000000b; asc     ;;
 1: len 4; hex 80000028; asc    (;;


*** (2) TRANSACTION:
TRANSACTION 37615, ACTIVE 24 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1192, 2 row lock(s), undo log entries 2
MySQL thread id 15, OS thread handle 140737024022272, query id 653 127.0.0.1 root update
insert into info values (60,8)

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 26 page no 5 n bits 80 index uk_name of table `apple`.`info` trx id 37615 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000000b; asc     ;;
 1: len 4; hex 80000028; asc    (;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 26 page no 5 n bits 80 index uk_name of table `apple`.`info` trx id 37615 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000000b; asc     ;;
 1: len 4; hex 80000028; asc    (;;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------

查看表結構

greatsql> show create table info \G
*************************** 1. row ***************************
       Table: info
Create Table: CREATE TABLE `info` (
  `id` int NOT NULL AUTO_INCREMENT,
  `name` int NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `uk_name` (`name`)
) ENGINE=InnoDB AUTO_INCREMENT=61 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.01 sec)

梳理 innodb status 日誌

  • 整理如下：
事務 T1 T2
操作 insert into info values (50,11) insert into info values (60,8)
關聯的對象 表apple.info的唯一索引 uk_name 表apple.info的唯一索引 uk_name
持有的鎖 lock mode S waitingheap no 7 11，40（十六進位為8，28） lock_mode X locks rec but not gapheap no 7 11，40（十六進位為8，28）
等待的鎖 lock mode S waitingheap no 7 11，40（十六進位為8，28） lock_mode X locks gap before rec insert intention waitingheap no 7 11，40（十六進位為8，28）

  • 首先事務T2獲取到了uk_name中記錄11的 lock x,rec not not gap 鎖

  • 事務T1嘗試獲取uk_name中記錄11的lock s, next key lock，由於T2持有了記錄的獨占鎖，因此被T1堵塞

  • 事務T2嘗試獲取uk_name中記錄11的lock x, gap before rec,insert intention，但被堵塞

獲取業務歷史SQL語句

通過系統表方式

通過performance_schema.threads、performance_schema.events_statements_history、performance_schema.events_statements_history_long等系統表獲取歷史SQL

  • 根據GreatSQL thread id獲得線程id
greatsql> select PROCESSLIST_ID,THREAD_ID,THREAD_OS_ID from  performance_schema.threads where processlist_id in (15,16);
+----------------+-----------+--------------+
| PROCESSLIST_ID | THREAD_ID | THREAD_OS_ID |
+----------------+-----------+--------------+
|             15 |        61 |         5714 |
|             16 |        62 |         5719 |
+----------------+-----------+--------------+
2 rows in set (0.00 sec)
  • 根據線程id獲得線程歷史SQL
greatsql> select THREAD_ID,EVENT_ID,CURRENT_SCHEMA,SQL_TEXT,MESSAGE_TEXT,EVENT_NAME,SOURCE from performance_schema.events_statements_history where thread_id in (61,62) order by THREAD_ID,EVENT_ID;
+-----------+----------+----------------+---------------------------------+--------------------------------------------------------------------+--------------------------+---------------------------------+
| THREAD_ID | EVENT_ID | CURRENT_SCHEMA | SQL_TEXT                        | MESSAGE_TEXT                                                       | EVENT_NAME               | SOURCE                          |
+-----------+----------+----------------+---------------------------------+--------------------------------------------------------------------+--------------------------+---------------------------------+
|        61 |     3762 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     3807 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     3852 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     3897 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     3942 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     3987 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     4032 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        61 |     4077 | apple          | begin                           | NULL                                                               | statement/sql/begin      | init_net_server_extension.cc:94 |
|        61 |     4100 | apple          | insert into info values (40,11) | NULL                                                               | statement/sql/insert     | init_net_server_extension.cc:94 |
|        61 |     4569 | apple          | insert into info values (60,8)  | NULL                                                               | statement/sql/insert     | init_net_server_extension.cc:94 |
|        62 |     3215 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3260 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3305 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3350 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3395 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3440 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3485 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3530 | apple          | NULL                            | NULL                                                               | statement/com/Field List | init_net_server_extension.cc:94 |
|        62 |     3575 | apple          | begin                           | NULL                                                               | statement/sql/begin      | init_net_server_extension.cc:94 |
|        62 |     3598 | apple          | insert into info values (50,11) | Deadlock found when trying to get lock; try restarting transaction | statement/sql/insert     | init_net_server_extension.cc:94 |
+-----------+----------+----------------+---------------------------------+--------------------------------------------------------------------+--------------------------+---------------------------------+
20 rows in set (0.00 sec)

  • 觀察show engine innodb status中的GreatSQL thread id 16和GreatSQL thread id 15

  • 通過performance_schema.threads獲取THREAD_ID

  • 通過performance_schema.events_statements_history獲取THREAD_ID執行的歷史SQL以及執行時間

最終可復現出如下業務SQL：

事務 T1 T2
語句 begin; begin;
語句 insert into info values (40,11);
語句 insert into info values (50,11);
語句 insert into info values (60,8);

通過解析binlog

$ mysqlbinlog -vv --base64-output=decode-rows bin.000030

SET @@SESSION.GTID_NEXT= 'e319a624-b2ce-11ee-9aac-00163e62ca8a:8696'/*!*/;
# at 10314
#240128 16:52:35 server id 1024  end_log_pos 10390 CRC32 0x59edb313         Query        thread_id=18        exec_time=0        error_code=0
SET TIMESTAMP=1706431955/*!*/;
BEGIN
/*!*/;
# at 10390
#240128 16:52:35 server id 1024  end_log_pos 10442 CRC32 0xc03dea61         Table_map: `apple`.`info` mapped to number 370
# at 10442
#240128 16:52:35 server id 1024  end_log_pos 10486 CRC32 0x670e0c66         Write_rows: table id 370 flags: STMT_END_F
### INSERT INTO `apple`.`info`
### SET
###   @1=30 /* INT meta=0 nullable=0 is_null=0 */
###   @2=30 /* INT meta=0 nullable=0 is_null=0 */
# at 10486
#240128 16:52:35 server id 1024  end_log_pos 10517 CRC32 0xab4e0d89         Xid = 598
COMMIT/*!*/;
# at 10517
#240128 19:22:12 server id 1024  end_log_pos 10596 CRC32 0x4f4cf08e         GTID        last_committed=30        sequence_number=36        rbr_only=yes        original_committed_timestamp=1706440932450590        immediate_commit_timestamp=1706440932450590 transaction_length=378
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1706440932450590 (2024-01-28 19:22:12.450590 CST)
# immediate_commit_timestamp=1706440932450590 (2024-01-28 19:22:12.450590 CST)
/*!80001 SET @@session.original_commit_timestamp=1706440932450590*//*!*/;
/*!80014 SET @@session.original_server_version=80026*//*!*/;
/*!80014 SET @@session.immediate_server_version=80026*//*!*/;
SET @@SESSION.GTID_NEXT= 'e319a624-b2ce-11ee-9aac-00163e62ca8a:8697'/*!*/;
# at 10596
#240128 16:53:16 server id 1024  end_log_pos 10672 CRC32 0xf222c003         Query        thread_id=15        exec_time=0        error_code=0
SET TIMESTAMP=1706431996/*!*/;
BEGIN
/*!*/;
# at 10672
#240128 16:53:16 server id 1024  end_log_pos 10724 CRC32 0x20cb8c86         Table_map: `apple`.`info` mapped to number 370
# at 10724
#240128 16:53:16 server id 1024  end_log_pos 10768 CRC32 0xd8f53958         Write_rows: table id 370 flags: STMT_END_F
### INSERT INTO `apple`.`info`
### SET
###   @1=40 /* INT meta=0 nullable=0 is_null=0 */
###   @2=11 /* INT meta=0 nullable=0 is_null=0 */
# at 10768
#240128 16:53:40 server id 1024  end_log_pos 10820 CRC32 0x23f22580         Table_map: `apple`.`info` mapped to number 370
# at 10820
#240128 16:53:40 server id 1024  end_log_pos 10864 CRC32 0x182ecdef         Write_rows: table id 370 flags: STMT_END_F
### INSERT INTO `apple`.`info`
### SET
###   @1=60 /* INT meta=0 nullable=0 is_null=0 */
###   @2=8 /* INT meta=0 nullable=0 is_null=0 */
# at 10864
#240128 19:22:12 server id 1024  end_log_pos 10895 CRC32 0x57fd1d3c         Xid = 650
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

根據binlog中部分SET @@SESSION.GTID_NEXT= 'e319a624-b2ce-11ee-9aac-00163e62ca8a:8697'該GTID的事務信息，可恢復T2，但T1執行的語句由於被回滾了，則不會記錄到binlog，可開啟general log日誌獲取排查

事務 T1 T2
語句 begin; begin;
語句 insert into info values (40,11);
語句 insert into info values (50,11);
語句 insert into info values (60,8);

分析死鎖

  • T1、T2開啟了一個事務

  • 隨後T2執行了插入(40,11)的insert語句：insert into info values (40,11)

  • T1執行了插入(50,11)的insert語句：insert into info values (50,11) 進行唯一性衝突檢查，嘗試獲取LOCK_S

  • 然後T1所在的連接會將T2中的隱式鎖轉換為顯示鎖，此時T2將獲取Lock X, Rec_not_gap。由於T2的Lock X, Rec_not_gap與T1的LOCK S不相容，因此T1被堵塞

  • 隨後，T2又執行了(60,8)的insert語句：insert into info values (60,8) 由於其插入的唯一索引值是8，因此不存在主鍵衝突，直接執行樂觀插入操作。執行樂觀插入時，需要檢查其它事務是否堵塞insert操作。其核心是獲取待插入記錄的下一個值（這裡剛好是10），並獲取該記錄上的所有鎖，與需要添加的鎖判斷是否存在衝突。

  • T1持有了記錄11的LOCK_S鎖與T2的LOCK_X、LOCK_INSERT_INTENTION不相容，因此T2被T1堵塞

  • 死鎖形成。

解決

• 適當的減少Unique索引

• 避免插入重覆的值（唯一索引所在列）

Enjoy GreatSQL

您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • FTP的安裝和使用
    實驗環境： windows server虛擬機一臺 網路適配器：vmnet1 ip：192.168.1.220 一.安裝FTP服務 打開伺服器管理器 點擊添加角色，勾IIS，點擊下一步直到對話框消失 勾選FTP 從開始菜單找到管理工具 打開IIS 可以看見ftp服務的相關信息，說明安裝成功 二：新建 ...
  • 使用zabbix實現郵箱/釘釘告警
    目錄一、zabbix部署1、安裝zabbix服務端2、準備資料庫（mariadb簡單點）3、修改服務的配置二、登錄zabbix三、客戶端配置1、安裝軟體包2、修改配置文件3、啟動客戶端服務四、報錯解決五、添加監控主機1、安裝軟體包2、修改配置文件3、啟動客戶端服務4、回到zabbix添加主機5、添加 ...
  • 正點原子AtomPi-CA1 RK3568的Linux CH340串口驅動安裝
    想使用串口，找了半天也沒找到它所給的pin的使用示例，淘寶客服說只是硬體相容樹莓派。 想來想去，還是直接接個USB串口最方便。 但是插上不識別，說明沒有驅動。 直接在板子上編譯沒有header依賴，後續下載華碩對應的arm依賴能編譯但是驅動不能正常使用。 就在所給虛擬機上交叉編譯。 先按照手冊配置好 ...
  • innodb_log_file_size 和 innodb_buffer_pool_size
    innodb_log_file_size 和 innodb_buffer_pool_size 是 MySQL 資料庫中 InnoDB 存儲引擎的兩個重要配置參數。它們對資料庫的性能和可靠性有著顯著的影響。 1. innodb_log_file_size innodb_log_file_size 參數 ...
  • 記錄惡意SQL註入引發的RDS只讀資料庫CPU飈100%
    前言: 在廣州這座城市下著小雨的晚上，我正在廚房洗著碗，突然手機有來電，脫下手套，一看是來自阿裡雲的告警電話。打開飛書查看告警內容，發現某個業務的RDS只讀實例CPU飈到100%，下意識覺得是不是有慢查詢導致，想著不會有啥問題，上去kill慢查就好了，結果發現是大問題....一、發現問題 2024年 ...
  • [20240313]使用tpt ashtop.sql腳本的困惑.txt
    我司使用Apache DolphinScheduler作為調度框架很久了，感興趣的小伙伴可以看看這些乾貨文章： 因為之前監控到會出現重覆的調度的問題，所以此文記錄排查重覆調度問題的全過程，希望對社區其他的小伙伴能夠起到拋磚引玉的作用！ 註：本文使用的DolphinScheduler 3.1.1的版本 ...
  • 詳解GaussDB(DWS)中3個防過載檢查項
    本文分享自華為雲社區《【防過載檢查項】》，作者： 譡里個檔。 1. GUC參數檢查 目的：針對不同版本建議設定不同的參數值，當前先檢查出來，後續diagnosis會給出建議值 SELECT split_part((substring(version() from '\((.*)\)')), ' ', ...
  • 特新介紹 | MySQL生態現有計算下推方案彙總
    作者：盧文雙 資深資料庫內核研發 本文首發於 2024-03-06 20:52:24 https://dbkernel.com 前言 計算下推是資料庫優化器優化查詢性能的一種常見手段，早期的資料庫系統提及的計算下推一般是指謂詞下推，其理論源自關係代數理論。2000 年以後，隨著 Oracle RAC ...
一周排行
    -Advertisement-
    Play Games
  • 移動開發（一）：使用.NET MAUI開發第一個安卓APP
    移動開發（一）：使用.NET MAUI開發第一個安卓APP 對於工作多年的C#程式員來說，近來想嘗試開發一款安卓APP，考慮了很久最終選擇使用.NET MAUI這個微軟官方的框架來嘗試體驗開發安卓APP，畢竟是使用Visual Studio開發工具，使用起來也比較的順手，結合微軟官方的教程進行了安卓 ...
  • wpf ToggleButton選中效果和一個登錄界面
    前言 QuestPDF 是一個開源 .NET 庫，用於生成 PDF 文檔。使用了C# Fluent API方式可簡化開發、減少錯誤並提高工作效率。利用它可以輕鬆生成 PDF 報告、發票、導出文件等。 項目介紹 QuestPDF 是一個革命性的開源 .NET 庫，它徹底改變了我們生成 PDF 文檔的方 ...
  • 彈幕樹洞項目功能新增篇
    項目地址 項目後端地址： https://github.com/ZyPLJ/ZYTteeHole 項目前端頁面地址： ZyPLJ/TreeHoleVue (github.com) https://github.com/ZyPLJ/TreeHoleVue 目前項目測試訪問地址： http://tree ...
  • 第27篇 sqlserver2022詳細安裝步驟
    話不多說，直接開乾 一.下載 1.官方鏈接下載： https://www.microsoft.com/zh-cn/sql-server/sql-server-downloads 2.在下載目錄中找到下麵這個小的安裝包 SQL2022-SSEI-Dev.exe，運行開始下載SQL server； 二. ...
  • .NET 開源高性能 MQTT 類庫
    前言 隨著物聯網（IoT）技術的迅猛發展，MQTT（消息隊列遙測傳輸）協議憑藉其輕量級和高效性，已成為眾多物聯網應用的首選通信標準。 MQTTnet 作為一個高性能的 .NET 開源庫，為 .NET 平臺上的 MQTT 客戶端與伺服器開發提供了強大的支持。 本文將全面介紹 MQTTnet 的核心功能 ...
  • Serilog文檔翻譯系列（六） - 可用的接收器、增強器、格式化輸出
    Serilog支持多種接收器用於日誌存儲，增強器用於添加屬性，LogContext管理動態屬性，支持多種輸出格式包括純文本、JSON及ExpressionTemplate。還提供了自定義格式化選項，適用於不同需求。 ...
  • 警惕 Visual Studio 屬性求值副作用導致邏輯不符合預期
    目錄簡介獲取 HTML 文檔解析 HTML 文檔測試參考文章 簡介 動態內容網站使用 JavaScript 腳本動態檢索和渲染數據，爬取信息時需要模擬瀏覽器行為，否則獲取到的源碼基本是空的。 本文使用的爬取步驟如下： 使用 Selenium 獲取渲染後的 HTML 文檔 使用 HtmlAgility ...
  • [使用目前最新版]HybridCLR6.9.0+YooAsset2.2.4實現純C# Unity熱更新方案 (一)
    1.前言 什麼是熱更新 游戲或者軟體更新時，無需重新下載客戶端進行安裝，而是在應用程式啟動的情況下，在內部進行資源或者代碼更新 Unity目前常用熱更新解決方案 HybridCLR，Xlua，ILRuntime等 Unity目前常用資源管理解決方案 AssetBundles，Addressable， ...
  • 在 ASP.NET Core Web API 中使用操作篩選器統一處理通用操作
    本文章主要是在C# ASP.NET Core Web API框架實現向手機發送驗證碼簡訊功能。這裡我選擇是一個互億無線簡訊驗證碼平臺，其實像阿裡雲，騰訊雲上面也可以。 首先我們先去 互億無線 https://www.ihuyi.com/api/sms.html 去註冊一個賬號 註冊完成賬號後，它會送 ...
  • 第28篇 如何.net中實現高效可靠數據同步api
    通過以下方式可以高效，並保證數據同步的可靠性 1.API設計 使用RESTful設計，確保API端點明確，並使用適當的HTTP方法（如POST用於創建，PUT用於更新）。 設計清晰的請求和響應模型，以確保客戶端能夠理解預期格式。 2.數據驗證 在伺服器端進行嚴格的數據驗證，確保接收到的數據符合預期格 ...
所有分類