はじめに
本ブログは、「Percona Toolkit のツールを全て使ってみる」シリーズの第 3 弾となります！
Percona 製品は、MySQL と非常に高い互換性を持つ MySQL の派生製品であり、 MySQL ユーザが快適に利用できることを開発コンセプトとしています。
また、MySQL と同様 OSS で提供され、ユーザは無償で利用することができます。
本記事で紹介する Percona Toolkit は、Percona 社が開発した MySQL の運用・監視・分析といった、手動で実行するには複雑な作業を簡単に実施することができるコマンドツール群です。
前回のブログより 2 つの新しいツールが追加され、現在 (2025/6/13) は 42 ツールが存在しています。
その中で、今回は pt-deadlock-logger について紹介します。
Percona Toolkit のツールを全て使ってみるシリーズのブログは以下の表にまとめています。
| シリーズ | ブログ公開日 | ||
|---|---|---|---|
| 第 1 弾 | 2024/12/9 | pt-align | pt-archiver |
| 第 2 弾 | 2025/5/13 | pt-config-diff | |
| 第 3 弾 (本ブログ) | 2025/6/13 | pt-deadlock-logger |
その他、Percona Toolkit 関連のブログは まとめ で紹介していますので併せてご覧ください。
Percona Toolkit のダウンロード・インストール
ダウンロード・インストールに関しては、以下の公式サイトを参考にしてください。
環境情報
今回利用する環境情報
- Oracle Linux 8
- Percona Server for MySQL 8.0.39-30
- Percona Toolkit 3.6.0
pt-deadlock-logger
pt-deadlock-logger は、MySQL のデッドロックに関する情報を簡易的に出力し、記録することができます。
情報は STDOUT に出力され、--dest を指定することでテーブルに保存することもできます。このツールは --run-time または --iterations が指定されない限り永久に実行されます。
実行例
実際に pt-deadlock-logger を実行してみます。
|
1 2 3 |
# Session-01 Shell# pt-deadlock-logger h=localhost,u=root,p=P@ssw0rd |
次に Session-02、3 でデッドロックを発生させます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
# Session-02 mysql> START TRANSACTION; Query OK, 0 rows affected (0.00 sec) mysql> SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE; +------+ | id | +------+ | 1 | +------+ 1 row in set (0.00 sec) mysql> SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE; |
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
# Session-03 mysql> START TRANSACTION; Query OK, 0 rows affected (0.00 sec) mysql> SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE; +------+ | id | +------+ | 1 | +------+ 1 row in set (0.00 sec) mysql> SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE; ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction mysql> |
デッドロックが発生すると Session-01 で以下のような出力がされました。
|
1 2 3 4 5 6 |
# Session-01 Shell# pt-deadlock-logger h=localhost,u=root,p=P@ssw0rd server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T01:16:56 47 0 121 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE localhost 2025-05-14T01:16:56 48 0 82 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE |
出力内容をまとめると SHOW ENGINE INNODB STATUS の LATEST DETECTED DEADLOCK で確認できる内容が簡易的に出力されているとわかります。
-
トランザクションID 47:
- 取得時刻: 2025-05-14T01:16:56
- スレッドID: 121
- ユーザー: root
- ロックがかかっている テーブル: test_tblB
- ロックタイプ: RECORD
- ロックモード: X (排他ロック)
- 待機状態: w (待機中)
- クエリ:
SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE
-
トランザクションID 48:
- 取得時刻: 2025-05-14T01:16:56
- スレッドID: 82
- ユーザー: root
- ロックがかかっている テーブル: test_tblA
- ロックタイプ: RECORD
- ロックモード: X (排他ロック)
- 待機状態: w (待機中)
- クエリ:
SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE
デッドロックが再度発生すると、先ほどのログ出力に新たなデッドロック情報が追記されます。
|
1 2 3 4 5 6 7 8 9 |
# Session-01 Shell# pt-deadlock-logger h=localhost,u=root,p=P@ssw0rd server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T01:16:56 47 0 121 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE localhost 2025-05-14T01:16:56 48 0 82 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE 追記 → server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T04:23:26 52 0 13 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE localhost 2025-05-14T04:23:26 53 0 23 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE |
pt-deadlock-logger を停止し、再度実行すると SHOW ENGINE INNODB STATUS 同様、最後のデッドロック情報のみが出力されます。
|
1 2 3 4 5 6 |
# Session-01 Shell# pt-deadlock-logger h=localhost,u=root,p=P@ssw0rd server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T04:23:26 52 0 13 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE localhost 2025-05-14T04:23:26 53 0 23 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE |
SHOW ENGINE INNODB STATUS との比較
pt-deadlock-logger は、MySQL で発生したデッドロック情報を自動的に収集・記録するツールです。
SHOW ENGINE INNODB STATUS は、直近 1 件のデッドロックしか確認できませんが、pt-deadlock-logger を使用することで定期的にデッドロックの発生を監視し、デッドロックの情報を記録することができます。
オプション紹介
pt-deadlock-logger には、多くのオプションが存在します。
今回は、7 つのオプションを試してみます。
| オプション | 説明 |
|---|---|
| –create-dest-table | 保存用テーブルを作成 (初回のみ) |
| –dest | デッドロック情報を保存するテーブルを指定 |
| –log | ログの出力先ファイルを指定 |
| –daemonize | バックグラウンドで実行 |
| –run-time | 実行する合計時間を指定。例: --run-time 1h |
| –interval | 秒単位でデッドロックのチェック間隔を指定。デフォルトは 30 秒 |
| –iterations | チェック回数を指定。例: --iterations 10 |
--interval と --iterations オプションは、--run-time オプションの使用方法が参考になるため検証は省略しています。
その他のオプションについては 公式サイト をご確認ください。
--create-dest-table、--dest
--create-dest-table、--dest オプションを使用して、デッドロック情報を保存するためのテーブルを作成します。
テーブルは作成されますが、データベースは事前に用意する必要があります。
|
1 2 3 4 |
# Session-01 mysql> create database pt_deadlock_logger; Query OK, 1 row affected (0.00 sec) |
次にテーブル作成のためのコマンドを実行します。
コマンドを実行すると直近 1 件のデッドロック情報が標準出力され監視が開始されます。
|
1 2 3 4 5 6 7 8 |
# Session-02 Shell# pt-deadlock-logger --create-dest-table --dest D=pt_deadlock_logger,t=deadlocks -uroot -pP@ssw0rd # A software update is available: server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T06:10:36 60 0 10 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE localhost 2025-05-14T06:10:36 61 0 21 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE |
deadlocks テーブルが作成され、上記で標準出力されたデッドロック情報が記録されたことを確認します。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
# Session-01 mysql> use pt_deadlock_logger Database changed mysql> show tables; +------------------------------+ | Tables_in_pt_deadlock_logger | +------------------------------+ | deadlocks | +------------------------------+ 1 row in set (0.01 sec) mysql> select * from deadlocks; +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ | server | ts | thread | txn_id | txn_time | user | hostname | ip | db | tbl | idx | lock_type | lock_mode | wait_hold | victim | query | +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ | localhost | 2025-05-14 06:10:36 | 60 | 0 | 10 | root | localhost | | test_db | test_tblA | GEN_CLUST_INDEX | RECORD | X | w | 1 | SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 06:10:36 | 61 | 0 | 21 | root | localhost | | test_db | test_tblB | GEN_CLUST_INDEX | RECORD | X | w | 0 | SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE | +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ 2 rows in set (0.00 sec) |
デッドロックを 2 回ほど発生させて再度 deadlocks テーブルを確認してみます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
# Session-01 mysql> select * from deadlocks; +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ | server | ts | thread | txn_id | txn_time | user | hostname | ip | db | tbl | idx | lock_type | lock_mode | wait_hold | victim | query | +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ | localhost | 2025-05-14 06:10:36 | 60 | 0 | 10 | root | localhost | | test_db | test_tblA | GEN_CLUST_INDEX | RECORD | X | w | 1 | SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 06:10:36 | 61 | 0 | 21 | root | localhost | | test_db | test_tblB | GEN_CLUST_INDEX | RECORD | X | w | 0 | SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 07:54:36 | 90 | 0 | 8 | root | localhost | | test_db | test_tblA | GEN_CLUST_INDEX | RECORD | X | w | 1 | SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 07:54:36 | 91 | 0 | 14 | root | localhost | | test_db | test_tblB | GEN_CLUST_INDEX | RECORD | X | w | 0 | SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 07:55:47 | 92 | 0 | 7 | root | localhost | | test_db | test_tblA | GEN_CLUST_INDEX | RECORD | X | w | 1 | SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE | | localhost | 2025-05-14 07:55:47 | 93 | 0 | 15 | root | localhost | | test_db | test_tblB | GEN_CLUST_INDEX | RECORD | X | w | 0 | SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE | +-----------+---------------------+--------+--------+----------+------+-----------+----+---------+-----------+-----------------+-----------+-----------+-----------+--------+-------------------------------------------------+ 6 rows in set (0.00 sec) |
全てのデッドロックが記憶されていることが確認できます。
--daemonize、--log、--run-time
--log、--daemonizeオプションを使用して、pt-deadlock-logger をバックグラウンド実行し、出力内容を指定したファイルに保存します。--run-timeを使用して合計時間を指定します。
|
1 2 3 4 5 6 7 |
# Session-01 Shell# pt-deadlock-logger --daemonize --log=/var/log/deadlock.log --run-time=3m -uroot -pP@ssw0rd Shell# ps aux | grep pt-deadlock-logger root 9049 0.0 1.1 94380 21232 ? Ss 08:29 0:00 /usr/bin/perl /bin/pt-deadlock-logger --daemonize --log=deadlock.log --run-time=5m -uroot -pP@ssw0rd root 9051 0.0 0.0 10388 1204 pts/3 S+ 08:30 0:00 grep --color=auto pt-deadlock-logger |
デッドロックを発生させて deadlock.log を確認します。
|
1 2 3 4 5 6 |
# Session-01 [root@blog ~]# cat /var/log/deadlock.log server ts thread txn_id txn_time user hostname ip db tbl idx lock_type lock_mode wait_hold victim query localhost 2025-05-14T08:54:30 114 0 19 root localhost test_db test_tblB GEN_CLUST_INDEX RECORD X w 0 SELECT * FROM test_tblB WHERE id = 1 FOR UPDATE localhost 2025-05-14T08:54:30 116 0 10 root localhost test_db test_tblA GEN_CLUST_INDEX RECORD X w 1 SELECT * FROM test_tblA WHERE id = 1 FOR UPDATE |
指定したファイルにデッドロック情報が記憶されていることが確認できました。
次は、3 分経過したのでプロセスを確認してみます。
|
1 2 3 4 |
# Session-01 [root@blog ~]# ps aux | grep pt-deadlock-logger root 9172 0.0 0.0 10388 1140 pts/3 S+ 09:01 0:00 grep --color=auto pt-deadlock-logger |
こちらも、pt-deadlock-logger コマンドが自動で終了していることが確認できました。
まとめ
pt-deadlock-logger について他の記事も見たいという方は、弊社ブログ pt-deadlock-loggerでデッドロックの情報を収集する をご確認ください。
Percona Toolkit は、インストール自体が非常に簡単でインストールしておくだけで 42 個のツールを利用することができます。
重宝するツールもあれば使いこなすのに一癖あるツールもありますが、Percona Toolkit 自体無償で提供されているのでぜひインストールしてみてください。
Percona Toolkit のツールを全て使ってみるシリーズはアルファベット順に進めていますので次回、第 4 弾は pt-diskstats と pt-duplicate-key-checker を紹介します！
(ボリュームによっては pt-diskstats のみの紹介となります)
Percona Toolkit を紹介した SmartStyle TECH BLOG
