排查 MySQL innodb Lock wait timeout exceeded; try restarting transaction的問題

OMG寫的時候崩潰了一次。

觸發關注這個問題的事情是 我們在使用pt-online-schedule 改表的時候總是拿不到鎖，並且報出mysql innodb Lock wait timeout exceeded; try restarting transaction的問題，所以才想到要排查。

首先最先想到的肯定是

show processlist;

來查看當前正在運行的查詢 或者等待休眠中的查詢是哪些，包括使用了多少時間等，類似

*************************** 582. row ***************************
           Id: 7485594
         User: xcf
         Host: cc:59580
           db: xx
      Command: Query
         Time: 0
        State: init
         Info: show processlist
    Rows_sent: 0
Rows_examined: 0
*************************** 583. row ***************************
           Id: 7485595
         User: xcf
         Host: cc-19:42614
           db: xx
      Command: Sleep
         Time: 0
        State:
         Info: NULL
    Rows_sent: 0
Rows_examined: 0

但是可以看到,當有很多任務在執行的時候，processlist將會非常大，想要從這里面獲取對我們有用的信息非常非常困難，最多也就簡單的看下，哪個query耗時的確過長，會不會是因為事務沒有提交導致的拿不到鎖，來推測並且使用kill task_id來殺掉相應的task。

 

其次我們如果有權限，可以使用能看到相對來說更為復雜和詳細的信息

SHOW ENGINE INNODB STATUS\G;

 通過innodb status 提供的詳細的系統情況來分析問題。 

 

如果我沒沒有使用show engine innodb status的權限，退而求其次我們可以使用另外一種思路來找到是哪個表持續被鎖，導致拿不到鎖的問題。

show open tables where in_use>0;

查看現在系統正在使用的表，然后使用

show processlist;

查找正在query該表的任務，查看代碼是否有一直沒有提交事物，卻沒有commit的代碼，用這個思路來找問題出現在哪兒。

 

另外在mysql5.5之后，information_schema數據庫加了三個關於鎖的表。

innodb_trx ## 當前運行的所有事務
innodb_locks ## 當前出現的鎖
innodb_lock_waits ## 鎖等待的對應關系

備忘一下他們的表結構

mysql> desc information_schema.innodb_trx;
+----------------------------+---------------------+------+-----+---------------------+-------+
| Field                      | Type                | Null | Key | Default             |Extra |
+----------------------------+---------------------+------+-----+---------------------+-------+
| trx_id                     | varchar(18)         | NO   |     |                     |      |　　# 事務id
| trx_state                  | varchar(13)         | NO   |     |                     |      |　　# 事務狀態
| trx_started                | datetime            | NO   |     | 0000-00-00 00:00:00 |      |　　# 事務開始的時間
| trx_requested_lock_id      | varchar(81)         | YES  |     | NULL                |      |　　# 事務請求到鎖的id
| trx_wait_started           | datetime            | YES  |     | NULL                |      |　　# 事務開始等待的時間
| trx_weight                 | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務權重
| trx_mysql_thread_id        | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務線程的id
| trx_query                  | varchar(1024)       | YES  |     | NULL                |      |　　# 事務sql語句
| trx_operation_state        | varchar(64)         | YES  |     | NULL                |      |　　# 事務當前的操作狀態
| trx_tables_in_use          | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務中有多少個表正在被使用
| trx_tables_locked          | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務擁有多少個鎖
| trx_lock_structs           | bigint(21) unsigned | NO   |     | 0                   |      |　　
| trx_lock_memory_bytes      | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務鎖住的內存大小
| trx_rows_locked            | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務鎖住的行數
| trx_rows_modified          | bigint(21) unsigned | NO   |     | 0                   |      |　　# 事務改變的行數
| trx_concurrency_tickets    | bigint(21) unsigned | NO   |     | 0                   |      |　　 
| trx_isolation_level        | varchar(16)         | NO   |     |                     |      |　　# 事務隔離等級
| trx_unique_checks          | int(1)              | NO   |     | 0                   |      |　　# 唯一鍵檢測
| trx_foreign_key_checks     | int(1)              | NO   |     | 0                   |      |　　# 外鍵檢測
| trx_last_foreign_key_error | varchar(256)        | YES  |     | NULL                |      |
| trx_adaptive_hash_latched  | int(1)              | NO   |     | 0                   |      |
| trx_adaptive_hash_timeout  | bigint(21) unsigned | NO   |     | 0                   |      |
| trx_is_read_only           | int(1)              | NO   |     | 0                   |      |　　# 是否是只讀事務
| trx_autocommit_non_locking | int(1)              | NO   |     | 0                   |      |
+----------------------------+---------------------+------+-----+---------------------+-------+

