Skip navigation links
13.5.12 マルチバージョンの実装 »
Section Navigation      [Toggle]

13.5.11.1. SHOW ENGINE INNODB STATUS と InnoDB モニタ

InnoDB は InnoDB 内部の状態についての情報をプリントする InnoDB モニタを含んでいます。ご自分の SQL クライアントにスタンダード InnoDB モニタのアウトプットをフェッチする為に、いつでも SHOW ENGINE INNODB STATUS SQL ステートメントを利用する事ができます。 この情報は性能調整をするうえで役立ちます。(もし mysql インタラクティブ SQL クライアントを利用しているなら、\G を通常のセミコロン ステートメント ターミネータと置き換えれば、アウトプットはより読みやすくなります。)InnoDB ロック モードの説明に関しては、項13.5.10.1. 「InnoDB ロック モード」 を参照してください。 

mysql> SHOW ENGINE INNODB STATUS\G

InnoDB モニタを利用する別の方法は、それらが mysqld サーバのスタンダード アウトプットにデータを定期的に書き込む事を許可する事です。この場合、アウトプットがクライアントに送られる事はありません。スイッチが入ると、InnoDB モニタは大体15秒毎にデータをプリントします。サーバ アウトプットは通常 MySQL データ ディレクトリ内の .err ログに導かれます。このデータは性能調整をするうえで役立ちます。Windows 上では、もしアウトプットをエラー ログではなくウィンドウに導きたければ、--console オプションを利用して、コンソール ウィンドウ内のコマンド プロンプトからサーバを起動しなければいけません。

モニタ アウトプットは次のタイプの情報を含んでいます:

  • 各アクティブ トランザクションによって保持されるテーブルとレコード ロック

  • トランザクションのロック取得待ち

  • スレッドのセマフォ待ち

  • 保留中のファイル I/O リクエスト

  • バッファ プール統計

  • ほとんどのシステム上でInnoDB のメイン スレッドのパージおよび挿入バッファ マージ活動

スタンダード InnoDB モニタに、mysqld のスタンダード アウトプットへの書き込みをさせる為、次の SQL ステートメントを利用してください: 

CREATE TABLE innodb_monitor (a INT) ENGINE=INNODB;

次のステートメントを発行する事でモニタを停止する事ができます: 

DROP TABLE innodb_monitor;

CREATE TABLE 構文は、MySQL の SQL パーサを通してコマンドをInnoDB エンジンに渡す手段に過ぎません:唯一問題となるのは、テーブル名 innodb_monitor と、InnoDB テーブルです。テーブルの構造は InnoDB モニタとまったく無関係です。サーバを一度シャットダウンして、再度サーバを起動しても、モニタは自動的に起動しません。再びモニタを起動するには、まずモニタ テーブルをドロップし、そして新しい CREATE TABLE ステートメントを発行しなければいけません。(この構文は今後のリリース版で変更される可能性があります。)

innodb_lock_monitor を似たような方法で利用する事ができます。これは、大量のロック情報の提供もするという事以外、innodb_monitor と同じです。別々の innodb_tablespace_monitor は、テーブル スペース内に存在し、テーブル スペース割り当てデータ構造を認証する、作成されたファイル セグメントのリストをプリントします。さらに、InnoDB 内部データ ディレクトリの内容をプリントする事ができる innodb_table_monitor もあります。

InnoDB モニタ アウトプットの例: 

mysql> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
Status:
=====================================
030709 13:00:59 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 18 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 413452, signal count 378357
--Thread 32782 has waited at btr0sea.c line 1477 for 0.00 seconds the
semaphore: X-lock on RW-latch at 41a28668 created in file btr0sea.c line 135
a writer (thread id 32782) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1
Last time read locked in file btr0sea.c line 731
Last time write locked in file btr0sea.c line 1347
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 108462, OS waits 37964; RW-excl spins 681824, OS waits
375485
------------------------
LATEST FOREIGN KEY ERROR
------------------------
030709 13:00:59 Transaction:
TRANSACTION 0 290328284, ACTIVE 0 sec, process no 3195, OS thread id 34831
inserting
15 lock struct(s), heap size 2496, undo log entries 9
MySQL thread id 25, query id 4668733 localhost heikki update
insert into ibtest11a (D, B, C) values (5, 'khDk' ,'khDk')
Foreign key constraint fails for table test/ibtest11a:
,
  CONSTRAINT `0_219242` FOREIGN KEY (`A`, `D`) REFERENCES `ibtest11b` (`A`,
  `D`) ON DELETE CASCADE ON UPDATE CASCADE
