第148回　InnoDBの行ロック状態を確認する［その2］

前に筆者が担当した第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のテーブルから確認することができるので、調べやすくなりました。

もし、ロックの競合を懸念される際はこれらのテーブルを使って確認してみると良いでしょう。