背景

最近業務系統生產環境的IDB在執行事務的過程中出現了ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction 異常。通過相關資料的查詢和了解，發現出現這個問題的原因是產生了懸掛事務。整個排查的過程也比較困難，因此和大家分享下排查問題的經過。如果文中有錯漏的地方，歡迎大家指正。

原理篇

? 什么是事務

首先介紹下事務的相關知識。什么是事務？事務就是用戶定義的一系列數據庫操作，這些操作可以視為一個完成的邏輯處理工作單元，要么全部執行，要么全部不執行，是不可分割的工作單元。

事務的的四大特性：原子性（Atomicity）、一致性(Consistency)、隔離性(Isolation)、持久性(Durability)。

mysql innodb引擎是如何實現上面四個特性的？

事務的隔離性由鎖機制+MVCC實現。

事務的原子性、一致性和持久性由事務的 redo 日志和undo 日志來保證。

mysql的鎖主要分為 共享鎖（S Lock）、排它鎖（X Lock）

共享鎖（S Lock）：共享鎖又稱為讀鎖，簡稱S鎖，共享鎖就是多個事務對于同一數據可以共享一把鎖，都能訪問到最新數據。但是不能執行Update、Delete操作。

排它鎖（X Lock）：排它鎖又稱為寫鎖，簡稱X鎖，排它鎖不能與其它鎖并存，而且只有一個事務能拿到某一數據行的排它鎖，其余事務不能再獲取該數據行的所有鎖。一旦有一個事務獲取了該數據的排它鎖之后，其余事務對于該數據的操作將會被阻塞，直至鎖釋放。常見的排他鎖：行鎖、間隙鎖等等。

mysql的重要日志：redo log、undo log和binlog

redo log：重做日志，記錄的是事務提交時數據頁的物理修改，是用來實現事務的持久性。該日志文件由兩部分組成：重做日志緩沖（redo log buffer）以及重做日志文件（redo log file）,前者是在內存中，后者在磁盤中。

當事務提交之后會把所有修改信息都存到該日志文件中, 用于在刷新臟頁到磁盤,發生錯誤時, 進行數據恢復使用。mysql在進行修改操作的時候并不是直接進行磁盤IO，因為那樣效率太低。而是將修改操作寫到緩存區（redo log buffer）中，再在適合的時機進行刷頁。為了防止緩存區中的數據因為意外錯誤丟失，所以會將緩沖區的數據寫入到redo 日志。

undo log：主要記錄的是數據的邏輯變化，為了在發生錯誤時回滾之前的操作，需要將之前的操作都記錄下來，然后在發生錯誤時才可以回滾。undo log和redo log記錄物理日志不一樣，它是邏輯日志?？梢哉J為當delete一條記錄時，undo log中會記錄一條對應的insert記錄，反之亦然，當update一條記錄時，它記錄一條對應相反的update記錄。當執行rollback時，就可以從undo log中的邏輯記錄讀取到相應的內容并進行回滾。

binlog: 歸檔日志，屬于邏輯日志，是以二進制的形式記錄的，用于記錄數據庫執行的寫入性操作(不包括查詢)信息。binlog不僅會記錄insert操作，還會記錄對應的反向操作delete，binlog提供基于時間點的數據恢復能力。

binlog的主要使用場景：主從復制和數據恢復。對于數據恢復場景，我們可以通過使用mysqlbinlog工具來恢復數據。集團內的IDB的數據追蹤功能也是利用binlog實現的，可用于找回被誤操作的數據。

一次事務的執行過程大致如下：

如上圖所示，事務執行流程步驟（更新操作）：

查詢數據若Buffer Pool存在，則輸出，不存在則讀取磁盤中的數據并放入Buffer Pool；

更新操作，會先將數據的舊值寫入undo log，以便回滾。（保證原子性）；

更新Buffer Pool（內存）數據；

將更新數據寫入到Redo Log Buffer（內存中）；

