MySQL 8 系で便利なロックを確認する data_locks テーブルの使い方を紹介します

こんにちは。
開発チームのワイルド担当、まんだいです。

今回は MySQL 8 系で便利なロック状態を確認する方法を紹介します。

デッドロックの確認をする時、SHOW ENGINE INNODB STATUS\G を確認するのは調べるとすぐに出てくると思いますが、デッドロックではなく、単にロック時間が長く後続のクエリが流れないといった場合は、デッドロックではないので、SHOW ENGINE INNODB STATUS\G では確認できません。

そんな時に便利なのが、 MySQL 8 系で performance_schema に追加された data_locks テーブルと data_lock_waits テーブルです。

data_locks テーブルってなんだ？

data_locks テーブルは、InnoDB のロック情報を保持しているテーブルです。

適当なテーブルを作って、実際にロックを掛けてどうなるか見てみます。

-- データベース作成
CREATE DATABASE test;

-- テーブル作成
CREATE TABLE users (
    id BIGINT UNSIGNED NOT NULL AUTO_INCREMENT,
    username VARCHAR(255) NOT NULL,
    email VARCHAR(255) NOT NULL,
    PRIMARY KEY (`id`),
    KEY `idx_username` (`username`),
    UNIQUE KEY `unique_email` (`email`)
);

この時点で、一度 data.locks テーブルを見てみます。

SELECT * FROM performance_schema.data_locks;
Empty set (0.001 sec)

はい、何もでてきません。

続いてこのテーブルにデータを1件追加します。

INSERT INTO users (username, email) VALUES ('test', '[email protected]');

続いて、トランザクションを開始して、SELECT ... FOR UPDATE でロックを掛けます。

-- トランザクション開始
BEGIN;

-- ロックを掛ける
SELECT * FROM users WHERE username = 'test' FOR UPDATE;

コミットしない状態で data_locks テーブルを見てみましょう。

SELECT * FROM performance_schema.data_locks;
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
| ENGINE | ENGINE_LOCK_ID                           | ENGINE_TRANSACTION_ID | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | PARTITION_NAME | SUBPARTITION_NAME | INDEX_NAME   | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE     | LOCK_STATUS | LOCK_DATA              |
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
| INNODB | 139629897444568:4067:139629789500112     |                432725 |        56 |      170 | test          | users       | NULL           | NULL              | NULL         |       139629789500112 | TABLE     | IX            | GRANTED     | NULL                   |
| INNODB | 139629897444568:2805:6:1:139629789497120 |                432725 |        56 |      170 | test          | users       | NULL           | NULL              | idx_username |       139629789497120 | RECORD    | X             | GRANTED     | supremum pseudo-record |
| INNODB | 139629897444568:2805:6:2:139629789497120 |                432725 |        56 |      170 | test          | users       | NULL           | NULL              | idx_username |       139629789497120 | RECORD    | X             | GRANTED     | 'test', 1              |
| INNODB | 139629897444568:2805:4:2:139629789497464 |                432725 |        56 |      170 | test          | users       | NULL           | NULL              | PRIMARY      |       139629789497464 | RECORD    | X,REC_NOT_GAP | GRANTED     | 1                      |
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
4 rows in set (0.001 sec)

先ほどは空でしたが、4件データが出てきました。
このように data_locks テーブルは現在テーブルにロックを掛けているトランザクションを可視化するためのテーブルになります。

幾つか重要な情報もあるので、カラムを見ていきましょう。

ENGINE_TRANSACTION_ID

トランザクション ID です。
この値は、SHOW ENGINE INNODB STATUS\G で確認できる Trx id になります。

information_schema テーブルの innodb_trx テーブルにトランザクションに関する詳細な情報が記載されていますので、 trx_id で検索すると詳細な情報が得られます。

OBJECT_SCHEMA

テーブルが格納されているスキーマ名です。
ロックが頻繁に発生する環境や、複数のスキーマを持つ環境の場合、ここも合わせて確認が必要になります。

OBJECT_NAME

テーブル名です。
私が遭遇したことのあるケースだと、 data_locks テーブルに 150 件以上のデータがあって、テーブルもまちまちだったため、このカラムで絞り込みを行ったりしました。

INDEX_NAME

ロックされたインデックスの名前です。
PRIMARY が出てきた場合は、プライマリキーにロックが掛かっている状態で、特定のインデックスにロックが掛かっている場合は、そのインデックス名が出てきます。

NULL の場合は、テーブルロックが掛かっている状態です。

LOCK_TYPE

ロックの種類です。
TABLE か RECORD の二種類があり、 TABLE はテーブル全体にロックが掛かっている状態、 RECORD はレコードにロックが掛かっている状態です。

