MySQLのInnoDBストレージエンジンにおいて、SHOW ENGINE INNODB STATUSコマンドはパフォーマンス障害の診断や内部状態の把握において最も強力なツールの一つです。このコマンドは、セマフォの競合、トランザクションの状態、デッドロック、I/Oスレッドの動作、バッファプールの統計など、リアルタイムで多岐にわたる情報を出力します。本記事では、出力される各セクションの意味と、そこから読み取れるデータベースの健全性について技術的に解説します。
セマフォ(Semaphores)とスレッド競合
SEMAPHORESセクションでは、InnoDB内部のスレッド間でのリソース競合状況を確認できます。ここには「OS WAIT ARRAY INFO」が含まれており、スレッドがオペレーティングシステムレベルで待機している回数(OS waits)や、CPUサイクルを消費して空転(スピン)している回数が表示されます。
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 45012
OS WAIT ARRAY INFO: signal count 45100
RW-shared spins 0, rounds 880120, OS waits 44000
RW-excl spins 0, rounds 42500, OS waits 900
RW-sx spins 1200, rounds 19500, OS waits 150
- OS WAIT ARRAY INFO:
reservation countはリソースの待機を開始した回数、signal countは待機が解除された回数です。これらの差分が大きいほど、解決されていない待機が存在することを示唆します。 - RW-shared / RW-excl / RW-sx: これらは共有ロック、排他ロック、共有排他ロックの取得待機に関する統計です。
spinsはCPUを空転させて待機した回数、roundsはその合計ラウンド数、OS waitsはスピンが失敗しOSレベルのコンテキストスイッチ(待機状態)に移行した回数です。
大量のOS waitsはシステム負荷が高く、ロック競合が頻発している可能性があります。一方、spinsが異常に多い場合、CPUが無駄なループ処理(ビジーウェイト)に時間を費やしていることを意味し、パラメータinnodb_sync_spin_loopsの調整を検討する必要があります。
デッドロック(LATEST DETECTED DEADLOCK)
LATEST DETECTED DEADLOCKセクションには、直近で検出されたデッドロックの詳細な状況が記録されます。ここには、関与したトランザクション、それらが保持しているロック、そして取得しようとして待機しているロックの情報が含まれます。
------------------------
LATEST DETECTED DEADLOCK
------------------------
2023-10-27 10:05:00 0x7f82c0000700
*** (1) TRANSACTION:
TRANSACTION 12345, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 42, OS thread handle 140019234567890, query id 500 localhost root updating
UPDATE customer_accounts SET balance = balance - 100 WHERE id = 10
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 10 page no 5 n bits 80 index PRIMARY of table `shop`.`customer_accounts` trx id 12345 lock_mode X locks rec but not gap waiting
Record lock, heap no 15 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
0: len 4; hex 8000000a; asc ;;
1: len 6; hex 000000002000; asc ;;
2: len 7; hex 010000011b0110; asc ;;
3: len 4; hex 000003e8; asc ;;
4: len 4; hex 00000bb8; asc ;;
*** (2) TRANSACTION:
TRANSACTION 12346, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 43, OS thread handle 140019234567891, query id 501 localhost root updating
UPDATE customer_accounts SET balance = balance + 100 WHERE id = 20
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 10 page no 5 n bits 80 index PRIMARY of table `shop`.`customer_accounts` trx id 12346 lock_mode X locks rec but not gap
Record lock, heap no 15 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
0: len 4; hex 8000000a; asc ;;
1: len 6; hex 000000002000; asc ;;
2: len 7; hex 010000011b0110; asc ;;
3: len 4; hex 000003e8; asc ;;
4: len 4; hex 00000bb8; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 10 page no 6 n bits 80 index idx_balance of table `shop`.`customer_accounts` trx id 12346 lock_mode X locks rec but not gap waiting
*** WE ROLL BACK TRANSACTION (1)
このログにより、トランザクション(1)と(2)が互いに相手が必要とするリソース(この例ではプライマリキーとセカンダリインデックスのレコード)をロックし合い、循環待機の状態に陥ったことがわかります。InnoDBはデッドロックを検出すると、コストの低いトランザクション(通常は変更量が少ない方)を強制的にロールバックして解決を図ります。上記の例では「WE ROLL BACK TRANSACTION (1)」とあるため、トランザクション1が犠牲になったことがわかります。
トランザクションとパージ(Purge)の状態
TRANSACTIONSセクションでは、現在のトランザクションIDカウンタや、パージスレッドの進行状況、ヒストリーリストの長さなどを監視できます。
------------
TRANSACTIONS
------------
Trx id counter 458920
Purge done for trx's n:o < 458100 undo n:o < 0
History list length 150
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
- Trx id counter: システムで次に割り当てられるトランザクションIDです。
- Purge done for trx's n:o < ...: この値は、クリーンアップ(パージ)処理が完了したトランザクションIDの上限を示します。
Trx id counterとこの値の差分が大きい場合、長時間実行されているトランザクションが存在し、古いバージョンのデータ(Undoログ)がパージされていない可能性があります。これはUndoテーブルスペースの肥大化を招くため注意が必要です。 - History list length: Undoログのヒストリーリストにあるエントリ数です。この数値が常に高い場合、コミット済みのトランザクションがロールバックのためにまだクリアされていないことを意味し、パフォーマンス低下の一因となります。
ファイルI/Oとスレッドの状態
FILE I/Oセクションでは、InnoDBの非同期I/Oスレッドの状態と、待機中のI/Oリクエスト数を確認できます。
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
Pending normal aio reads: [0, 0, 0, 0], aio writes: [0, 0, 0, 0]
Pending flushes (fsync) log: 0; buffer pool: 0
Pending normal aio readsやPending flushes (fsync)の値が0でない、あるいは継続的に増加している場合、ディスクI/Oがボトルネックとなっている可能性があります。特にPending flushes (fsync) logの値が高いと、ログのディスクへの書き出し(コミット処理)が遅延しており、トランザクションの応答時間に悪影響を及ぼしています。
バッファプールとメモリ統計
BUFFER POOL AND MEMORYセクションは、InnoDBのデータキャッシュの効率性を判断するために最も重要な指標を含んでいます。
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 342544
Buffer pool size 8191
Free buffers 10
Database pages 8181
Old database pages 3001
Modified db pages 150
Buffer pool hit rate 998 / 1000
- Buffer pool hit rate: バッファプールのヒット率です。1000/1000に近いほど理想であり、ディスク読み取りなしでデータがメモリから供給されていることを示します。この値が低い(例えば950以下)場合、バッファプールサイズが不足しているか、データアクセスパターンに偏りがあります。
- Modified db pages: ダーティページ(変更がメモリ上だけで、まだディスクに書き込まれていないページ)の数です。この数が急激に増加する場合、フラッシュ処理が追いついていない可能性があります。
ログ(Log)の進行状況
LOGセクションでは、Redoログのシーケンス番号(LSN)とチェックポイントの進行状況を確認できます。
---
LOG
---
Log sequence number 987654321
Log flushed up to 987654000
Pages flushed up to 987653000
Last checkpoint at 987650000
Last checkpointの値と現在のLSNの差分が大きいと、クラッシュリカバリ時にログの適用に時間がかかるようになります。また、Log flushed up toとLast checkpointの差が大きい場合、バッファプールのページ書き出しが遅延していることを示唆しています。