Comment 5 for bug 1040735

Revision history for this message
Joern Heissler (joernheissler) wrote :

I'm running "percona-server-server-5.5 5.5.27-rel28.0-291.precise" on ubuntu 12.04, 64 bit.

The server runs in slave mode and only replicates, no other load.

The query which is currently being replicated looks like this:
INSERT INTO `sometable` (columms...) VALUES (...),... ON DUPLICATE KEY UPDATE some stuff;

Symptoms: Query got stuck, other queries won't get executed but hang. (show slave status, show processlist are the only exceptions), eventually all connections are used up. Only little CPU load, maybe from replication thread which download logs.

Similar problems happened with 5.5.25, there it was "TRUNCATE TABLE" or "DROP TABLE" iirc.

Another slave running "5.5.24-rel26.0-256.precise" seems to be stable. I downgraded to see if it helps.

InnoDB: Warning: a long semaphore wait:
--Thread 139685069317888 has waited at buf0lru.c line 1102 for 241.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619390080768 has waited at buf0flu.c line 1887 for 241.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619381688064 has waited at buf0lru.c line 1102 for 241.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0

=====================================
120826 9:20:05 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 15 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2355 1_second, 2283 sleeps, 227 10_second, 4171 background, 4170 flush
srv_master_thread log flush and writes: 3317
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 98450, signal count 319060
--Thread 139685069317888 has waited at buf0lru.c line 1102 for 248.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
--Thread 139619390080768 has waited at buf0flu.c line 1887 for 248.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
--Thread 139619381688064 has waited at buf0lru.c line 1102 for 248.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
Mutex spin waits 1025363, rounds 2430593, OS waits 40278
RW-shared spins 388510, rounds 4354413, OS waits 28770
RW-excl spins 124035, rounds 2089687, OS waits 20762
Spin rounds per wait: 2.37 mutex, 11.21 RW-shared, 16.85 RW-excl
--------
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, 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
1497638 OS file reads, 1766767 OS file writes, 65253 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 6071, seg size 6073, 12305 merges
merged operations:
 insert 13945, delete mark 242250, delete 2960
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 123248603, node heap has 81590 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 3250958542457
Log flushed up to 3250958542184
Last checkpoint at 3250196518412
Max checkpoint age 869019772
Checkpoint age target 841862905
Modified age 759564708
Checkpoint age 762024045
0 pending log writes, 0 pending chkp writes
493077 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 63979913216; in additional pool allocated 0
Internal hash tables (constant factor + variable factor)
    Adaptive hash index 2322763600 (985988824 + 1336774776)
    Page hash 15406904 (buffer pool 0 only)
    Dictionary cache 247027308 (246498992 + 528316)
    File system 207192 (82672 + 124520)
    Lock system 154062000 (154061624 + 376)
    Recovery system 0 (0 + 0)
Dictionary memory allocated 528316

InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 139685069317888 has waited at buf0lru.c line 1102 for 272.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619390080768 has waited at buf0flu.c line 1887 for 272.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619381688064 has waited at buf0lru.c line 1102 for 272.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 139685069317888 has waited at buf0lru.c line 1102 for 303.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619390080768 has waited at buf0flu.c line 1887 for 303.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 139619381688064 has waited at buf0lru.c line 1102 for 303.00 seconds the semaphore:
Mutex at 0x2f0e3f8 '&buf_pool->mutex', lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
InnoDB: ###### Diagnostic info printed to the standard error stream

Any more information I can provide on this?