MySQL 5.1 Reference Manual  /  ...  /  InnoDB Standard Monitor and Lock Monitor Output

14.6.9.1 InnoDB Standard Monitor and Lock Monitor Output

The Lock Monitor is the same as the standard Monitor except that it includes additional lock information. Enabling either monitor for periodic output by creating the associated InnoDB table turns on the same output stream, but the stream includes the extra information if the Lock Monitor is enabled. For example, if you create the innodb_monitor and innodb_lock_monitor tables, that turns on a single output stream. The stream includes extra lock information until you disable the Lock Monitor by removing the innodb_lock_monitor table.

Example InnoDB Monitor output (as of MySQL 5.1.72):

mysql> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
141017  9:57:58 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 9 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 416, signal count 413
Mutex spin waits 0, rounds 4630, OS waits 153
RW-shared spins 516, OS waits 258; RW-excl spins 9, OS waits 5
------------------------
LATEST FOREIGN KEY ERROR
------------------------
141017  9:50:15 Transaction:
TRANSACTION 0 2309, ACTIVE 0 sec, process no 4615, OS thread id 140008823879424 
inserting, thread declared inside InnoDB 498
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1216, 3 row lock(s), undo log entries 3
MySQL thread id 1, query id 90 localhost msandbox update
INSERT INTO child VALUES (NULL, 1), (NULL, 2), (NULL, 3), (NULL, 4), (NULL, 5), 
(NULL, 6)
Foreign key constraint fails for table `mysql`.`child`:
,
  CONSTRAINT `child_ibfk_1` FOREIGN KEY (`parent_id`) REFERENCES `parent` (`id`)
 ON DELETE CASCADE ON UPDATE CASCADE
Trying to add in child table, in index `par_ind` tuple:
DATA TUPLE: 2 fields;
 0: len 4; hex 80000003; asc     ;; 1: len 4; hex 80000003; asc     ;;

But in parent table `mysql`.`parent`, in index `PRIMARY`,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000004; asc     ;; 1: len 6; hex 000000000902; asc       ;; 2: 
len 7; hex 800000002d0134; asc     - 4;;

------------------------
LATEST DETECTED DEADLOCK
------------------------
141017  9:52:52
*** (1) TRANSACTION:
TRANSACTION 0 2313, ACTIVE 9 sec, process no 4615, OS thread id 140008823346944 
starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 3, query id 103 localhost msandbox updating
DELETE FROM t WHERE i = 1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 56 n bits 72 index `GEN_CLUST_INDEX` of table `m
ysql`.`t` trx id 0 2313 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000300; asc       ;; 1: len 6; hex 000000000907; asc       
;; 2: len 7; hex 800000002d0110; asc     -  ;; 3: len 4; hex 80000001; asc     ;
;

*** (2) TRANSACTION:
TRANSACTION 0 2312, ACTIVE 27 sec, process no 4615, OS thread id 140008823879424
 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1216, 3 row lock(s)
