We are running MySQL 5.5.9 on a Dual XEON Server with 8 cores and 120GB of RAM. The tablespace is on a fast SSD Drive.
I was experiencing very low mysql performance while the overall CPU load was under 10% and very low SSD access.
After looking at innodb monitor I lowered innodb_thread_concurrency from 256 to 32. Result: a huge performance boost. Seems the threads were waiting for mutexes most of the time...
My questions are:
Could 32 threads still be to much?
What is a good mutex spin wait/ os wait ratio?
Is it normal to have all I/O threads in state: "wait Windows aio" (I never saw another state)?
Current Settings:
innodb_read_io_threads = 8
innodb_write_io_threads = 8
innodb_thread_concurrency = 32
Thank you very much for your help!
Maurizio
--- APPENDIX ----
Some semaphores innodb monitor outputs:
20 seconds:
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1237274, signal count 1718960
Mutex spin waits 61927390, rounds 88274233, OS waits 1191097
RW-shared spins 292403, rounds 1200748, OS waits 22765
RW-excl spins 30001, rounds 1436869, OS waits 18966
Spin rounds per wait: 1.43 mutex, 4.11 RW-shared, 47.89 RW-excl
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1510828, signal count 1927689
Mutex spin waits 64256205, rounds 98465742, OS waits 1460531
RW-shared spins 313695, rounds 1311507, OS waits 25333
RW-excl spins 32153, rounds 1546598, OS waits 20362
Spin rounds per wait: 1.53 mutex, 4.18 RW-shared, 48.10 RW-excl
This is a full innodb monitor output:
=====================================
110314 13:25:32 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 20 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 11373 1_second, 11372 sleeps, 1124 10_second, 405 background, 405 flush
srv_master_thread log flush and writes: 11464
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1508316, signal count 1925586
Mutex spin waits 64229942, rounds 98364059, OS waits 1458040
RW-shared spins 313502, rounds 1310927, OS waits 25321
RW-excl spins 32136, rounds 1545701, OS waits 20355
Spin rounds per wait: 1.53 mutex, 4.18 RW-shared, 48.10 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 596A0C341
Purge done for trx's n
< 596A0B720 undo n < 0
History list length 205
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 596A0C1C9, not started, OS thread id 208136
MySQL thread id 17697, query id 8151093 localhost ::1 root
---TRANSACTION 596A0C333, not started, OS thread id 20760
MySQL thread id 17610, query id 8151726 localhost ::1 root
---TRANSACTION 596A0B286, not started, OS thread id 285112
MySQL thread id 17570, query id 8144961 localhost ::1 root
---TRANSACTION 596A0BE36, not started, OS thread id 55348
MySQL thread id 17339, query id 8149503 localhost ::1 root
---TRANSACTION 0, not started, OS thread id 84980
MySQL thread id 1791, query id 6569273 localhost ::1 root
---TRANSACTION 59647C428, not started, OS thread id 57584
MySQL thread id 49, query id 1103345 localhost ::1 root
---TRANSACTION 596A0C340, ACTIVE 0 sec, OS thread id 30544 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 0
MySQL thread id 17670, query id 8151743 localhost ::1 root statistics
Select DomainUID from DomainTable Where Domain='http://www.blawsom.com' Limit 1
Trx read view will not see trx with id >= 596A0C341, sees < 596A0863E
---TRANSACTION 596A0863E, ACTIVE 37 sec, OS thread id 140664 fetching rows, thread declared inside InnoDB 395
mysql tables in use 1, locked 1
30867 lock struct(s), heap size 3996088, 8006426 row lock(s)
MySQL thread id 893, query id 8126690 localhost ::1 root Sending data
Replace Into Backlink.2011_10
( SELECT LinkDomainUID, DomainUID, PageUID, Position, DeepLink, Follow, Active, TextUID, Week, WeekRescan, YearRescan FROM Firma.`PagerelationsTable`
WHERE Saved = 99 Limit 20300000, 100000 )
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (read thread)
I/O thread 7 state: wait Windows aio (read thread)
I/O thread 8 state: wait Windows aio (read thread)
I/O thread 9 state: wait Windows aio (read thread)
I/O thread 10 state: wait Windows aio (write thread)
I/O thread 11 state: wait Windows aio (write thread)
I/O thread 12 state: wait Windows aio (write thread)
I/O thread 13 state: wait Windows aio (write thread)
I/O thread 14 state: wait Windows aio (write thread)
I/O thread 15 state: wait Windows aio (write thread)
I/O thread 16 state: wait Windows aio (write thread)
I/O thread 17 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 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
2557122 OS file reads, 162752 OS file writes, 28198 OS fsyncs
86.20 reads/s, 5248 avg bytes/read, 9.05 writes/s, 3.85 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 261426, seg size 261428, 13571 merges
merged operations:
insert 83277, delete mark 459921, delete 58180
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 144498583, node heap has 83577 buffer(s)
94999.75 hash searches/s, 1993.50 non-hash searches/s
---
LOG
---
Log sequence number 9836204638037
Log flushed up to 9836204595512
Last checkpoint at 9835970245764
0 pending log writes, 0 pending chkp writes
11324 log i/o's done, 1.10 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 74725720064; in additional pool allocated 0
Dictionary memory allocated 1012343
Buffer pool size 4456448
Free buffers 1246014
Database pages 2587126
Old database pages 955033
Modified db pages 63332
Pending reads 1
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10964, not young 0
5.65 youngs/s, 0.00 non-youngs/s
Pages read 2556935, created 32065, written 144994
86.20 reads/s, 5.20 creates/s, 6.85 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
LRU len: 2587126, unzip_LRU len: 1446750
I/O sum[4719]:cur[6], unzip sum[5324]:cur[10]
--------------
ROW OPERATIONS
--------------
2 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 140360, state: sleeping
Number of rows inserted 2259224, updated 1561336, deleted 1190, read 2729194687
65.40 inserts/s, 10.85 updates/s, 0.00 deletes/s, 96350.43 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
I was experiencing very low mysql performance while the overall CPU load was under 10% and very low SSD access.
After looking at innodb monitor I lowered innodb_thread_concurrency from 256 to 32. Result: a huge performance boost. Seems the threads were waiting for mutexes most of the time...
My questions are:
Could 32 threads still be to much?
What is a good mutex spin wait/ os wait ratio?
Is it normal to have all I/O threads in state: "wait Windows aio" (I never saw another state)?
Current Settings:
innodb_read_io_threads = 8
innodb_write_io_threads = 8
innodb_thread_concurrency = 32
Thank you very much for your help!
Maurizio
--- APPENDIX ----
Some semaphores innodb monitor outputs:
20 seconds:
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1237274, signal count 1718960
Mutex spin waits 61927390, rounds 88274233, OS waits 1191097
RW-shared spins 292403, rounds 1200748, OS waits 22765
RW-excl spins 30001, rounds 1436869, OS waits 18966
Spin rounds per wait: 1.43 mutex, 4.11 RW-shared, 47.89 RW-excl
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1510828, signal count 1927689
Mutex spin waits 64256205, rounds 98465742, OS waits 1460531
RW-shared spins 313695, rounds 1311507, OS waits 25333
RW-excl spins 32153, rounds 1546598, OS waits 20362
Spin rounds per wait: 1.53 mutex, 4.18 RW-shared, 48.10 RW-excl
This is a full innodb monitor output:
=====================================
110314 13:25:32 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 20 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 11373 1_second, 11372 sleeps, 1124 10_second, 405 background, 405 flush
srv_master_thread log flush and writes: 11464
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1508316, signal count 1925586
Mutex spin waits 64229942, rounds 98364059, OS waits 1458040
RW-shared spins 313502, rounds 1310927, OS waits 25321
RW-excl spins 32136, rounds 1545701, OS waits 20355
Spin rounds per wait: 1.53 mutex, 4.18 RW-shared, 48.10 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 596A0C341
Purge done for trx's n
< 596A0B720 undo n < 0History list length 205
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 596A0C1C9, not started, OS thread id 208136
MySQL thread id 17697, query id 8151093 localhost ::1 root
---TRANSACTION 596A0C333, not started, OS thread id 20760
MySQL thread id 17610, query id 8151726 localhost ::1 root
---TRANSACTION 596A0B286, not started, OS thread id 285112
MySQL thread id 17570, query id 8144961 localhost ::1 root
---TRANSACTION 596A0BE36, not started, OS thread id 55348
MySQL thread id 17339, query id 8149503 localhost ::1 root
---TRANSACTION 0, not started, OS thread id 84980
MySQL thread id 1791, query id 6569273 localhost ::1 root
---TRANSACTION 59647C428, not started, OS thread id 57584
MySQL thread id 49, query id 1103345 localhost ::1 root
---TRANSACTION 596A0C340, ACTIVE 0 sec, OS thread id 30544 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 0
MySQL thread id 17670, query id 8151743 localhost ::1 root statistics
Select DomainUID from DomainTable Where Domain='http://www.blawsom.com' Limit 1
Trx read view will not see trx with id >= 596A0C341, sees < 596A0863E
---TRANSACTION 596A0863E, ACTIVE 37 sec, OS thread id 140664 fetching rows, thread declared inside InnoDB 395
mysql tables in use 1, locked 1
30867 lock struct(s), heap size 3996088, 8006426 row lock(s)
MySQL thread id 893, query id 8126690 localhost ::1 root Sending data
Replace Into Backlink.2011_10
( SELECT LinkDomainUID, DomainUID, PageUID, Position, DeepLink, Follow, Active, TextUID, Week, WeekRescan, YearRescan FROM Firma.`PagerelationsTable`
WHERE Saved = 99 Limit 20300000, 100000 )
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (read thread)
I/O thread 7 state: wait Windows aio (read thread)
I/O thread 8 state: wait Windows aio (read thread)
I/O thread 9 state: wait Windows aio (read thread)
I/O thread 10 state: wait Windows aio (write thread)
I/O thread 11 state: wait Windows aio (write thread)
I/O thread 12 state: wait Windows aio (write thread)
I/O thread 13 state: wait Windows aio (write thread)
I/O thread 14 state: wait Windows aio (write thread)
I/O thread 15 state: wait Windows aio (write thread)
I/O thread 16 state: wait Windows aio (write thread)
I/O thread 17 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 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
2557122 OS file reads, 162752 OS file writes, 28198 OS fsyncs
86.20 reads/s, 5248 avg bytes/read, 9.05 writes/s, 3.85 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 261426, seg size 261428, 13571 merges
merged operations:
insert 83277, delete mark 459921, delete 58180
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 144498583, node heap has 83577 buffer(s)
94999.75 hash searches/s, 1993.50 non-hash searches/s
---
LOG
---
Log sequence number 9836204638037
Log flushed up to 9836204595512
Last checkpoint at 9835970245764
0 pending log writes, 0 pending chkp writes
11324 log i/o's done, 1.10 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 74725720064; in additional pool allocated 0
Dictionary memory allocated 1012343
Buffer pool size 4456448
Free buffers 1246014
Database pages 2587126
Old database pages 955033
Modified db pages 63332
Pending reads 1
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10964, not young 0
5.65 youngs/s, 0.00 non-youngs/s
Pages read 2556935, created 32065, written 144994
86.20 reads/s, 5.20 creates/s, 6.85 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
LRU len: 2587126, unzip_LRU len: 1446750
I/O sum[4719]:cur[6], unzip sum[5324]:cur[10]
--------------
ROW OPERATIONS
--------------
2 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 140360, state: sleeping
Number of rows inserted 2259224, updated 1561336, deleted 1190, read 2729194687
65.40 inserts/s, 10.85 updates/s, 0.00 deletes/s, 96350.43 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
Comment