61
MySQL · 特性分析 · 到底是誰執行了FTWL
什麼是FTWL
FTWRL是FLUSH TABLES WITH READ LOCK的簡稱(FTWRL)，該命令主要用於保證備份一致性備份。為了達到這個目的，它需要關閉所有表對象，因此這個命令的殺傷性很大，執行命令時容易導致庫hang住。如果它在主庫執行，則業務無法正常訪問；如果在備庫，則會導致SQL線程卡住，主備延遲。 FTWRL通過持有以下兩把全局的MDL(MetaDataLock)鎖：
- 全局讀鎖(lock_global_read_lock) 會導致所有的更新操作被堵塞
- 全局COMMIT鎖(make_global_read_lock_block_commit) 會導致所有的活躍事務無法提交
FLUSH TABLES WITH READ LOCK執行後整個係統會一直處於隻讀狀態，直到顯示執行UNLOCK TABLES。這點請切記。
如何高效定位FTWL的執行會話
由於FTWL持有的是MDL鎖，所以一旦它執行完成，你將無法以定位DML鎖的方式來定位它。即在show processlist的結果和information_schema相關的表中找不到任何相關的線索。我們來看下麵的一個例子：
[test]> flush tables with read lock;
Query OK, 0 rows affected (0.06 sec)
[test]> show full processlist\G
*************************** 1. row ***************************
Id: 10
User: root
Host: localhost
db: test
Command: Query
Time: 0
State: init
Info: show full processlist
Progress: 0.000
*************************** 2. row ***************************
Id: 11
User: root
Host: localhost
db: test
Command: Query
Time: 743
State: Waiting for global read lock
Info: delete from t0
Progress: 0.000
2 rows in set (0.00 sec)
[test]> select * from information_schema.processlist\G
*************************** 1. row ***************************
ID: 11
USER: root
HOST: localhost
DB: test
COMMAND: Query
TIME: 954
STATE: Waiting for global read lock
INFO: delete from t0
TIME_MS: 954627.587
STAGE: 0
MAX_STAGE: 0
PROGRESS: 0.000
MEMORY_USED: 67464
EXAMINED_ROWS: 0
QUERY_ID: 1457
INFO_BINARY: delete from t0
TID: 8838
*************************** 2. row ***************************
ID: 10
USER: root
HOST: localhost
DB: test
COMMAND: Query
TIME: 0
STATE: Filling schema table
INFO: select * from information_schema.processlist
TIME_MS: 0.805
STAGE: 0
MAX_STAGE: 0
PROGRESS: 0.000
MEMORY_USED: 84576
EXAMINED_ROWS: 0
QUERY_ID: 1461
INFO_BINARY: select * from information_schema.processlist
TID: 8424
2 rows in set (0.02 sec)
從上的輸出中，我們隻發現了會話11 在等候一個全局讀鎖。但這個鎖被誰持有，從這個輸出裏麵我們找不到任何線索。我現在再來看看INNODB STATUS輸出：
...
------------
TRANSACTIONS
------------
Trx id counter 20439
Purge done for trx's n:o < 20422 undo n:o < 0 state: running but idle
History list length 176
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 11, OS thread handle 0x7f7f5cdb8b00, query id 1457 localhost root Waiting for global read lock
delete from t0
---TRANSACTION 0, not started
MySQL thread id 10, OS thread handle 0x7f7f5ce02b00, query id 1462 localhost root init
show engine innodb status
--------
...
我們從引擎層也沒有找到相關的線索。這個毫無疑問，在本文開始的時候就已經指出了FTWL持有的事MDL鎖。
當然因為這個例子中隻有兩個會話，你一眼就可以看出來誰持有了全局讀鎖。如果是線上的環境，將會有成百上千個會話。那又怎麼辦呢？請繼續往下看。那我們如何快速定位FTWL的鎖呢？主要有下麵三種方法：
-
如果你用的Mysql 5.7，那麼你可以使用performance_schema.metadata_locks
-
如果你用的Mysql 5.6，那麼你可以使用performance_schema.events_statements_history
-
如果你用的Mysql版本比較老，那麼可以使用genearal log或者一些sql審計的日誌來定位
以上三種方法都是要開啟的，默認情況這些方法是沒有開啟的。所以在工作中，我們會經常遇到這種情況。
整個庫都被堵住了。數據庫裏出現了大量的Waiting for global read lock等待。但上麵提到的三種方法又不適用於我們。所以接下來我會為大家用展示一種利用gdb去快速定位執行FTWL的會話。我們來看下麵的例子：
會話1：
flush tables with read lock;
Query OK, 0 rows affected (0.00 sec)
會話2：
mysql> delete from t; --被hang住
會話3：
mysql> show processlist;
+----+------+-----------+------+---------+------+------------------------------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+------------------------------+------------------+
| 7 | root | localhost | test | Query | 227 | Waiting for global read lock | delete from t |
| 8 | root | localhost | NULL | Sleep | 215 | | NULL |
| 9 | root | localhost | NULL | Query | 0 | init | show processlist |
+----+------+-----------+------+---------+------+------------------------------+------------------+
由於會話1執行了FTWL,導致了會話2中的DML無法執行。接下來，我們演示如何通過gdb去定位執行了FTWL的會話。見下麵的步驟
-
找出myql的進程id， ps -ef grep mysql
root 7743 2366 0 05:07 ? 00:00:01 /u02/mysql/bin/mysqld
2.利用gdb來跟蹤mysql進程 執行 gdb -p 7743
3.在mysql把已經連接的會話保存在一個叫global_thread_list的全局變量中在這個變量中的thread有一個叫global_read_lock的變量來表示持有鎖的情況。所以我們隻有在gdb中找global_read_lock不為空的thread即可。所以我們在gdb中執行下麵的語句
(gdb) pset global_thread_list THD*
elem[0]: $1 = (THD *) 0x4a55de0
elem[1]: $2 = (THD *) 0x4a5cf10
elem[2]: $3 = (THD *) 0x4b24aa0
Set size = 3
上麵的命令輸出了三個會話的內存地址。接下來我們根據這些內存地址去查找每個會話各自對應的global_read_lock
4.依次在dgb中打印上麵三個會話中的global_read_lock和thread_id的值
(gdb) p ((THD *) 0x4a55de0)->global_read_lock
$4 = {
static m_active_requests = 1,
m_state = Global_read_lock::GRL_NONE,
m_mdl_global_shared_lock = 0x0,
m_mdl_blocks_commits_lock = 0x0
} //這個會話的Global_read_lock為空，不是我們要找的
(gdb) p ((THD *) 0x4a5cf10)->global_read_lock
$5 = {
static m_active_requests = 1,
m_state = Global_read_lock::GRL_NONE,
m_mdl_global_shared_lock = 0x0,
m_mdl_blocks_commits_lock = 0x0
} //這個會話的Global_read_lock也為空，不是我們要找的
(gdb) p ((THD *) 0x4b24aa0)->global_read_lock
$6 = {
static m_active_requests = 1,
m_state = Global_read_lock::GRL_ACQUIRED_AND_BLOCKS_COMMIT,
m_mdl_global_shared_lock = 0x7f6034002bb0,
m_mdl_blocks_commits_lock = 0x7f6034002c20
}
//這個會話的Global_read_lock不為空，GRL_ACQUIRED_AND_BLOCKS_COMMIT表示全局讀鎖與commit鎖，這個就是我們要好的。我接下來打印出它的thread_id
p ((THD *) 0x4b24aa0)->thread_id
$7 = 8 //8號會話執行了FTWL
5.我們可以通過執行kill 8結束這個會話來釋放全局的鎖。讓被堵住的會話，繼續運行下去。
在新開的mysql會話中，執行下麵的語句
mysql> kill 8
以前被堵在的會話中，會看到下麵的結果
mysql> delete from t;
Query OK, 0 rows affected (40 min 20.73 sec)
小結
由於FTWL持有的是MetaDataLock類型的鎖，所以給我們定位問題的源頭帶來很大的困難。很多同學在解決類似的問題的時候，會把運行時間最長的幾個會話殺掉。這種方法並不可取。因為造成擁堵的源頭並沒有找到。所以我給大家提供了一個利用調試工具抓取mysql內部狀態變量的方法來定位這類問題的源頭。希望大家喜歡。
最後更新：2017-08-21 09:02:52