這個表對於排查因為事務未提交引起的鎖問題可以說是舉足輕重。當我們有事務長時間未提交導致鎖住數據庫，其他程序拿不到鎖的時候，因為對這張表進行排查。

比如我們獲取一條記錄的線程id， 即可拿着該線程id去information_schma.processlist中獲取他的具體情況。

mysql> select * from information_schema.processlist where id=701520;
+--------+------+----------------+-----------+---------+------+-------+------+---------+-----------+---------------+
| ID     | USER | HOST           | DB        | COMMAND | TIME | STATE | INFO | TIME_MS | ROWS_SENT | ROWS_EXAMINED |
+--------+------+----------------+-----------+---------+------+-------+------+---------+-----------+---------------+
| 701520 | ppp  | hazelnut:50308 | xxxxxxxxx | Sleep   | 5492 |       | NULL | 5492065 |         0 |             0 |
+--------+------+----------------+-----------+---------+------+-------+------+---------+-----------+---------------+

然后找到在占用服務器50308端口的程序

netstat -nlatp |grep 50308

piperck@grape:~$ netstat -nlatp | grep 46698
(No info could be read for "-p": geteuid()=1025 but you should be root.)
tcp        0      0 192.168.2.79:46698      192.168.2.83:3306       ESTABLISHED -

可以看到協議 本機端口 去往mysql 也就是我們起初的數據庫， 這里 established后面 本正常會顯示占用程序的pid -p參數可以將其顯示出來。

 

接下來看下記錄鎖信息的表 innodb_locks

mysql> desc information_schema.innodb_locks;
+-------------+---------------------+------+-----+---------+-------+
| Field       | Type                | Null | Key | Default | Extra |
+-------------+---------------------+------+-----+---------+-------+
| lock_id     | varchar(81)         | NO   |     |         |       |　　# 鎖id
| lock_trx_id | varchar(18)         | NO   |     |         |       |　　# 擁有鎖的事務id　　　
| lock_mode   | varchar(32)         | NO   |     |         |       |　　# 鎖模式
| lock_type   | varchar(32)         | NO   |     |         |       |　　# 鎖類型
| lock_table  | varchar(1024)       | NO   |     |         |       |　　# 被鎖的表
| lock_index  | varchar(1024)       | YES  |     | NULL    |       |　　# 被鎖的索引
| lock_space  | bigint(21) unsigned | YES  |     | NULL    |       |　　# 被鎖的表空間號
| lock_page   | bigint(21) unsigned | YES  |     | NULL    |       |　　# 被鎖的頁號
| lock_rec    | bigint(21) unsigned | YES  |     | NULL    |       |　　# 被鎖的記錄號
| lock_data   | varchar(8192)       | YES  |     | NULL    |       |　　# 被鎖的數據
+-------------+---------------------+------+-----+---------+-------+

如果 我們要排查的問題正鎖死我們的某張表，那么該表的數據表就會有所體現。同時和這個表使用的 還有information_schema.innodb_lock_waits

+-------------------+-------------+------+-----+---------+-------+
| Field             | Type        | Null | Key | Default | Extra |
+-------------------+-------------+------+-----+---------+-------+
| requesting_trx_id | varchar(18) | NO   |     |         |       |　　# 請求鎖的事務id
| requested_lock_id | varchar(81) | NO   |     |         |       |　　# 請求鎖的鎖id
| blocking_trx_id   | varchar(18) | NO   |     |         |       |　　# 擁有鎖的事務id
| blocking_lock_id  | varchar(81) | NO   |     |         |       |　　# 擁有鎖的鎖id
+-------------------+-------------+------+-----+---------+-------+

結合以上兩個表再查對應的信息  可以說已經很方便了。那天出問題，我回家的時候就已經被解決了。我並沒有在線上環境嘗試過，但是模擬了幾次，使用這些辦法提供的線索都能解決問題，等我有機會解決線上問題的時候，再補一個詳細例子。

 

 

Reference:

http://stackoverflow.com/questions/5836623/getting-lock-wait-timeout-exceeded-try-restarting-transaction-even-though-im  getting-lock-wait-timeout-exceeded-try-restarting-transaction-even-though-im 

http://blog.csdn.net/hw_libo/article/details/39080809  MySQL鎖阻塞分析

http://blog.sina.com.cn/s/blog_6bb63c9e0100s7cb.html  MySQL innodb_lock_wait 鎖等待

http://dev.mysql.com/doc/refman/5.6/en/innodb-information-schema-understanding-innodb-locking.html  mysql5.6官方文檔

https://stackoverflow.com/questions/37306568/how-to-solve-mysql-innodb-waiting-for-table-metadata-lock-on-truncate-table?rq=1    metadata_lock 鎖的問題