MySQL thread id 1, query id 104 localhost msandbox updating
DELETE FROM t WHERE i = 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 56 n bits 72 index `GEN_CLUST_INDEX` of table `m
ysql`.`t` trx id 0 2312 lock mode S
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000300; asc       ;; 1: len 6; hex 000000000907; asc       
;; 2: len 7; hex 800000002d0110; asc     -  ;; 3: len 4; hex 80000001; asc     ;
;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 56 n bits 72 index `GEN_CLUST_INDEX` of table `m
ysql`.`t` trx id 0 2312 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 6; hex 000000000300; asc       ;; 1: len 6; hex 000000000907; asc       
;; 2: len 7; hex 800000002d0110; asc     -  ;; 3: len 4; hex 80000001; asc     ;
;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 0 3160
Purge done for trx's n:o < 0 2935 undo n:o < 0 0
History list length 18
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 3159, not started, process no 4615, OS thread id 14000882361318
4
MySQL thread id 2, query id 957 localhost msandbox
INSERT INTO `dept_emp` VALUES (77697,'d007','1993-08-23','1993-09-10'),(77698,'d
004','1990-07-24','2002-02-16'),(77698,'d009','2002-02-16','9999-01-01'),(77699,
'd008','1998-01-12','9999-01-01'),(77700,'d005','1995-07-05','9999-01-01'),(7770
1,'d007','1986-10-10','1992-05-07'),(77702,'d007','1988-11-22','9999-01-01'),(77
703,'d004','1992-11-16','9999-01-01'),(77704,'d007','1999-06-23','9999-01-01'),(
77705,'d004','1998-09-29','9999-01-01'),(77706,'d007','1991-03-17','2001-02-20')
,(77707,'d001','1997-06-16','2002-03-03'),(77707,'d007','2002-03-03','9999-01-01
'),(77708,'d008','1987-04-08','9999-01-0
---TRANSACTION 0 2313, not started, process no 4615, OS thread id 14000882334694
4
MySQL thread id 3, query id 105 localhost msandbox
---TRANSACTION 0 2312, ACTIVE 333 sec, process no 4615, OS thread id 14000882387
9424
4 lock struct(s), heap size 1216, 4 row lock(s), undo log entries 1
MySQL thread id 1, query id 958 localhost msandbox
SHOW ENGINE INNODB STATUS
TABLE LOCK table `mysql`.`t` trx id 0 2312 lock mode IS
RECORD LOCKS space id 0 page no 56 n bits 72 index `GEN_CLUST_INDEX` of table `m
ysql`.`t` trx id 0 2312 lock mode S
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 6; hex 000000000300; asc       ;; 1: len 6; hex 000000000908; asc       
;; 2: len 7; hex 00000000320a51; asc     2 Q;; 3: len 4; hex 80000001; asc     ;
;

TABLE LOCK table `mysql`.`t` trx id 0 2312 lock mode IX
RECORD LOCKS space id 0 page no 56 n bits 72 index `GEN_CLUST_INDEX` of table `m
ysql`.`t` trx id 0 2312 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 6; hex 000000000300; asc       ;; 1: len 6; hex 000000000908; asc       
;; 2: len 7; hex 00000000320a51; asc     2 Q;; 3: len 4; hex 80000001; asc     ;
;

--------
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
5934 OS file reads, 14161 OS file writes, 4182 OS fsyncs
12.22 reads/s, 39023 avg bytes/read, 38.00 writes/s, 11.33 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 17393, node heap has 79 buffer(s)
73846.91 hash searches/s, 1343.52 non-hash searches/s
---
LOG
---
Log sequence number 0 1509321681
Log flushed up to   0 1509321681
Last checkpoint at  0 1506336310
0 pending log writes, 0 pending chkp writes
5287 log i/o's done, 14.55 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 20644802; in additional pool allocated 852992
Dictionary memory allocated 88200
Buffer pool size   512
Free buffers       2
Database pages     431
Modified db pages  110
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 15891, created 51023, written 61061
29.11 reads/s, 137.21 creates/s, 145.76 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 4615, id 140008618981120, state: sleeping
Number of rows inserted 16050922, updated 0, deleted 3, read 4
41645.71 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

InnoDB Monitor output is limited to 64,000 bytes when produced using the SHOW ENGINE INNODB STATUS statement. This limit does not apply to output written to the server's error output.

Some notes on the output sections:

Status

This section shows the timestamp, the monitor name, and the number of seconds that per-second averages are based on. The number of seconds is the elapsed time between the current time and the last time InnoDB Monitor output was printed.

BACKGROUND THREAD

The srv_master_thread lines shows work done by the main background thread. This section is displayed only by InnoDB Plugin.

SEMAPHORES

This section reports threads waiting for a semaphore and statistics on how many times threads have needed a spin or a wait on a mutex or a rw-lock semaphore. A large number of threads waiting for semaphores may be a result of disk I/O, or contention problems inside InnoDB. Contention can be due to heavy parallelism of queries or problems in operating system thread scheduling. Setting the innodb_thread_concurrency system variable smaller than the default value might help in such situations. The Spin rounds per wait line (InnoDB Plugin only) shows the number of spinlock rounds per OS wait for a mutex.

LATEST FOREIGN KEY ERROR

This section provides information about the most recent foreign key constraint error. It is not present if no such error has occurred. The contents include the statement that failed as well as information about the constraint that failed and the referenced and referencing tables.

LATEST DETECTED DEADLOCK

This section provides information about the most recent deadlock. It is not present if no deadlock has occurred. The contents show which transactions are involved, the statement each was attempting to execute, the locks they have and need, and which transaction InnoDB decided to roll back to break the deadlock. The lock modes reported in this section are explained in Section 14.6.4.1, “InnoDB Lock Modes”.

TRANSACTIONS

If this section reports lock waits, your applications might have lock contention. The output can also help to trace the reasons for transaction deadlocks.

FILE I/O

This section provides information about threads that InnoDB uses to perform various types of I/O. The first few of these are dedicated to general InnoDB processing. The contents also display information for pending I/O operations and statistics for I/O performance.

On Unix, the number of threads is always 4. On Windows, the number depends on the setting of the innodb_file_io_threads system variable.

INSERT BUFFER AND ADAPTIVE HASH INDEX

This section shows the status of the InnoDB insert buffer and adaptive hash index. (See Section 14.6.3.2.3, “Insert Buffering”, and Section 14.6.3.2.4, “Adaptive Hash Indexes”.) The contents include the number of operations performed for each, plus statistics for hash index performance.

LOG

This section displays information about the InnoDB log. The contents include the current log sequence number, how far the log has been flushed to disk, and the position at which InnoDB last took a checkpoint. (See Section 14.6.10.2, “InnoDB Checkpoints”.) The section also displays information about pending writes and write performance statistics.

BUFFER POOL AND MEMORY

This section gives you statistics on pages read and written. You can calculate from these numbers how many data file I/O operations your queries currently are doing.

For additional information about the operation of the buffer pool, see Section 8.10.2, “The InnoDB Buffer Pool”.

ROW OPERATIONS

This section shows what the main thread is doing, including the number and performance rate for each type of row operation.


User Comments
Sign Up Login You must be logged in to post a comment.