LOCK_MODE

ロックのモードです。
今回の例で出てきている IX、X、REC_NOT_GAP の3つです。
IX は インテンション排他ロックと呼ばれるロックでテーブルロックが掛かっている場合はこのロックモードでロックが掛かります。
X は 排他ロックで、単体で表示されている場合はネクストキーロックになっています。
REC_NOT_GAP は レコードロックで、ギャップロックではないことを示しています。

他にもロックの種類やモードがありますので、詳しくは 公式ドキュメント を参照してください。

LOCK_STATUS

ロックの状態です。
ロックが取れている場合は GRANTED 、ロックが取れていない、つまり他クエリのロックが終わるのを待っている場合は WAITING が出力されます。

LOCK_DATA

ロックに関連するデータが表示されます。
INNODB の場合は LOCK_TYPE が RECORD の場合のみ表示され TABLE の場合は NULL が出力されます。

複合インデックスの場合は、カンマ区切りで複数の値が表示されます。

また supremum pseudo-record と表示された場合は、インデックスの最小上限値の疑似レコードを示しています。
疑似レコードなので実際にレコードは存在しないんですが、仕組み上ロックの終端が必要になるため、擬似的に用意されたレコードになります。

data_lock_waits テーブルってなんだ？

users テーブルにロックを掛けたまま、もう一つのセッションで同じレコードにロックを掛けようとすると、ロック待ちが発生します。
このロック待ちをしているクエリを確認するためのテーブルが data_lock_waits テーブルです。

以下のように再現してみます。
ターミナルが 2 枚必要になるので、別々のターミナルで MySQL に接続してください。

まず、ターミナル 1 から、先程の SELECT ... FOR UPDATE を実行します。

-- ターミナル 1 で実行
-- トランザクション開始
BEGIN;

-- ロックを掛ける
SELECT * FROM users WHERE username = 'test' FOR UPDATE;

-- MySQL をターミナル 2 で接続して以下のクエリを実行
-- トランザクション開始
BEGIN;

-- ロックを掛ける
SELECT * FROM users WHERE username = 'test' FOR UPDATE;

このクエリを実行すると、ターミナル2の画面が固まったように見えます。
裏では、ロック待ちが発生していて、結果が返せてない状態になります。

まずは data_locks テーブルを確認してみます。

SELECT * FROM performance_schema.data_locks;
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
| ENGINE | ENGINE_LOCK_ID                           | ENGINE_TRANSACTION_ID | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | PARTITION_NAME | SUBPARTITION_NAME | INDEX_NAME   | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE     | LOCK_STATUS | LOCK_DATA              |
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
| INNODB | 139629897446184:4067:139629789512192     |                432729 |        60 |       89 | test          | users       | NULL           | NULL              | NULL         |       139629789512192 | TABLE     | IX            | GRANTED     | NULL                   |
| INNODB | 139629897446184:2805:6:2:139629789509280 |                432729 |        60 |       89 | test          | users       | NULL           | NULL              | idx_username |       139629789509280 | RECORD    | X             | WAITING     | 'test', 1              |
| INNODB | 139629897444568:4067:139629789500112     |                432727 |        56 |      262 | test          | users       | NULL           | NULL              | NULL         |       139629789500112 | TABLE     | IX            | GRANTED     | NULL                   |
| INNODB | 139629897444568:2805:6:1:139629789497120 |                432727 |        56 |      262 | test          | users       | NULL           | NULL              | idx_username |       139629789497120 | RECORD    | X             | GRANTED     | supremum pseudo-record |
| INNODB | 139629897444568:2805:6:2:139629789497120 |                432727 |        56 |      262 | test          | users       | NULL           | NULL              | idx_username |       139629789497120 | RECORD    | X             | GRANTED     | 'test', 1              |
| INNODB | 139629897444568:2805:4:2:139629789497464 |                432727 |        56 |      262 | test          | users       | NULL           | NULL              | PRIMARY      |       139629789497464 | RECORD    | X,REC_NOT_GAP | GRANTED     | 1                      |
+--------+------------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+--------------+-----------------------+-----------+---------------+-------------+------------------------+
6 rows in set (0.001 sec)

先ほどまでは 4 件だけだったロックが、6 件に増えています。
増えた 2 件を見てみると、 1 件の LOCK_STATUS が WAITING になっていることがわかります。

この状態がロック待ちの状態です。

続いて data_lock_waits テーブルを確認してみます。