準備提交事務，會調用fsync將Redo Log Buffer的值刷入到redo log日志文件中，狀態為prepare；

準備提交事務，binlog 日志寫入磁盤；

binlog寫入成功后，將redo log的狀態變更為commit；

在合適的時間，將Buffer Pool的數據刷盤；

? 什么是懸掛事務

正常的事務流程 （人為控制事務提交）：begin, rollback, commit。正常情況下的流程如下：

試想一下，如果我們開啟一個事務，但不rollback也不commit這個事務，會發生什么現象。答案是：事務將一直掛起，事務中獲得的鎖也不會被釋放，其他事務也無法操作被鎖定的數據，此時就產生了懸掛事務。伴隨著懸掛事務的產生，通常會出現ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction 這個錯誤。下面舉個簡單的例子：

事務1會獲得id=2的行鎖，然后一直不釋放，事務1的會話將一直存在。事務2也要獲得id=2的行鎖，這時，事務2開始等待id=2的行鎖釋放，到了默認的超時時間50s（mysql的默認超時時間參數：

innodb_lock_wait_timeout=50），事務2拋出異常：ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction 。事務1除了人為commit或者殺死該進程，否則事務1的進程永遠處于掛起狀態（即sleep狀態）。

? 懸掛事務產生的問題

如果一個數據庫連接中開啟事務且未顯式提交或回滾，在不考慮其他因素的前提下，只有在連接斷開的時候才會回滾或者將該事務的進程殺死，該事務才會被回滾。這樣一來，懸掛事務將會帶來兩個非常嚴重的問題。

懸掛事務不回滾，隨著用戶操作越來越多，懸掛事務也會不斷堆積，整張表被鎖的數據行也會越來越多。最終會導致這個表被完全鎖住。所有的后續事務都無法獲取鎖而導致獲取鎖超時，整個系統徹底崩潰。

懸掛事務回滾，當前這段時間內，用戶提交的數據是無法找回的。參考上面的事務執行過程，這個事務其實是被認為失敗了，被rollback掉了，也無法通過binlog找回丟失的數據。

實踐篇

在前半部分，我分享了有關懸掛事物的相關知識。下面我將分享一例生產環境中的關于懸掛事務的案例。

?起因

某日中午，釘釘報警群里面開始零星出現 Lock wait timeout exceeded; try restarting transaction異常（如下圖所示）。立即開始排查問題，到了下午的時候，釘釘報警群開始大量出現無法獲得數據庫鏈接和獲取鎖超時異常，系統開始出現用戶無法提交數據的情況。我立即和團隊內的小伙伴的開始緊急處理這個問題。

一開始的時候，通過查閱相關資料，已經定位到產生問題的原因是產生了懸掛事務。那么懸掛事務怎么產生的呢？Spring提供了兩種實現事務的方式，@Transactional 注解 和 調用事務管理器的getTransaction方法。值得注意的是getTransaction需要自己控制commit和rollback邏輯。

而@Transactional注解則不需要。我們立即排查了最近上線的幾個需求是否使用了getTransaction這種人工控制事務的方式，因為手動控制事務的方式，極有可能會出現事務不commit的情況。通過排查，最近上線的需求沒有使用getTransaction這種人工控制事務，初步排除是最近上線的需求導致的。

我們再次開始排查系統中使用了getTransaction這種人工控制事務的方式的代碼，系統中大概有7-8處使用了這種方式，這些代碼最后一次提交日期大概是2020年，大致走查下來，也沒發現什么問題。其實很難通過這種方式排查出原因。

隨著時間的流逝，由于懸掛事務的存在導致其他正常的事務也無法執行，數據庫中的活躍會話越來越多，越來越多的用戶無法提交數據。我們可以從活躍會話得到當前正在執行的sql，導致這些sql無法提交的原因是前面的懸掛事務導致的，無法從當前眾多的活躍會話中提取到更多的有效信息。

