前に筆者が担当した第145回に続いて、InnoDBの行ロック状態を確認する方法について紹介します。先に第145回 InnoDBの行ロック状態を確認する[その1] をご確認ください。
今回も引き続きMySQL 8.0.23を使用しています。
data_lock_waits
テーブル
MySQL 8.0から追加されたperformance_schemaのテーブルであるdata_lock_waits
テーブルは、行ロックを待機している状態を確認できます。これにより、スレッド間の行ロックの依存関係を把握することができます。data_locksテーブルのどのデータロックリクエストが、data_locksテーブルのどのデータロックによってブロックされているかを示す多対多関係が実装されています。
ロック待ちが発生していると、以下のような出力を確認できます。
mysql> SELECT * FROM performance_schema.data_lock_waits\G
*************************** 1. row ***************************
ENGINE: INNODB
REQUESTING_ENGINE_LOCK_ID: 140492041772440:5:4:2:140491937095392
REQUESTING_ENGINE_TRANSACTION_ID: 3093
REQUESTING_THREAD_ID: 47
REQUESTING_EVENT_ID: 119
REQUESTING_OBJECT_INSTANCE_BEGIN: 140491937095392
BLOCKING_ENGINE_LOCK_ID: 140492041773296:5:4:2:140491937101616
BLOCKING_ENGINE_TRANSACTION_ID: 3092
BLOCKING_THREAD_ID: 48
BLOCKING_EVENT_ID: 25
BLOCKING_OBJECT_INSTANCE_BEGIN: 140491937101616
1 row in set (0.01 sec)
なお、このテーブルを使って行ロックの関係を把握するよりも、人間が理解しやすい形で表示してくれる後述のsysスキーマのview innodb_lock_waits
を見るのが良いので、詳しい説明は省きます。
data_lock_waits
テーブルにつきましては、マニュアルの27.12.13.2 data_lock_waitsテーブル をご確認ください。
sys.innodb_lock_waitsビュー
このviewはdata_locks
テーブルとdata_lock_waits
テーブルなどをJOINして、トランザクションが待機しているInnoDBロックの状態を表示します。
以下のようなSQLを実行して、Session2をロック待ちにさせます。
Session1
Session2
BEGIN;
UPDATE t0 SET col1=9 WHERE id=1;
BEGIN;
UPDATE t0 SET col1=10000 WHERE id=1;(Waiting)
その状態で、sys.innodb_lock_waitsからSELECTした結果が以下になります。
mysql> SELECT * FROM sys.innodb_lock_waits\G
*************************** 1. row ***************************
wait_started: 2021-05-30 01:37:22
wait_age: 00:00:03
wait_age_secs: 3
locked_table: `i`.`t0`
locked_table_schema: i
locked_table_name: t0
locked_table_partition: NULL
locked_table_subpartition: NULL
locked_index: PRIMARY
locked_type: RECORD
waiting_trx_id: 3094
waiting_trx_started: 2021-05-30 01:37:22
waiting_trx_age: 00:00:03
waiting_trx_rows_locked: 1
waiting_trx_rows_modified: 0
waiting_pid: 8
waiting_query: update i.t0 set col1=10000 where id=1
waiting_lock_id: 140492041772440:5:4:2:140491937095392
waiting_lock_mode: X,REC_NOT_GAP
blocking_trx_id: 3092
blocking_pid: 9
blocking_query: NULL
blocking_lock_id: 140492041773296:5:4:2:140491937101616
blocking_lock_mode: X,REC_NOT_GAP
blocking_trx_started: 2021-05-30 01:34:01
blocking_trx_age: 00:03:24
blocking_trx_rows_locked: 1
blocking_trx_rows_modified: 1
sql_kill_blocking_query: KILL QUERY 9
sql_kill_blocking_connection: KILL 9
このうち項目のいくつかを抜粋して紹介します。
wait_age_secs
ロックが待機された時間(秒)
locked_table
ロックされたスキーマを含むテーブル
locked_index
ロックされたインデックスの名前
locked_type
待機中のロックのタイプ
waiting_query
ロックを待機しているステートメント
waiting_lock_mode
待機ロックのモード
waiting_trx_rows_locked
待機中のトランザクションによってロックされた行数
waiting_trx_rows_modified
待機中のトランザクションによって変更された行数
blocking_pid
ロックを保持しているprocess_id
blocking_query
ブロックしているトランザクションが実行しているステートメント
しかし、これはそのステートメントが実行中であればブロックしているステートメントが表示されますが、すでに流れてしまった(実行が完了しているがcommitされていない)状態ではNULLであったり、sys.innodb_lock_waitsからSELECTしたタイミングで実行されているステートメントが表示されるのでご注意ください。
sql_kill_blocking_connection
ロックを保持しているprocess_idを強制終了するために実行する KILLステートメント
どのセッションが原因でロック待機が発生しているのか、そのprocess_idやそれを強制終了するためのSQLなど表示してくれます。
ロックの原因となっているSQLを確認する
前述のblocking_query
はすでにそのSQLが流れてしまうと確認できないと説明しました。ここではちょっとした工夫によりblocking_queryを表示させるためのTipsを紹介したいと思います。
準備として、events_statements_history_longを有効にします。以下のSQLを実行します。デフォルトはNO(OFF)になっています。
mysql> UPDATE performance_schema.setup_consumers SET ENABLED='YES' WHERE NAME='events_statements_history_long';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
このevents_statements_history_longを有効にすると、スレッドごとにN 個の最新のステートメントイベントを保持してくれるようになります。
N 個と表したのはデフォルトでは-1(auto_resize)となっていて、以下パラメータをもとにサイズを決定します。
max_connections
table_definition_cache
table_open_cache
これにより100、1000または10000の中から選択されます。
以下、variablesから現在の値が確認できます。
mysql> show variables like '%performance_schema_events_statements_history_long_size%';
+--------------------------------------------------------+-------+
| Variable_name | Value |
+--------------------------------------------------------+-------+
| performance_schema_events_statements_history_long_size | 10000 |
+--------------------------------------------------------+-------+
注意として、events_statements_history_longを有効にすると、保持するステートメント数が増えてメモリーを多く使います。
そして、この少し長いSQLを実施するとevents_statements_history_longを使用して、blocking_query
を表示できるようになります。
SELECT
t.PROCESSLIST_ID,concat('KILL ',t.PROCESSLIST_ID,';') Kill_Query,
CASE WHEN esh.SQL_TEXT IS NOT NULL THEN esh.SQL_TEXT WHEN esc.SQL_TEXT IS NOT NULL THEN esc.SQL_TEXT ELSE eshl.SQL_TEXT END as BLOCKING_SQLTEXT
FROM
(SELECT block.BLOCKING_THREAD_ID,block.BLOCKING_EVENT_ID
FROM performance_schema.data_lock_waits block
LEFT JOIN performance_schema.data_lock_waits req
ON block.BLOCKING_THREAD_ID=req.REQUESTING_THREAD_ID AND block.BLOCKING_EVENT_ID=req.REQUESTING_EVENT_ID
WHERE req.REQUESTING_THREAD_ID IS NULL AND req.REQUESTING_EVENT_ID IS NULL
GROUP BY 1,2
) wait
JOIN performance_schema.threads t ON wait.BLOCKING_THREAD_ID=t.THREAD_ID
LEFT JOIN performance_schema.events_statements_history esh ON wait.BLOCKING_THREAD_ID=esh.THREAD_ID AND (wait.BLOCKING_EVENT_ID - 1)=esh.EVENT_ID
LEFT JOIN performance_schema.events_statements_current esc ON wait.BLOCKING_THREAD_ID=esc.THREAD_ID AND (wait.BLOCKING_EVENT_ID - 1)=esc.EVENT_ID
LEFT JOIN performance_schema.events_statements_history_long eshl ON wait.BLOCKING_THREAD_ID=eshl.THREAD_ID AND (wait.BLOCKING_EVENT_ID - 1)=eshl.EVENT_ID;
先ほど実行した例を用いて、Session2が待機している状態で実行した結果は、次の通りとなります。
+----------------+------------+---------------------------------+
| PROCESSLIST_ID | Kill_Query | BLOCKING_SQLTEXT |
+----------------+------------+---------------------------------+
| 9 | KILL 9; | UPDATE t0 SET col1=9 WHERE id=1 |
+----------------+------------+---------------------------------+
このように、Session1で実行したblocking_query
が表示されるので、ロックの原因を追いやすくなります。
こちらのSQLの例では、ブロックしているPROCESSLIST_IDとそれをKillするステートメント、そしてブロックしているステートメントを表示しています。このSQLを編集して、出力する項目を変更することもできます。
まとめ
第145回と今回で、InnoDBの行ロック状態を確認する方法を紹介しました。MySQL 8.0からは、ロックの競合やロックの状態をperformance_schemaのテーブルから確認することができるので、調べやすくなりました。
もし、ロックの競合を懸念される際はこれらのテーブルを使って確認してみると良いでしょう。