Re: MySQL optimization for testing purpose
I don't know how I can give a snapshot of InnoDB status exactly at the right moment...
So far I have re-executed the test 4 times (without restarting the server BTW), and for the run 1, 2 and 3 the test took 5 seconds. At run #4, the test started to slowdown, so I executed 3 consecutive SHOW ENGINE INNODB STATUS in another session, and here are the outputs...
If there is a better way to catch InnoDB status let me know!
I can eventually share my screen and show you live, maybe that will be more efficient.
| InnoDB | |
=====================================
2018-04-09 17:59:04 0x7f543c20f700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 22 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 197 srv_active, 0 srv_shutdown, 8900 srv_idle
srv_master_thread log flush and writes: 9097
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1990
OS WAIT ARRAY INFO: signal count 1946
RW-shared spins 410, rounds 539, OS waits 131
RW-excl spins 214, rounds 2142, OS waits 43
RW-sx spins 3, rounds 22, OS waits 0
Spin rounds per wait: 1.31 RW-shared, 10.01 RW-excl, 7.33 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-04-09 15:37:55 0x7f543c1c8700 Transaction:
TRANSACTION 961232, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 82, OS thread handle 139999762482944, query id 62228 localhost 127.0.0.1 mysuser update
INSERT INTO t192_detail VALUES (?,?)
Foreign key constraint fails for table `test1`.`t192_detail`:
,
CONSTRAINT `t192_detail_ibfk_1` FOREIGN KEY (`ref`) REFERENCES `t192_master` (`id`)
Trying to add in child table, in index ref tuple:
DATA TUPLE: 2 fields;
0: len 4; hex 80000003; asc ;;
1: len 4; hex 800000cb; asc ;;
But in parent table `test1`.`t192_master`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 0000000eaac3; asc ;;
2: len 7; hex 81000001190110; asc ;;
3: len 6; hex 7365636f6e64; asc second;;
------------
TRANSACTIONS
------------
Trx id counter 973816
Purge done for trx's n:o < 973814 undo n:o < 0 state: running but idle
History list length 39
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421474779719520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 973814, ACTIVE 0 sec creating table
4 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 11
MySQL thread id 126, OS thread handle 139999763064576, query id 89324 localhost 127.0.0.1 mysuser creating table
CREATE TABLE t337 ( col1 char(10) )
--------
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)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
1090 OS file reads, 27995 OS file writes, 17299 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 129.81 writes/s, 107.54 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 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 2 buffer(s)
Hash table size 69257, node heap has 3 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 0 buffer(s)
178.63 hash searches/s, 3645.61 non-hash searches/s
---
LOG
---
Log sequence number 1643363900
Log flushed up to 1643363705
Pages flushed up to 1632406448
Last checkpoint at 1632406448
0 pending log flushes, 0 pending chkp writes
11937 log i/o's done, 75.68 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 274857984
Dictionary memory allocated 484739
Buffer pool size 16384
Free buffers 3195
Database pages 13179
Old database pages 4844
Modified db pages 807
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1067, created 12112, written 11268
0.00 reads/s, 74.36 creates/s, 24.36 writes/s
Buffer pool hit rate 1000 / 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: 13179, 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
0 read views open inside InnoDB
Process ID=14874, Main thread ID=139999212459776 , state=sleeping
Number of rows inserted 61522, updated 24813, deleted 53234, read 154650
225.44 inserts/s, 149.08 updates/s, 178.90 deletes/s, 598.15 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
| InnoDB | |
=====================================
2018-04-09 17:59:13 0x7f543c20f700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 9 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 205 srv_active, 0 srv_shutdown, 8900 srv_idle
srv_master_thread log flush and writes: 9105
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2002
OS WAIT ARRAY INFO: signal count 1965
RW-shared spins 417, rounds 547, OS waits 132
RW-excl spins 216, rounds 2202, OS waits 44
RW-sx spins 3, rounds 22, OS waits 0
Spin rounds per wait: 1.31 RW-shared, 10.19 RW-excl, 7.33 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-04-09 15:37:55 0x7f543c1c8700 Transaction:
TRANSACTION 961232, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 82, OS thread handle 139999762482944, query id 62228 localhost 127.0.0.1 mysuser update
INSERT INTO t192_detail VALUES (?,?)
Foreign key constraint fails for table `test1`.`t192_detail`:
,
CONSTRAINT `t192_detail_ibfk_1` FOREIGN KEY (`ref`) REFERENCES `t192_master` (`id`)
Trying to add in child table, in index ref tuple:
DATA TUPLE: 2 fields;
0: len 4; hex 80000003; asc ;;
1: len 4; hex 800000cb; asc ;;
But in parent table `test1`.`t192_master`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 0000000eaac3; asc ;;
2: len 7; hex 81000001190110; asc ;;
3: len 6; hex 7365636f6e64; asc second;;
------------
TRANSACTIONS
------------
Trx id counter 974069
Purge done for trx's n:o < 974069 undo n:o < 0 state: running but idle
History list length 14
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421474779720440, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421474779719520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
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)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 1; buffer pool: 0
1090 OS file reads, 28179 OS file writes, 17426 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 20.44 writes/s, 14.11 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 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 2 buffer(s)
Hash table size 69257, node heap has 3 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 0 buffer(s)
20.00 hash searches/s, 402.07 non-hash searches/s
---
LOG
---
Log sequence number 1643687383
Log flushed up to 1643686380
Pages flushed up to 1633624540
Last checkpoint at 1633233385
1 pending log flushes, 0 pending chkp writes
12018 log i/o's done, 9.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 274857984
Dictionary memory allocated 484739
Buffer pool size 16384
Free buffers 3120
Database pages 13254
Old database pages 4872
Modified db pages 818
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1067, created 12187, written 11342
0.00 reads/s, 8.33 creates/s, 8.22 writes/s
Buffer pool hit rate 1000 / 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: 13254, 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
0 read views open inside InnoDB
Process ID=14874, Main thread ID=139999212459776 , state=sleeping
Number of rows inserted 61741, updated 24963, deleted 53414, read 155254
24.33 inserts/s, 16.66 updates/s, 20.00 deletes/s, 67.10 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
| InnoDB | |
=====================================
2018-04-09 17:59:23 0x7f543c20f700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 10 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 214 srv_active, 0 srv_shutdown, 8900 srv_idle
srv_master_thread log flush and writes: 9113
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2015
OS WAIT ARRAY INFO: signal count 1983
RW-shared spins 420, rounds 551, OS waits 133
RW-excl spins 218, rounds 2239, OS waits 45
RW-sx spins 3, rounds 22, OS waits 0
Spin rounds per wait: 1.31 RW-shared, 10.27 RW-excl, 7.33 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-04-09 15:37:55 0x7f543c1c8700 Transaction:
TRANSACTION 961232, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 82, OS thread handle 139999762482944, query id 62228 localhost 127.0.0.1 mysuser update
INSERT INTO t192_detail VALUES (?,?)
Foreign key constraint fails for table `test1`.`t192_detail`:
,
CONSTRAINT `t192_detail_ibfk_1` FOREIGN KEY (`ref`) REFERENCES `t192_master` (`id`)
Trying to add in child table, in index ref tuple:
DATA TUPLE: 2 fields;
0: len 4; hex 80000003; asc ;;
1: len 4; hex 800000cb; asc ;;
But in parent table `test1`.`t192_master`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 0000000eaac3; asc ;;
2: len 7; hex 81000001190110; asc ;;
3: len 6; hex 7365636f6e64; asc second;;
------------
TRANSACTIONS
------------
Trx id counter 974338
Purge done for trx's n:o < 974338 undo n:o < 0 state: running but idle
History list length 40
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421474779719520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 974333, ACTIVE (PREPARED) 0 sec
14 lock struct(s), heap size 1136, 17 row lock(s), undo log entries 14
MySQL thread id 127, OS thread handle 139999763064576, query id 89978 localhost 127.0.0.1 mysuser checking permissions
DROP TABLE t337
--------
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)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 1; buffer pool: 0
1090 OS file reads, 28402 OS file writes, 17567 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 22.30 writes/s, 14.10 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 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 2 buffer(s)
Hash table size 69257, node heap has 3 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 1 buffer(s)
Hash table size 69257, node heap has 0 buffer(s)
18.80 hash searches/s, 385.96 non-hash searches/s
---
LOG
---
Log sequence number 1644027248
Log flushed up to 1644016577
Pages flushed up to 1634377516
Last checkpoint at 1633895780
1 pending log flushes, 0 pending chkp writes
12107 log i/o's done, 8.90 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 274857984
Dictionary memory allocated 489653
Buffer pool size 16384
Free buffers 3040
Database pages 13334
Old database pages 4902
Modified db pages 772
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1067, created 12267, written 11444
0.00 reads/s, 8.00 creates/s, 10.20 writes/s
Buffer pool hit rate 1000 / 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: 13334, 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
0 read views open inside InnoDB
Process ID=14874, Main thread ID=139999212459776 , state=flushing log
Number of rows inserted 61981, updated 25123, deleted 53606, read 155894
24.00 inserts/s, 16.00 updates/s, 19.20 deletes/s, 63.99 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================