Lock deadlock with PXC 5.6
| Affects | Status | Importance | Assigned to | Milestone | ||
|---|---|---|---|---|---|---|
| Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC | ||||||
| 5.6 |
New
|
Undecided
|
Unassigned | |||
Bug Description
=======
2013-09-26 17:51:53 16072 [Note] WSREP: Member 1 (jhc-new-
InnoDB: Warning: a long semaphore wait:
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 241.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 241.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 241.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 241.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 241.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
=======
2013-09-26 17:56:17 7f2816ffb700 INNODB MONITOR OUTPUT
=======
Per second averages calculated from the last 20 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 8 srv_active, 0 srv_shutdown, 20 srv_idle
srv_master_thread log flush and writes: 27
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 103
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 253.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 253.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 253.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 253.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 253.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810056398592 has waited at buf0flu.cc line 1052 for 252.00 seconds the semaphore:
S-lock on RW-latch at 0x7f28235fa9c0 '&block->lock'
a writer (thread id 139810077374208) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.cc line 3232
Last time write locked in file /mnt/workspace/
--Thread 139810098349824 has waited at srv0srv.cc line 2541 for 252.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x1364780 '&dict_
a writer (thread id 139810098349824) has reserved it in mode wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file row0purge.cc line 720
Last time write locked in file /mnt/workspace/
OS WAIT ARRAY INFO: signal count 95
Mutex spin waits 169, rounds 3223, OS waits 72
RW-shared spins 46, rounds 1211, OS waits 16
RW-excl spins 3, rounds 461, OS waits 14
Spin rounds per wait: 19.07 mutex, 26.33 RW-shared, 153.67 RW-excl
FAIL TO OBTAIN LOCK MUTEX, SKIP LOCK INFO PRINTING
--------
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 (write thread)
I/O thread 5 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0] , aio writes: 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
596 OS file reads, 3257 OS file writes, 1957 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
0.00 hash searches/s, 0.00 non-hash searches/s
-------
END OF INNODB MONITOR OUTPUT
=======
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 272.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 272.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 272.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 272.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 272.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810056398592 has waited at buf0flu.cc line 1052 for 271.00 seconds the semaphore:
S-lock on RW-latch at 0x7f28235fa9c0 '&block->lock'
a writer (thread id 139810077374208) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.cc line 3232
Last time write locked in file /mnt/workspace/
InnoDB: Warning: a long semaphore wait:
--Thread 139810098349824 has waited at srv0srv.cc line 2541 for 271.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x1364780 '&dict_
a writer (thread id 139810098349824) has reserved it in mode wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file row0purge.cc line 720
Last time write locked in file /mnt/workspace/
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
=======
2013-09-26 17:56:37 7f2816ffb700 INNODB MONITOR OUTPUT
=======
Per second averages calculated from the last 20 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 8 srv_active, 0 srv_shutdown, 20 srv_idle
srv_master_thread log flush and writes: 27
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 103
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 273.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 273.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 273.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 273.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 273.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810056398592 has waited at buf0flu.cc line 1052 for 272.00 seconds the semaphore:
S-lock on RW-latch at 0x7f28235fa9c0 '&block->lock'
a writer (thread id 139810077374208) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.cc line 3232
Last time write locked in file /mnt/workspace/
--Thread 139810098349824 has waited at srv0srv.cc line 2541 for 272.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x1364780 '&dict_
a writer (thread id 139810098349824) has reserved it in mode wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file row0purge.cc line 720
Last time write locked in file /mnt/workspace/
OS WAIT ARRAY INFO: signal count 95
Mutex spin waits 169, rounds 3223, OS waits 72
RW-shared spins 46, rounds 1211, OS waits 16
RW-excl spins 3, rounds 461, OS waits 14
Spin rounds per wait: 19.07 mutex, 26.33 RW-shared, 153.67 RW-excl
FAIL TO OBTAIN LOCK MUTEX, SKIP LOCK INFO PRINTING
----------
OS WAIT ARRAY INFO: reservation count 103
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 293.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 293.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 293.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 293.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 293.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
--Thread 139810056398592 has waited at buf0flu.cc line 1052 for 292.00 seconds the semaphore:
S-lock on RW-latch at 0x7f28235fa9c0 '&block->lock'
a writer (thread id 139810077374208) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.cc line 3232
Last time write locked in file /mnt/workspace/
--Thread 139810098349824 has waited at srv0srv.cc line 2541 for 292.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x1364780 '&dict_
a writer (thread id 139810098349824) has reserved it in mode wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file row0purge.cc line 720
Last time write locked in file /mnt/workspace/
OS WAIT ARRAY INFO: signal count 95
Mutex spin waits 169, rounds 3223, OS waits 72
RW-shared spins 46, rounds 1211, OS waits 16
RW-excl spins 3, rounds 461, OS waits 14
Spin rounds per wait: 19.07 mutex, 26.33 RW-shared, 153.67 RW-excl
FAIL TO OBTAIN LOCK MUTEX, SKIP LOCK INFO PRINTING
--------
FILE I/O
FAIL TO OBTAIN LOCK MUTEX, SKIP LOCK INFO PRINTING
-------
END OF INNODB MONITOR OUTPUT
=======
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 139810324395776 has waited at ha_innodb.cc line 4309 for 303.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323064576 has waited at lock0lock.cc line 4708 for 303.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810322798336 has waited at lock0lock.cc line 4708 for 303.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810323330816 has waited at lock0lock.cc line 4708 for 303.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810077374208 has waited at lock0lock.cc line 3636 for 303.00 seconds the semaphore:
Mutex at 0x7f282340b088 '&lock_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139810056398592 has waited at buf0flu.cc line 1052 for 302.00 seconds the semaphore:
S-lock on RW-latch at 0x7f28235fa9c0 '&block->lock'
a writer (thread id 139810077374208) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.cc line 3232
Last time write locked in file /mnt/workspace/
=======
Full details here http://
| no longer affects: | percona-xtradb-cluster |
| Raghavendra D Prabhu (raghavendra-prabhu) wrote | #1 |
| Raghavendra D Prabhu (raghavendra-prabhu) wrote | #2 |
Attached backtrace.