我們立即聯系DBA，協助解決問題。DBA確認了懸掛事務的存在（部分事務執行了3個多小時一直未提交），由于這些進程處于sleep狀態，DBA也無法找出關聯的sql。事后，查閱了相關資料，發現下面的方法可以找出“可能”的懸掛事務。我們請求DBA將這些懸掛事務的進程全部殺掉（即使不殺掉，這些事務也無法被 commit）。

隨著懸掛事務的進程被清理掉之后，數據庫活躍會話開始逐漸減少，系統開始正常工作。然而，好景不長，因為一直沒找到產生懸掛事務的根源，大約10分鐘后又開始出現了Lock wait timeout exceeded; try restarting transaction異常。

我嘗試從SLS日志（我們系統的所有日志均會被采集到SLS日志系統中）出發，看看能否找到錯誤日志從而定位到問題。我重點查看了系統恢復到再次發生問題的這段時間的所有日志，終于發現下圖這個異常。其實這段時間內系統的亂七八糟異常信息很多。

能重點注意到這個異常的主要的原因主要是在第2步的時候，我對這段代碼（AddServiceToCart）有點印象，記得這段代碼好像使用的是手動事務控制事務的。

重點查看AddServiceToCart這段代碼，立即發現問題。這段代碼大致下面這樣的方式實現的。

在jsonObject.getLong("quota")時，quota不是Long型，jsonObject.getLong拋出RuntimeException，由于異常沒有被捕獲，事務的rollback和commit都沒被執行，這樣這個事務就會一直存在。除了應用重啟和人工殺掉該事務的進程，讓這個事務回滾，沒有其他辦法。

而這樣做帶來的后果是這段時間內用戶提交的數據都會丟失。如果想要找回，可能只能自己通過應用日志，自己將丟失的數據找回，然后人工將數據重新錄入。通過mysql的binlog是無法直接找回的。

?復盤

從前面的實踐篇章節中，我們很容易知道兩個事務要操作相同行的數據會產生鎖等待的情況。那么是不是意味著上面的代碼只會影響到自己事務里面的表呢？現在假設上面的代碼只會用到A表，那么是不是同一數據庫中的其他的B、C、D表是不是不受影響呢。先揭曉答案：會受到影響，B、C、D表的數據行也會被鎖。這是為啥？

首先介紹一下Spring的事務的實現機制。

Spring事務是如何保證iBatis執行sql時，這些sql用的是相同的Connection？答案是：ThreadLocal。在執行完doBegin方法后，其實是通過bindResouce方法將從DruidDataSource連接池中獲得的鏈接放入當前線程的TheadLocal,這里的TheadLocal中存放的是一個Map, key是dataSouce，value是connectionHolder（connectionHolder中持有Connection的引用。近似認為connectionHolder和Connection是一回事）。

IBatis在執行sql時，通過DataSourceUtils.getConnection獲取數據庫鏈接。這里會優先從當前線程的ThreadLocal中獲取，如果獲取不到，從數據源中獲取。

ThreadLocal中的變量什么時候會被清除呢？當commit和rollback的時候，ThreadLocal中的變量會被清理掉。

從上面的分析過程中，可以看出，當事務沒有被commit和rollback的時候，當前線程可能會有上次殘留的ThreadLocal的。因為當前線程是從線程池中獲取的，線程是會被復用的。如果當前線程之前執行的事務沒有被正確commit或者rollback的話，現在繼續要獲取鏈接并執行sql，由于上次是開啟了事務且未提交，這次的sql也會被認為進入事務，這些sql也會鎖住相應的數據行，這樣就造成數據庫中大面積的表被鎖。

總結

盡量不使用getTransaction這種人工控制事務（這種方式比較容易埋坑，推薦使用@Transactional ），如果要使用，請務必要try catch。一定注意提前return的問題（由于提前return導致rollback和commit都沒被執行，這種case也很常見）。否則萬一出問題，可能真的很頭大；

參數校驗一定要嚴謹，任何類型轉化的地方不做類型檢查可能都會產生異常；



審核編輯：劉清