Trying to add in child table, in index PRIMARY tuple:
 0: len 4; hex 80000101; asc ....;; 1: len 4; hex 80000005; asc ....;; 2:
 len 4; hex 6b68446b; asc khDk;; 3: len 6; hex 0000114e0edc; asc ...N..;; 4:
 len 7; hex 00000000c3e0a7; asc .......;; 5: len 4; hex 6b68446b; asc khDk;;
But in parent table test/ibtest11b, in index PRIMARY,
the closest match we can find is record:
RECORD: info bits 0 0: len 4; hex 8000015b; asc ...[;; 1: len 4; hex
80000005; asc ....;; 2: len 3; hex 6b6864; asc khd;; 3: len 6; hex
0000111ef3eb; asc ......;; 4: len 7; hex 800001001e0084; asc .......;; 5:
len 3; hex 6b6864; asc khd;;
------------------------
LATEST DETECTED DEADLOCK
------------------------
030709 12:59:58
*** (1) TRANSACTION:
TRANSACTION 0 290252780, ACTIVE 1 sec, process no 3185, OS thread id 30733
inserting
LOCK WAIT 3 lock struct(s), heap size 320, undo log entries 146
MySQL thread id 21, query id 4553379 localhost heikki update
INSERT INTO alex1 VALUES(86, 86, 794,'aA35818','bb','c79166','d4766t',
'e187358f','g84586','h794',date_format('2001-04-03 12:54:22','%Y-%m-%d
%H:%i'),7
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 48310 n bits 568 table test/alex1 index
symbole trx id 0 290252780 lock mode S waiting
Record lock, heap no 324 RECORD: info bits 0 0: len 7; hex 61613335383138;
asc aa35818;; 1:
*** (2) TRANSACTION:
TRANSACTION 0 290251546, ACTIVE 2 sec, process no 3190, OS thread id 32782
inserting
130 lock struct(s), heap size 11584, undo log entries 437
MySQL thread id 23, query id 4554396 localhost heikki update
REPLACE INTO alex1 VALUES(NULL, 32, NULL,'aa3572','','c3572','d6012t','',
NULL,'h396', NULL, NULL, 7.31,7.31,7.31,200)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 48310 n bits 568 table test/alex1 index
symbole trx id 0 290251546 lock_mode X locks rec but not gap
Record lock, heap no 324 RECORD: info bits 0 0: len 7; hex 61613335383138;
asc aa35818;; 1:
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 48310 n bits 568 table test/alex1 index
symbole trx id 0 290251546 lock_mode X locks gap before rec insert intention
waiting
Record lock, heap no 82 RECORD: info bits 0 0: len 7; hex 61613335373230;
asc aa35720;; 1:
*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 0 290328385
Purge done for trx's n:o < 0 290315608 undo n:o < 0 17
Total number of lock structs in row lock hash table 70
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 3491, OS thread id 42002
MySQL thread id 32, query id 4668737 localhost heikki
show innodb status
---TRANSACTION 0 290328384, ACTIVE 0 sec, process no 3205, OS thread id
38929 inserting
1 lock struct(s), heap size 320
MySQL thread id 29, query id 4668736 localhost heikki update
insert into speedc values (1519229,1, 'hgjhjgghggjgjgjgjgjggjgjgjgjgjgggjgjg
jlhhgghggggghhjhghgggggghjhghghghghghhhhghghghjhhjghjghjkghjghjghjghjfhjfh
---TRANSACTION 0 290328383, ACTIVE 0 sec, process no 3180, OS thread id
28684 committing
1 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 19, query id 4668734 localhost heikki update
insert into speedcm values (1603393,1, 'hgjhjgghggjgjgjgjgjggjgjgjgjgjgggjgj
gjlhhgghggggghhjhghgggggghjhghghghghghhhhghghghjhhjghjghjkghjghjghjghjfhjf
---TRANSACTION 0 290328327, ACTIVE 0 sec, process no 3200, OS thread id
36880 starting index read
LOCK WAIT 2 lock struct(s), heap size 320
MySQL thread id 27, query id 4668644 localhost heikki Searching rows for
update
update ibtest11a set B = 'kHdkkkk' where A = 89572
------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 65556 n bits 232 table test/ibtest11a index
PRIMARY trx id 0 290328327 lock_mode X waiting
Record lock, heap no 1 RECORD: info bits 0 0: len 9; hex 73757072656d756d00;
asc supremum.;;
------------------
---TRANSACTION 0 290328284, ACTIVE 0 sec, process no 3195, OS thread id
34831 rollback of SQL statement
ROLLING BACK 14 lock struct(s), heap size 2496, undo log entries 9
MySQL thread id 25, query id 4668733 localhost heikki update
insert into ibtest11a (D, B, C) values (5, 'khDk' ,'khDk')
---TRANSACTION 0 290327208, ACTIVE 1 sec, process no 3190, OS thread id
32782
58 lock struct(s), heap size 5504, undo log entries 159
MySQL thread id 23, query id 4668732 localhost heikki update
REPLACE INTO alex1 VALUES(86, 46, 538,'aa95666','bb','c95666','d9486t',
'e200498f','g86814','h538',date_format('2001-04-03 12:54:22','%Y-%m-%d
%H:%i'),
---TRANSACTION 0 290323325, ACTIVE 3 sec, process no 3185, OS thread id
30733 inserting
4 lock struct(s), heap size 1024, undo log entries 165
MySQL thread id 21, query id 4668735 localhost heikki update
INSERT INTO alex1 VALUES(NULL, 49, NULL,'aa42837','','c56319','d1719t','',
NULL,'h321', NULL, NULL, 7.31,7.31,7.31,200)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
151671 OS file reads, 94747 OS file writes, 8750 OS fsyncs
25.44 reads/s, 18494 avg bytes/read, 17.55 writes/s, 2.33 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 19, seg size 21,
85004 inserts, 85004 merged recs, 26669 merges
Hash table size 207619, used cells 14461, node heap has 16 buffer(s)
1877.67 hash searches/s, 5121.10 non-hash searches/s
---
LOG
---
Log sequence number 18 1212842764
Log flushed up to   18 1212665295
Last checkpoint at  18 1135877290
0 pending log writes, 0 pending chkp writes
4341 log i/o's done, 1.22 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 84966343; in additional pool allocated 1402624
Buffer pool size   3200
Free buffers       110
Database pages     3074
Modified db pages  2674
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 171380, created 51968, written 194688
28.72 reads/s, 20.72 creates/s, 47.55 writes/s
Buffer pool hit rate 999 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 3004, id 7176, state: purging
Number of rows inserted 3738558, updated 127415, deleted 33707, read 755779
1586.13 inserts/s, 50.89 updates/s, 28.44 deletes/s, 107.88 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

アウトプットの注意点:

  • もし TRANSACTIONS セクションがロック待ちを報告したら、アプリケーションでロックが競合している可能性があります。このアウトプットから、トランザクションのデッドロックの原因を追跡する事もできます。

  • e.SEMAPHORES セクションには、セマフォを待っているスレッドと、スレッドがスピンまたは相互排他ロック(mutex)や 読み書きロックでの待機を必要とした回数に関する統計情報が報告されます。多数のスレッドがセマフォを待っている場合は、ディスク I/O または InnoDB 内部の競合が原因となっている可能性があります。競合の原因としては、多数のクエリを並行して処理しているか、OSでのスレッドのスケジューリングに問題がある事が考えられます。innodb_thread_concurrency をデフォルト値よりも小さく設定すると、このような状況を救う事ができます。

  • BUFFER POOL AND MEMORY セクションは読み込み、書き込みされたページの統計を提供します。.これらの数字から、クエリが現在いくつのデータ ファイル I/O 操作を行っているかを計算する事ができます。

  • ROW OPERATIONS セクションはメインスレッドが何をしているのかを表します。

InnoDB は、バッファ オーバ フローの可能性を避ける為に、stdout や固定サイズ メモリ バッファではなく、stderr やファイルに診断アウトプットを送ります。副作用として、15秒ごとに MySQL データ ディレクトリ内のステータス ファイルに SHOW ENGINE INNODB STATUS のアウトプットが書き込まれます。ファイルの名前は innodb_status.pid で、pid はサーバ プロセス ID です。InnoDB は通常のシャットダウンの為にファイルを削除します。もし異常なシャットダウンが起きたら、これらのステータス ファイルが存在する可能性があり、それはマニュアルで削除する必要があります。それらを削除する前に、異常シャットダウンの原因に関する有益な情報を含んでいるかどうかを確認した方が良いでしょう。innodb_status.pid ファイルは設定オプション innodb_status_file=1 が設定された場合のみ作成されます。