MySQL 死鎖與日誌二三事

發表於2017-07-31

最近線上 MySQL 接連發生了幾起資料異常,都是在凌晨爆發,由於業務場景屬於典型的資料倉儲型應用,白天壓力較小無法復現。甚至有些異常還比較詭異,最後 root cause 分析頗費周折。那實際業務當中我們們如何能快速的定位線上 MySQL 問題,修復異常呢?下文我會根據兩個實際 case,分享下相關的經驗與方法。

1、Case1:部分資料更新失敗

某天渠道同學反饋某報表極個別渠道資料為 0,大部分渠道資料正常。這個資料是由一個統計程式每天凌晨例行更新的,按理來說,要麼全部正常,要麼全部失敗,那會是什麼原因導致極個別資料異常呢?

首先我們能想到的自然是根據統計任務日誌來看了,但是看了統計程式列印的日誌沒有發現諸如 SQL update 失敗的異常描述,那當時的資料庫究竟發生了什麼呢?在檢視 MySQL-server 日誌之前,習慣性的看了下資料庫狀態:

恰好看到了凌晨這個 update 發生了死鎖:

篇幅所限,上下文我這裡省略了很多,從這段日誌裡可以看到,TRANSACTION 1 和 TRANSACTION 2 分別持有一定數量的行鎖,然後又等待對方的鎖,最後 MySQL 檢測到 deadlock ,然後選擇回滾了 TRANSACTION 1:Innodb目前處理死鎖的方法是將持有最少行級排他鎖的事務進行回滾。

那這裡就有 3 個問題了:

(1)innodb 行鎖不是隻鎖一行?

因為這張表是 innodb 引擎的,InnoDB 支援行鎖和表鎖。而InnoDB行鎖是通過給索引上的索引項加鎖來實現的,這一點MySQL與Oracle不同,後者是通過在資料塊中對相應資料行加鎖來實現的。InnoDB這種行鎖實現特點意味著:只有通過索引條件檢索資料,InnoDB才使用行級鎖,否則,InnoDB將使用表鎖,會把所有掃描過的行都鎖定!在實際應用中,要特別注意InnoDB行鎖的這一特性,不然的話,可能導致大量的鎖衝突,從而影響併發效能。由於MySQL的行鎖是針對索引加的鎖,不是針對記錄加的鎖,所以雖然是訪問不同行的記錄,但是如果是使用相同的索引鍵,是會出現鎖衝突的。當我們用範圍條件而不是相等條件檢索資料,並請求共享或排他鎖時,InnoDB會給符合條件的已有資料記錄的索引項加鎖;另外間隙鎖也會鎖多行,InnoDB除了通過範圍條件加鎖時使用間隙鎖外,如果使用相等條件請求給一個不存在的記錄加鎖,InnoDB也會使用間隙鎖!

話都說到這了,那就看下我們們業務表的索引情況:

可以看到這張表的索引極不合理:有3個索引,但是 update 卻沒有完全的用上索引,導致 update 沒有精確的用上索引,需要鎖定多行範圍資料,從而引發死鎖。

知道原理後,我們們再精心構建一個四欄位的組合索引即可讓 update 精準的走 innodb 索引,實際上,我們更新索引後,這個死鎖問題即得到了解決。
注:innodb不僅會列印出事務和事務持有和等待的鎖,而且還有記錄本身,不幸的是,它可能超過innodb為輸出結果預留的長度(只能列印1M的內容且只能保留最近一次的死鎖資訊),如果你無法看到完整的輸出,此時可以在任意庫下建立innodb_monitor或innodb_lock_monitor表,這樣innodb status資訊會完整且每15s一次被記錄到錯誤日誌中。如:create table innodb_monitor(a int)engine=innodb;,不需要記錄到錯誤日誌中時就刪掉這個表即可。

(2)回滾的話,為什麼只有部分 update 語句失敗,而不是整個事務裡的所有 update 都失敗?

這是因為我們們的 innodb 預設是自動提交的:

在多個 update 或 insert 語句情況下,每執行完一條 SQL,innodb 就立即 commit 一次以持久化變更,同時釋放鎖,這也正是本例中死鎖回滾事務後只有極個別語句失敗的原因。

需要注意的是,通常還有另外一種情況也可能導致部分語句回滾,需要格外留意。在 innodb 裡有個引數叫:innodb_rollback_on_timeout

官方手冊裡這樣描述:

In MySQL 5.1, InnoDB rolls back only the last statement on a transaction timeout by default. If –innodb_rollback_on_timeout is specified, a transaction timeout causes InnoDB to abort and roll back the entire transaction (the same behavior as in MySQL 4.1). This variable was added in MySQL 5.1.15.

解釋:這個引數關閉或不存在的話遇到超時只回滾事務最後一個Query,開啟的話事務遇到超時就回滾整個事務。

(3)怎樣降低 innodb 死鎖機率?

