mysql更新獲取鎖超時線上解決過程

    最近有一個接口偶然出現超時報500的狀況，經過服務後臺log，發現如下錯誤，說白了就是在更新mysql的時候，獲取排它鎖超時致使更新失敗了。

org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.dao.CannotAcquireLockException: PreparedStatementCallback; SQL [UPDATE news SET news.quality = ? WHERE news.pk = ?]; Lock wait timeout exceeded; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction

　　

exception的堆棧以下：

    

這是什麼緣由呢？我在想，會不會是代碼在同一個事務裏面有死鎖的狀況，因而查看了代碼，發現代碼使用的是spring「聲明式」事務，該接口的業務層面不會發生死鎖的狀況。

    因而我想，會不會是和其餘的事務有交叉加鎖而致使死鎖呢？因而經過mysql的「show engine innodb status;」語句把最近的死鎖信息copy出來檢查了一遍，發現最近的「LATEST DETECTED DEADLOCK」的相關數據裏面並無和news表相關的dead lock，那說明可能不是死鎖致使的。

    因而我想着去服務器看下報錯的那個時間附近有沒有相關的慢查詢，經過耗時和時間過濾，一看，果真，報錯的附近時間恰好有一個很慢的慢查詢，以下圖最後一行，耗時達到了57s，掃描了六千多萬行記錄，嚇我一跳，以下圖：

 

    

    上圖的第一行，就是報錯接口業務層執行的更新語句，說明接口在更新mysql的時候，等待了51s，還沒競爭到鎖，因此失敗了。可是那個慢查詢是select類型的語句，根據mysql的mvvc樂觀鎖，不該該鎖表纔對啊，因而猜想多是同一個事物裏面，包含了update的語句以及該慢查詢。這個事務先是update news表，這時候鎖住相關記錄，而後再執行這個慢查詢，等慢查詢結束以後，才釋放鎖，那就說明確實是這個慢查詢的長事務致使的。因而根據這個sql的來源ip，原來是大數據團隊的sql，經過大數據團隊的確認，確實是猜測的那樣，有個長事務，在同一個事務裏面，先是update了news表，而後執行了上面的慢查詢。因而讓大數據團隊趕忙優化sql，優化sql以後，持續跟蹤了一段時間，發現這個問題不在出現。

    這裏還有一個小問題，上面的報錯接口業務執行的update語句，爲何是持續競爭鎖51s以後，就報錯了呢？mysql的innodb引擎是有個事務鎖超時的時間的，經過如下語句能夠查到：

# 查詢全局等待事務鎖超時時間
SHOW GLOBAL VARIABLES LIKE 'innodb_lock_wait_timeout';
​
# 查詢當前會話等待事務鎖超時時間
SHOW VARIABLES LIKE 'innodb_lock_wait_timeout';

　　

    經過查詢，mysql服務器的事務鎖超時時間恰好是50s，以下，和上面實際獲取鎖超時51s相差了1s，多是有必定的偏差的吧。

innodb_lock_wait_timeout  50

　　

    謝謝觀賞~

 

　　　　　　　　　　　　　　　　　　　　　　　歡迎關注微信公衆號「ismallboy」，請掃碼並關注如下公衆號，並在公衆號下面回覆「lock」，得到本文最新內容。