pt-sift doesnot seem to calculate the right mutexes
| Affects | Status | Importance | Assigned to | Milestone | |
|---|---|---|---|---|---|
| Percona Toolkit moved to https://jira.percona.com/projects/PT |
Confirmed
|
Undecided
|
Unassigned | ||
Bug Description
pt-sift displays something like this:
--innodb--
txns: 84xLOCK WAIT (405s) 163xACTIVE (9892s) 36xnot (0s)
0 queries inside InnoDB, 0 queries in queue
Main thread: making checkpoint, pending reads 1, writes 0, flush 0
Log: lsn = 36623175066868, chkp = 36622450173415, chkp age = 724893453
Threads are waiting at:
32 trx0trx.c line 790
7 trx0trx.c line 1767
3 trx0trx.c line 1179
2 trx0trx.c line 223
2 row0sel.c line 3075
2 row0ins.c line 2008
2 lock0lock.c line 5120
1 trx0trx.c line 2137
1 trx0trx.c line 2114
1 trx0purge.c line 391
1 row0sel.c line 4801
1 lock0lock.c line 5350
1 btr0pcur.c line 426
1 btr0cur.c line 546
Threads are waiting on:
2 X-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
2 S-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
1 S-lock on RW-latch at 0x2aaaee043638 '&block->lock'
while inndobstatus1 and innodbstatus2 contains a lot of &kernel_mutex semaphore waits:
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 13055816227, signal count 3164232053
--Thread 1264777536 has waited at btr0cur.c line 546 for 0.0000 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x2ab72a741a08 '&new_index->lock'
a writer (thread id 1264777536) has reserved it in mode wait exclusive
number of readers 5, waiters flag 0, lock_word: fffffffffffffffb
Last time read locked in file btr0cur.c line 553
Last time write locked in file /home/buildbot/
--Thread 1315363136 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1268771136 has waited at row0ins.c line 2008 for 0.0000 seconds the semaphore:
X-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
a writer (thread id 1288206656) has reserved it in mode exclusive
number of readers 0, waiters flag 0, lock_word: 0
Last time read locked in file row0sel.c line 3075
Last time write locked in file /home/buildbot/
--Thread 1272232256 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1346513216 has waited at lock0lock.c line 5120 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1348110656 has waited at row0ins.c line 2008 for 0.0000 seconds the semaphore:
X-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
a writer (thread id 1288206656) has reserved it in mode exclusive
number of readers 0, waiters flag 0, lock_word: 0
Last time read locked in file row0sel.c line 3075
Last time write locked in file /home/buildbot/
--Thread 1351838016 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1345182016 has waited at trx0trx.c line 2114 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1326278976 has waited at trx0purge.c line 391 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1281816896 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1285544256 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1348376896 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1333467456 has waited at trx0trx.c line 2137 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1316960576 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1327343936 has waited at row0sel.c line 4801 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1345714496 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1334266176 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1280751936 has waited at row0sel.c line 3075 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
a writer (thread id 1288206656) has reserved it in mode exclusive
number of readers 0, waiters flag 0, lock_word: 0
Last time read locked in file row0sel.c line 3075
Last time write locked in file /home/buildbot/
--Thread 1298323776 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1343052096 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1269303616 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1306310976 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1293265216 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1310038336 has waited at lock0lock.c line 5120 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1341987136 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1306044736 has waited at trx0trx.c line 223 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1272498496 has waited at row0sel.c line 3075 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x2aaaaefc91b8 '&block->lock'
a writer (thread id 1288206656) has reserved it in mode exclusive
number of readers 0, waiters flag 0, lock_word: 0
Last time read locked in file row0sel.c line 3075
Last time write locked in file /home/buildbot/
--Thread 1297791296 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1339857216 has waited at trx0trx.c line 223 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1341188416 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1311369536 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1305512256 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1344915776 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1273297216 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1349441856 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1300719936 has waited at trx0trx.c line 1179 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1324415296 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1328675136 has waited at trx0trx.c line 1179 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1340123456 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1291934016 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1303648576 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1332668736 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1318025536 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1297525056 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1277024576 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1295661376 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1330006336 has waited at trx0trx.c line 1767 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1278089536 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1348909376 has waited at lock0lock.c line 5350 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1307375936 has waited at btr0pcur.c line 426 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x2aaaee043638 '&block->lock'
a writer (thread id 1346513216) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.c line 3075
Last time write locked in file /home/buildbot/
--Thread 1349175616 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1295395136 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1268504896 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1338526016 has waited at trx0trx.c line 1179 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1337461056 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1330272576 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
--Thread 1294596416 has waited at trx0trx.c line 790 for 0.0000 seconds the semaphore:
Mutex at 0x1905aa18 '&kernel_mutex', lock var 1
waiters flag 0
Mutex spin waits 16210335455, rounds 431570432038, OS waits 10966433915
RW-shared spins 1483243861, rounds 37761580946, OS waits 1040814371
RW-excl spins 239209004, rounds 29473436626, OS waits 888212940
Spin rounds per wait: 26.62 mutex, 25.46 RW-shared, 123.21 RW-excl
| tags: | added: pt-sift wrong-output |
| Changed in percona-toolkit: | |
| status: | New → Confirmed |
| Shahriyar Rzayev (rzayev-sehriyar) wrote | #1 |
Percona now uses JIRA for bug reports so this bug report is migrated to: https:/