死鎖在行鎖及事務場景下很難完全消除,但可以通過表設計和SQL調整等措施減少鎖衝突和死鎖,包括:

  • 儘量使用較低的隔離級別,比如如果發生了間隙鎖,你可以把會話或者事務的事務隔離級別更改為 RC(read committed)級別來避免,但此時需要把 binlog_format 設定成 row 或者 mixed 格式
  • 精心設計索引,並儘量使用索引訪問資料,使加鎖更精確,從而減少鎖衝突的機會;
  • 選擇合理的事務大小,小事務發生鎖衝突的機率也更小;
  • 給記錄集顯示加鎖時,最好一次性請求足夠級別的鎖。比如要修改資料的話,最好直接申請排他鎖,而不是先申請共享鎖,修改時再請求排他鎖,這樣容易產生死鎖;
  • 不同的程式訪問一組表時,應儘量約定以相同的順序訪問各表,對一個表而言,儘可能以固定的順序存取表中的行。這樣可以大大減少死鎖的機會;
  • 儘量用相等條件訪問資料,這樣可以避免間隙鎖對併發插入的影響;
  • 不要申請超過實際需要的鎖級別;除非必須,查詢時不要顯示加鎖;
  • 對於一些特定的事務,可以使用表鎖來提高處理速度或減少死鎖的可能。

2、Case2:詭異的 Lock wait timeout

連續幾天凌晨6點和早上8點 都分別有一個任務失敗,load data local infile 的時候報 Lock wait timeout exceeded try restarting transaction innodb 的 Java SQL 異常,和平臺的同學溝通得知,這是我們自己的業務資料庫的 Lock 時間太短或者鎖衝突的問題。但是回頭一想不應該啊?這不一直好好的嗎?而且基本都是單表單任務,不存在多人衝突。

甭管誰的問題,那我們們還是先看自己的資料庫有沒有問題:

預設 lock 超時時間 50s,這個時間真心不短了,估計調了也沒用,事實上確實死馬當活馬醫的試了下沒用。。。

而且這次 SHOW ENGINE INNODB STATUSG 也沒出現任何死鎖資訊,然後又將目光轉向 MySQL-server 日誌,希望能從日誌裡看一看那個時刻前後資料究竟在做什麼操作。這裡先簡單的介紹下MySQL日誌檔案系統的組成:

(a) error 日誌:記錄啟動、執行或停止 mysqld 時出現的問題,預設開啟。
(b) general 日誌:通用查詢日誌,記錄所有語句和指令,開啟資料庫會有 5% 左右效能損失。
(c) binlog 日誌:二進位制格式,記錄所有更改資料的語句,主要用於 slave 複製和資料恢復。
(d) slow 日誌:記錄所有執行時間超過 long_query_time 秒的查詢或不使用索引的查詢,預設關閉。
(e) Innodb日誌:innodb redo log、undo log,用於恢復資料和撤銷操作。

從上面的介紹可以看到,目前這個問題的日誌可能在 d 和 b 中,看了下 d 中沒有,那就只能開啟 b 了,但 b 對資料庫的效能有一定損耗,由於是全量日誌,量非常巨大,所以開啟一定要謹慎:

我這裡只是每天在出問題的前後半小時開啟下全量日誌,結果沒有發現任何 MySQL-client 請求到我們的業務資料庫!該日誌格式如下,記錄了所有的連線與命令:

那問題基本確定了,客戶端請求都沒到我們這邊就丟擲了上述的異常,和平臺方再三溝通確認下,最後平臺方查證是因為在執行插入前他們需要先從 SQL task 表取出 SQL 和更新 task 狀態,結果這張表由於在整點存在大量 insert 和 update 併發,導致部分 SQL 等待 lock 超時了。。。

3、MySQL 日誌分析指令碼

由於凌晨是資料倉儲的業務高峰,很多問題都是在這個時候爆發,一些詭異的問題往往是過了這個村就沒這個店了,白天無法復現。如何能捕獲我們關心的日誌,便於快速的定位問題,這個是重中之重,這裡我寫了個小指令碼,crontab 部署,可以選擇時間範圍開啟,每分鐘取樣一次日誌,需要說明的是 general log 沒事別輕易開啟,否則對資料庫效能損耗較大。

Refer:

[1] MySQL批量SQL插入效能優化

http://database.51cto.com/art/201309/411050.htm

[2] MySQL 四種事務隔離級的說明

http://www.cnblogs.com/zhoujinyi/p/3437475.html

[3] innodb_rollback_on_timeout引數對鎖的影響

http://q.fireflyclub.org/?/article/37

[4] 日均萬條資料丟失,一個隱式騷操作導致的奇葩事故!

https://mp.weixin.qq.com/s/OpPV24ILewVc2lRDrV4vvA

[5] mysql之show engine innodb status解讀(轉)

http://www.cnblogs.com/ajianbeyourself/p/6941905.html

http://www.cnblogs.com/olinux/p/5497176.html

[6] Mysql 鎖機制筆記

http://www.jianshu.com/p/fa28035656a9

http://www.jianshu.com/p/ec4a343c49f0

http://hudeyong926.iteye.com/blog/1490687

[7] MySQL索引原理及慢查詢優化

https://tech.meituan.com/mysql-index.html

[8] [譯文]MySQL發生死鎖腫麼辦?

http://www.10tiao.com/html/672/201612/2653929751/1.html

[9] MySQL的timeout那點事

http://www.penglixun.com/tech/database/mysql_timeout.html

[10] mysql死鎖(deadlock)分析及解決 (索引 間隙鎖 sql順序)

http://www.youyong.top/article/1158d0e3bcf

相關文章