SELECT * FROM performance_schema.data_lock_waits;
+--------+------------------------------------------+----------------------------------+----------------------+---------------------+----------------------------------+------------------------------------------+--------------------------------+--------------------+-------------------+--------------------------------+
| ENGINE | REQUESTING_ENGINE_LOCK_ID                | REQUESTING_ENGINE_TRANSACTION_ID | REQUESTING_THREAD_ID | REQUESTING_EVENT_ID | REQUESTING_OBJECT_INSTANCE_BEGIN | BLOCKING_ENGINE_LOCK_ID                  | BLOCKING_ENGINE_TRANSACTION_ID | BLOCKING_THREAD_ID | BLOCKING_EVENT_ID | BLOCKING_OBJECT_INSTANCE_BEGIN |
+--------+------------------------------------------+----------------------------------+----------------------+---------------------+----------------------------------+------------------------------------------+--------------------------------+--------------------+-------------------+--------------------------------+
| INNODB | 139629897446184:2805:6:2:139629789509280 |                           432729 |                   60 |                  89 |                  139629789509280 | 139629897444568:2805:6:2:139629789497120 |                         432727 |                 56 |               262 |                139629789497120 |
+--------+------------------------------------------+----------------------------------+----------------------+---------------------+----------------------------------+------------------------------------------+--------------------------------+--------------------+-------------------+--------------------------------+
1 row in set (0.001 sec)

こちらも 1 件だけデータが出てきました。

REQUESTING_ENGINE_TRANSACTION_ID の値を data_locks テーブルの ENGINE_TRANSACTION_ID と照らし合わせると、 LOCK_STATUS が WAITING になっているクエリでロック待ちが発生していることがわかります。

また、BLOCKING_ENGINE_TRANSACTION_ID と BLOCKING_ENGINE_LOCK_ID から、どのロックがロック待ちを発生させているかもわかります。

これらの情報から、停止させるクエリを特定していくわけですが、スキーマとテーブル名だけで追いかけていくのも難しいのも事実です。
そこで事前に設定が必要ですが、実際に流れているクエリを確認する方法があります。

もちろんがんばればバイナリログでも追えるのですが、よっぽど流れるクエリが少ない場合でないとクエリだけで追いかけるのは難しいんじゃないかと思いますので、次項で説明する events_statements_history_long テーブルを使った調査が有効になります。

events_statements_history_long テーブルを有効にする

デフォルトの状態だと events_statements_history_long テーブルへの書き込みは無効になっているため、有効にする必要があります。
有効化はオンラインで可能で、以下の SQL を実行するだけです。

UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME = 'events_statements_history_long';

一旦これで、以降のクエリは events_statements_history_long テーブルに記録されるようになりましたが、恒久的に設定を維持する場合は、 my.cnf にも以下の設定を追加します。

[mysqld]
performance-schema-consumer-events-statements-history-long=ON

保存される件数は、スレッドごとに以下のクエリの値の件数分保存されます。

show variables like 'performance_schema_events_statements_history_long_size';
+--------------------------------------------------------+-------+
| Variable_name                                          | Value |
+--------------------------------------------------------+-------+
| performance_schema_events_statements_history_long_size | 10000 |
+--------------------------------------------------------+-------+
1 row in set (0.002 sec)

この値は読み込み専用なので、変更する場合は my.cnf に以下の設定を追加して再起動する必要があります。

[mysqld]
performance_schema_events_statements_history_long_size=20000

events_statements_history_long テーブルのデータはメモリ上に保存されているため、値が大きすぎるとメモリを圧迫する可能性があります。

events_statements_history_long テーブルは実行されたクエリ全体を performance_schema_events_statements_history_long_size の件数分保持します。
performance_schema_events_statements_history_long_size が 10000 件の場合は 10001 件目が挿入されると 1 件目が削除されるため、特定の実行元（ Web サーバーとは異なるバッチ処理があるなど）が判明している場合は、 events_statements_history テーブルを利用する方が良いかもしれません。

events_statements_history テーブルは、スレッド毎に performance_schema_events_statements_history_size で設定された件数分保存されます。
performance_schema_events_statements_history_size は一般的な自動サイズ設定だと 10 件のため、少々心許ないですが、こちらも my.cnf で設定を変更することができます（要再起動）。

events_statements_history テーブルはデフォルトで有効になっているので、概ね設定は不要で使えるかと思います。

まとめ

今回は MySQL にデッドロックと判定されていないタイプのロックを確認する方法を紹介しました。

events_statements_history_long テーブルを有効にした副次的な効果として、クエリ以外にもエラー内容や使用したメモリ量などの実行結果が色々付随するため、定期的に確認するのもいいなと思います。

以上です。