Details
-
Bug
-
Status: Closed (View Workflow)
-
Minor
-
Resolution: Won't Fix
-
5.5.30, 5.1.67, 5.2.14, 5.3.12
-
None
-
Windows, Linux
Description
If you are running MariaDB 5.5.30 (at least on Windows) and you enable the InnoDB Lock Monitor (i.e., CREATE TABLE innodb_lock_monitor (id int) ENGINE=InnoDB), no extra lock information is logged. It is the same output as SHOW ENGINE INNODB STATUS. This differs from the standard InnoDB Plugin, as it displays much more lock information.
1. Start MariaDB 5.5.30
2. SHOW ENGINE INNODB STATUS\G
3. CREATE TABLE innodb_lock_monitor (id int) ENGINE=InnoDB;
4. SHOW ENGINE INNODB STATUS\G
5. Compare the 2 SHOW ENGINE INNODB STATUS Outputs. You'll see they are identical. This is not the case with the standard MySQL InnoDB Plugin.
6. You can also examine the error log, which you will see the output written there matches that of the above.
See my 3 outputs below (SHOW INNODB STATUS #1, SHOW INNODB STATUS #2, Error log):
1st SHOW ENGINE INNODB STATUS Output
mysql> show engine innodb status\G
|
*************************** 1. row ***************************
|
Type: InnoDB
|
Name:
|
Status:
|
=====================================
|
130319 14:15:22 INNODB MONITOR OUTPUT
|
=====================================
|
Per second averages calculated from the last 5 seconds
|
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 12 1_second, 12 sleeps, 1 10_second, 2 background, 2 flush
|
srv_master_thread log flush and writes: 139
|
----------
|
SEMAPHORES
|
----------
|
OS WAIT ARRAY INFO: reservation count 4, signal count 4
|
Mutex spin waits 1, rounds 30, OS waits 1
|
RW-shared spins 3, rounds 90, OS waits 3
|
RW-excl spins 0, rounds 0, OS waits 0
|
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 0.00 RW-excl
|
--------
|
FILE I/O
|
--------
|
I/O thread 0 state: native aio handle (insert buffer thread)
|
I/O thread 1 state: native aio handle (log thread)
|
I/O thread 2 state: native aio handle (read thread)
|
I/O thread 3 state: native aio handle (read thread)
|
I/O thread 4 state: native aio handle (read thread)
|
I/O thread 5 state: native aio handle (read thread)
|
I/O thread 6 state: native aio handle (write thread)
|
I/O thread 7 state: native aio handle (write thread)
|
I/O thread 8 state: native aio handle (write thread)
|
I/O thread 9 state: native aio handle (write thread)
|
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
|
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
|
Pending flushes (fsync) log: 0; buffer pool: 0
|
246 OS file reads, 18 OS file writes, 8 OS fsyncs
|
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
|
-------------------------------------
|
INSERT BUFFER AND ADAPTIVE HASH INDEX
|
-------------------------------------
|
Ibuf: size 1, free list len 0, seg size 2, 0 merges
|
merged operations:
|
insert 0, delete mark 0, delete 0
|
discarded operations:
|
insert 0, delete mark 0, delete 0
|
Hash table size 199289, node heap has 1 buffer(s)
|
0.00 hash searches/s, 0.00 non-hash searches/s
|
---
|
LOG
|
---
|
Log sequence number 1723639
|
Log flushed up to 1723639
|
Last checkpoint at 1723639
|
Max checkpoint age 84223550
|
Checkpoint age target 81591565
|
Modified age 0
|
Checkpoint age 0
|
0 pending log writes, 0 pending chkp writes
|
11 log i/o's done, 0.00 log i/o's/second
|
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total memory allocated 103415808; in additional pool allocated 0
|
Internal hash tables (constant factor + variable factor)
|
Adaptive hash index 1614912 (1594312 + 20600)
|
Page hash 100424 (buffer pool 0 only)
|
Dictionary cache 844668 (798704 + 45964)
|
File system 83536 (82672 + 864)
|
Lock system 250600 (249848 + 752)
|
Recovery system 0 (0 + 0)
|
Dictionary memory allocated 45964
|
Buffer pool size 6143
|
Buffer pool size, bytes 100646912
|
Free buffers 5906
|
Database pages 236
|
Old database pages 0
|
Modified db pages 0
|
Pending reads 0
|
Pending writes: LRU 0, flush list 0, single page 0
|
Pages made young 0, not young 0
|
0.00 youngs/s, 0.00 non-youngs/s
|
Pages read 235, created 1, written 11
|
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
|
No buffer pool page gets since the last printout
|
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
|
LRU len: 236, unzip_LRU len: 0
|
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
|
--------------
|
ROW OPERATIONS
|
--------------
|
0 queries inside InnoDB, 0 queries in queue
|
1 read views open inside InnoDB
|
---OLDEST VIEW---
|
Normal read view
|
Read view low limit trx n:o 700
|
Read view up limit trx id 700
|
Read view low limit trx id 700
|
Read view individually stored trx ids:
|
-----------------
|
Main thread id 10564, state: waiting for server activity
|
Number of rows inserted 5, updated 0, deleted 0, read 5
|
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
|
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 703
|
Purge done for trx's n:o < 3A3 undo n:o < 0
|
History list length 41
|
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 0, not started
|
MySQL thread id 2, OS thread handle 0x3444, query id 8 localhost ::1 root
|
show engine innodb status
|
---TRANSACTION 702, ACTIVE 16 sec
|
2 lock struct(s), heap size 376, 6 row lock(s)
|
MySQL thread id 1, OS thread handle 0x3444, query id 7 localhost ::1 root
|
TABLE LOCK table `test1`.`t` trx id 702 lock mode IX
|
RECORD LOCKS space id 0 page no 401 n bits 72 index `GEN_CLUST_INDEX` of table `test1`.`t` trx id 702 lock_mode X
|
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
|
|
1 row in set (0.04 sec)
|
2nd SHOW ENGINE INNODB STATUS Output
mysql> create table innodb_lock_monitor (id int) engine=innodb;
|
Query OK, 0 rows affected (0.05 sec)
|
|
|
mysql> show engine innodb status\G
|
*************************** 1. row ***************************
|
Type: InnoDB
|
Name:
|
Status:
|
=====================================
|
130319 14:15:51 INNODB MONITOR OUTPUT
|
=====================================
|
Per second averages calculated from the last 29 seconds
|
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 13 1_second, 13 sleeps, 1 10_second, 4 background, 4 flush
|
srv_master_thread log flush and writes: 140
|
----------
|
SEMAPHORES
|
----------
|
OS WAIT ARRAY INFO: reservation count 5, signal count 5
|
Mutex spin waits 1, rounds 30, OS waits 1
|
RW-shared spins 4, rounds 120, OS waits 4
|
RW-excl spins 0, rounds 0, OS waits 0
|
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 0.00 RW-excl
|
--------
|
FILE I/O
|
--------
|
I/O thread 0 state: native aio handle (insert buffer thread)
|
I/O thread 1 state: native aio handle (log thread)
|
I/O thread 2 state: native aio handle (read thread)
|
I/O thread 3 state: native aio handle (read thread)
|
I/O thread 4 state: native aio handle (read thread)
|
I/O thread 5 state: native aio handle (read thread)
|
I/O thread 6 state: native aio handle (write thread)
|
I/O thread 7 state: native aio handle (write thread)
|
I/O thread 8 state: native aio handle (write thread)
|
I/O thread 9 state: native aio handle (write thread)
|
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
|
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
|
Pending flushes (fsync) log: 0; buffer pool: 0
|
247 OS file reads, 33 OS file writes, 12 OS fsyncs
|
0.03 reads/s, 16384 avg bytes/read, 0.52 writes/s, 0.14 fsyncs/s
|
-------------------------------------
|
INSERT BUFFER AND ADAPTIVE HASH INDEX
|
-------------------------------------
|
Ibuf: size 1, free list len 0, seg size 2, 0 merges
|
merged operations:
|
insert 0, delete mark 0, delete 0
|
discarded operations:
|
insert 0, delete mark 0, delete 0
|
Hash table size 199289, node heap has 1 buffer(s)
|
0.00 hash searches/s, 0.24 non-hash searches/s
|
---
|
LOG
|
---
|
Log sequence number 1726126
|
Log flushed up to 1726126
|
Last checkpoint at 1726126
|
Max checkpoint age 84223550
|
Checkpoint age target 81591565
|
Modified age 0
|
Checkpoint age 0
|
0 pending log writes, 0 pending chkp writes
|
13 log i/o's done, 0.07 log i/o's/second
|
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total memory allocated 103415808; in additional pool allocated 0
|
Internal hash tables (constant factor + variable factor)
|
Adaptive hash index 1614912 (1594312 + 20600)
|
Page hash 100424 (buffer pool 0 only)
|
Dictionary cache 848790 (798704 + 50086)
|
File system 83536 (82672 + 864)
|
Lock system 250600 (249848 + 752)
|
Recovery system 0 (0 + 0)
|
Dictionary memory allocated 50086
|
Buffer pool size 6143
|
Buffer pool size, bytes 100646912
|
Free buffers 5903
|
Database pages 239
|
Old database pages 0
|
Modified db pages 0
|
Pending reads 0
|
Pending writes: LRU 0, flush list 0, single page 0
|
Pages made young 0, not young 0
|
0.00 youngs/s, 0.00 non-youngs/s
|
Pages read 236, created 3, written 23
|
0.03 reads/s, 0.07 creates/s, 0.41 writes/s
|
Buffer pool hit rate 981 / 1000, young-making rate 0 / 1000 not 0 / 1000
|
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
|
LRU len: 239, unzip_LRU len: 0
|
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
|
--------------
|
ROW OPERATIONS
|
--------------
|
0 queries inside InnoDB, 0 queries in queue
|
1 read views open inside InnoDB
|
---OLDEST VIEW---
|
Normal read view
|
Read view low limit trx n:o 700
|
Read view up limit trx id 700
|
Read view low limit trx id 700
|
Read view individually stored trx ids:
|
-----------------
|
Main thread id 10564, state: waiting for server activity
|
Number of rows inserted 5, updated 0, deleted 0, read 5
|
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
|
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 704
|
Purge done for trx's n:o < 3A3 undo n:o < 0
|
History list length 41
|
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 0, not started
|
MySQL thread id 2, OS thread handle 0x3444, query id 10 localhost ::1 root
|
show engine innodb status
|
---TRANSACTION 702, ACTIVE 45 sec
|
2 lock struct(s), heap size 376, 6 row lock(s)
|
MySQL thread id 1, OS thread handle 0x3444, query id 7 localhost ::1 root
|
TABLE LOCK table `test1`.`t` trx id 702 lock mode IX
|
RECORD LOCKS space id 0 page no 401 n bits 72 index `GEN_CLUST_INDEX` of table `test1`.`t` trx id 702 lock_mode X
|
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
|
|
1 row in set (0.00 sec)
|
|
|
mysql> drop table innodb_lock_monitor;
|
Query OK, 0 rows affected (0.05 sec)
|
Error Log:
130319 13:56:59 InnoDB: The InnoDB memory heap is disabled
|
130319 13:56:59 InnoDB: Mutexes and rw_locks use Windows interlocked functions
|
130319 13:56:59 InnoDB: Compressed tables use zlib 1.2.3
|
130319 13:56:59 InnoDB: Initializing buffer pool, size = 96.0M
|
130319 13:56:59 InnoDB: Completed initialization of buffer pool
|
130319 13:56:59 InnoDB: highest supported file format is Barracuda.
|
130319 13:56:59 InnoDB: Waiting for the background threads to start
|
130319 13:57:00 Percona XtraDB (http://www.percona.com) 5.5.30-MariaDB-30.1 started; log sequence number 1721723
|
130319 13:57:00 [Note] Plugin 'FEEDBACK' is disabled.
|
130319 13:57:01 [Note] Event Scheduler: Loaded 0 events
|
130319 13:57:01 [Note] C:\Program Files\MariaDB 5.5\bin\mysqld.exe: ready for connections.
|
Version: '5.5.30-MariaDB' socket: '' port: 3310 mariadb.org binary distribution
|
|
|
=====================================
|
130319 14:15:59 INNODB MONITOR OUTPUT
|
=====================================
|
Per second averages calculated from the last 8 seconds
|
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 13 1_second, 13 sleeps, 1 10_second, 4 background, 4 flush
|
srv_master_thread log flush and writes: 140
|
----------
|
SEMAPHORES
|
----------
|
OS WAIT ARRAY INFO: reservation count 5, signal count 5
|
Mutex spin waits 1, rounds 30, OS waits 1
|
RW-shared spins 4, rounds 120, OS waits 4
|
RW-excl spins 0, rounds 0, OS waits 0
|
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 0.00 RW-excl
|
--------
|
FILE I/O
|
--------
|
I/O thread 0 state: native aio handle (insert buffer thread)
|
I/O thread 1 state: native aio handle (log thread)
|
I/O thread 2 state: native aio handle (read thread)
|
I/O thread 3 state: native aio handle (read thread)
|
I/O thread 4 state: native aio handle (read thread)
|
I/O thread 5 state: native aio handle (read thread)
|
I/O thread 6 state: native aio handle (write thread)
|
I/O thread 7 state: native aio handle (write thread)
|
I/O thread 8 state: native aio handle (write thread)
|
I/O thread 9 state: native aio handle (write thread)
|
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
|
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
|
Pending flushes (fsync) log: 0; buffer pool: 0
|
247 OS file reads, 33 OS file writes, 12 OS fsyncs
|
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
|
-------------------------------------
|
INSERT BUFFER AND ADAPTIVE HASH INDEX
|
-------------------------------------
|
Ibuf: size 1, free list len 0, seg size 2, 0 merges
|
merged operations:
|
insert 0, delete mark 0, delete 0
|
discarded operations:
|
insert 0, delete mark 0, delete 0
|
Hash table size 199289, node heap has 1 buffer(s)
|
0.00 hash searches/s, 0.00 non-hash searches/s
|
---
|
LOG
|
---
|
Log sequence number 1726126
|
Log flushed up to 1726126
|
Last checkpoint at 1726126
|
Max checkpoint age 84223550
|
Checkpoint age target 81591565
|
Modified age 0
|
Checkpoint age 0
|
0 pending log writes, 0 pending chkp writes
|
13 log i/o's done, 0.00 log i/o's/second
|
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total memory allocated 103415808; in additional pool allocated 0
|
Internal hash tables (constant factor + variable factor)
|
Adaptive hash index 1614912 (1594312 + 20600)
|
Page hash 100424 (buffer pool 0 only)
|
Dictionary cache 848790 (798704 + 50086)
|
File system 83536 (82672 + 864)
|
Lock system 250600 (249848 + 752)
|
Recovery system 0 (0 + 0)
|
Dictionary memory allocated 50086
|
Buffer pool size 6143
|
Buffer pool size, bytes 100646912
|
Free buffers 5903
|
Database pages 239
|
Old database pages 0
|
Modified db pages 0
|
Pending reads 0
|
Pending writes: LRU 0, flush list 0, single page 0
|
Pages made young 0, not young 0
|
0.00 youngs/s, 0.00 non-youngs/s
|
Pages read 236, created 3, written 23
|
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
|
No buffer pool page gets since the last printout
|
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
|
LRU len: 239, unzip_LRU len: 0
|
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
|
--------------
|
ROW OPERATIONS
|
--------------
|
0 queries inside InnoDB, 0 queries in queue
|
1 read views open inside InnoDB
|
---OLDEST VIEW---
|
Normal read view
|
Read view low limit trx n:o 700
|
Read view up limit trx id 700
|
Read view low limit trx id 700
|
Read view individually stored trx ids:
|
-----------------
|
Main thread id 10564, state: waiting for server activity
|
Number of rows inserted 5, updated 0, deleted 0, read 5
|
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
|
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 704
|
Purge done for trx's n:o < 3A3 undo n:o < 0
|
History list length 41
|
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 0, not started
|
MySQL thread id 2, OS thread handle 0x3444, query id 10 localhost ::1 root
|
---TRANSACTION 702, ACTIVE 53 sec
|
2 lock struct(s), heap size 376, 6 row lock(s)
|
MySQL thread id 1, OS thread handle 0x3444, query id 7 localhost ::1 root
|
TABLE LOCK table `test1`.`t` trx id 702 lock mode IX
|
RECORD LOCKS space id 0 page no 401 n bits 72 index `GEN_CLUST_INDEX` of table `test1`.`t` trx id 702 lock_mode X
|
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
Attachments
Issue Links
Activity
From all I see, it's reproducible on Percona Server (e.g. 5.5.29) as well. I can resubmit the report to percona-server bug tracker if you didn't file it there yet.
Hello,
No, I did not file it with Percona.
(I usually don't test Percona much since I use Windows mainly, but I'll try and test it on a *nix box next time.)
Many thanks for reporting this with Percona bug tracker. It's most appreciated.
Best wishes,
Chris
So, it looks somewhat strange, but Percona says it doesn't work in XtraDB by design: https://bugs.launchpad.net/percona-server/+bug/1158041/comments/1
Sergei,
Do we want to re-design this design, or should I close it as "it is what it is"?
Percona is the vendor, if they say it's intentional, then it's not a bug.
To have lock information, a user should set innodb_show_verbose_locks in the my.cnf file.
Test Case to generate something useful in the output:
Connection #1:
create table t (id int) engine=innodb;
insert into t (id) values (1),(2),(3),(4),(5);
start transaction;
select * from t for update;
Connection #2:
show engine innodb status\G
create table innodb_lock_monitor (id int) engine=innodb;
show engine innodb status\G
drop table innodb_lock_monitor;