Freezes with "has waited at buf0buf.c line 2529 for XXX seconds the semaphore" errors
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona Server moved to https://jira.percona.com/projects/PS |
Fix Released
|
Critical
|
Stewart Smith | ||
5.1 |
Invalid
|
Undecided
|
Unassigned | ||
5.5 |
Fix Released
|
Critical
|
Stewart Smith |
Bug Description
Almost daily my Percona MySQL Server is freezing and I have to kill -9 all processes and restart the server since normal kill or shutdown doesn't work. The server runs 25GB database (mostly InnoDB). It happens usually at night and the only thing that comes to mind is the backup of databases and r1soft cdp backup which I do nightly.
mysqladmin processlist shows many waiting processes and one with "Waiting for table metadata lock" status.
mysqlbug output:
--- CUT ---
Server version 5.5.24-55
Protocol version 10
Connection Localhost via UNIX socket
UNIX socket /var/run/
Uptime: 1 day 7 min 46 sec
Threads: 301 Questions: 9526676 Slow queries: 206 Opens: 2391 Flush tables: 1 Open tables: 1148 Queries per second avg: 109.670
>C compiler: gcc (Debian 4.4.5-8) 4.4.5
>C++ compiler: gcc (Debian 4.4.5-8) 4.4.5
>Environment:
<machine, os, target, libraries (multiple lines)>
System: Linux xxx.xxx 2.6.32-5-amd64 #1 SMP Sun May 6 04:00:17 UTC 2012 x86_64 GNU/Linux
Some paths: /usr/bin/perl /usr/bin/make /usr/bin/gcc /usr/bin/cc
GCC: Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-
Thread model: posix
gcc version 4.4.5 (Debian 4.4.5-8)
Compilation info (call): CC='/usr/bin/gcc' CFLAGS='-g -O2 -fPIC -Wall -O3 -g -static-libgcc -fno-omit-
Compilation info (used): CC='/usr/bin/gcc' CFLAGS='-g -O2 -fPIC -Wall -O3 -g -static-libgcc -fno-omit-
LIBC:
lrwxrwxrwx 1 root root 14 Jun 25 09:32 /lib/libc.so.6 -> libc-2.11.3.so
-rwxr-xr-x 1 root root 1437064 Feb 12 20:12 /lib/libc-2.11.3.so
-rw-r--r-- 1 root root 4439052 Feb 12 20:12 /usr/lib/libc.a
-rw-r--r-- 1 root root 247 Feb 12 20:10 /usr/lib/libc.so
--- CUT ---
Error log:
--- CUT ---
InnoDB: Warning: a long semaphore wait:
--Thread 140476551141120 has waited at dict0dict.c line 744 for 241.00 seconds the semaphore:
Mutex at 0x2279ec38 '&dict_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 140476533987072 has waited at buf0buf.c line 2529 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
=======
120720 4:00:47 INNODB MONITOR OUTPUT
=======
Per second averages calculated from the last 38 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 62511 1_second, 62263 sleeps, 6229 10_second, 251 background, 251 flush
srv_master_thread log flush and writes: 85222
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 35233, signal count 94778
--Thread 140476551141120 has waited at dict0dict.c line 744 for 253.00 seconds the semaphore:
Mutex at 0x2279ec38 '&dict_sys->mutex', lock var 1
waiters flag 1
--Thread 140476533987072 has waited at buf0buf.c line 2529 for 253.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476565554944 has waited at buf0buf.c line 2529 for 252.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476213966592 has waited at buf0buf.c line 2529 for 251.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476548933376 has waited at buf0buf.c line 2529 for 245.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476527363840 has waited at buf0buf.c line 2529 for 244.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476513515264 has waited at buf0buf.c line 2529 for 235.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476533786368 has waited at buf0buf.c line 2529 for 235.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476520339200 has waited at buf0buf.c line 2529 for 225.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476524152576 has waited at buf0buf.c line 2529 for 225.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476300654336 has waited at buf0buf.c line 2529 for 224.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476300453632 has waited at buf0buf.c line 2529 for 222.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476219385600 has waited at buf0buf.c line 2529 for 222.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140497213142784 has waited at buf0buf.c line 2529 for 221.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476216575744 has waited at buf0buf.c line 2529 for 221.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476219987712 has waited at buf0buf.c line 2529 for 218.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476548732672 has waited at buf0buf.c line 2529 for 217.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476218984192 has waited at buf0buf.c line 2529 for 214.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476219184896 has waited at buf0buf.c line 2529 for 213.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476215772928 has waited at buf0buf.c line 2529 for 209.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476218181376 has waited at buf0buf.c line 2529 for 200.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476518532864 has waited at buf0buf.c line 2529 for 84.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476520740608 has waited at buf0buf.c line 2529 for 32.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476529370880 has waited at buf0buf.c line 2529 for 31.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476531377920 has waited at buf0buf.c line 2529 for 25.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476536194816 has waited at buf0buf.c line 2529 for 24.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476531980032 has waited at buf0buf.c line 2529 for 21.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476538402560 has waited at buf0buf.c line 2529 for 17.000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
--Thread 140476526360320 has waited at buf0buf.c line 2529 for 8.0000 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
Mutex spin waits 291401, rounds 415500, OS waits 4104
RW-shared spins 47145, rounds 769368, OS waits 23733
RW-excl spins 11868, rounds 338903, OS waits 7174
Spin rounds per wait: 1.43 mutex, 16.32 RW-shared, 28.56 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
918443 OS file reads, 2096575 OS file writes, 196710 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 12, seg size 14, 3033 merges
merged operations:
insert 9053, delete mark 1086, delete 81
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 38249647, node heap has 24414 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 93233771103
Log flushed up to 93233771103
Last checkpoint at 93233771103
Max checkpoint age 6720677
Checkpoint age target 6510656
Modified age 0
Checkpoint age 0
0 pending log writes, 0 pending chkp writes
830472 log i/o's done, 0.00 log i/o's/second
-------
BUFFER POOL AND MEMORY
-------
Total memory allocated 19855835136; in additional pool allocated 0
Internal hash tables (constant factor + variable factor)
Adaptive hash index 706000368 (305997176 + 400003192)
Page hash 19125592 (buffer pool 0 only)
Dictionary cache 77734832 (76501168 + 1233664)
File system 160112 (82672 + 77440)
Lock system 47847008 (47812792 + 34216)
Recovery system 0 (0 + 0)
Dictionary memory allocated 1233664
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 140476551141120 has waited at dict0dict.c line 744 for 272.00 seconds the semaphore:
Mutex at 0x2279ec38 '&dict_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 140476533987072 has waited at buf0buf.c line 2529 for 272.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476565554944 has waited at buf0buf.c line 2529 for 271.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476213966592 has waited at buf0buf.c line 2529 for 270.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476548933376 has waited at buf0buf.c line 2529 for 264.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476527363840 has waited at buf0buf.c line 2529 for 263.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476513515264 has waited at buf0buf.c line 2529 for 254.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476533786368 has waited at buf0buf.c line 2529 for 254.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476520339200 has waited at buf0buf.c line 2529 for 244.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476524152576 has waited at buf0buf.c line 2529 for 244.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476300654336 has waited at buf0buf.c line 2529 for 243.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476300453632 has waited at buf0buf.c line 2529 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476219385600 has waited at buf0buf.c line 2529 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
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 140476551141120 has waited at dict0dict.c line 744 for 303.00 seconds the semaphore:
Mutex at 0x2279ec38 '&dict_sys->mutex', lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 140476533987072 has waited at buf0buf.c line 2529 for 303.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476565554944 has waited at buf0buf.c line 2529 for 302.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476213966592 has waited at buf0buf.c line 2529 for 301.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476548933376 has waited at buf0buf.c line 2529 for 295.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476527363840 has waited at buf0buf.c line 2529 for 294.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476513515264 has waited at buf0buf.c line 2529 for 285.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476533786368 has waited at buf0buf.c line 2529 for 285.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476520339200 has waited at buf0buf.c line 2529 for 275.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476524152576 has waited at buf0buf.c line 2529 for 275.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476300654336 has waited at buf0buf.c line 2529 for 274.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476300453632 has waited at buf0buf.c line 2529 for 272.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476219385600 has waited at buf0buf.c line 2529 for 272.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140497213142784 has waited at buf0buf.c line 2529 for 271.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476216575744 has waited at buf0buf.c line 2529 for 271.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476219987712 has waited at buf0buf.c line 2529 for 268.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476548732672 has waited at buf0buf.c line 2529 for 267.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476218984192 has waited at buf0buf.c line 2529 for 264.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476219184896 has waited at buf0buf.c line 2529 for 263.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476215772928 has waited at buf0buf.c line 2529 for 259.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
InnoDB: Warning: a long semaphore wait:
--Thread 140476218181376 has waited at buf0buf.c line 2529 for 250.00 seconds the semaphore:
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
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
120720 4:09:41 [Warning] Too many connections
120720 4:23:23 [Warning] Too many connections
120720 4:26:56 [Warning] Too many connections
120720 4:27:07 [Warning] Too many connections
120720 4:27:09 [Warning] Too many connections
120720 4:27:17 [Warning] Too many connections
120720 4:27:18 [Warning] Too many connections
120720 4:27:23 [Warning] Too many connections
120720 4:27:24 [Warning] Too many connections
120720 4:27:25 [Warning] Too many connections
120720 4:27:26 [Warning] Too many connections
120720 4:27:44 [Warning] Too many connections
120720 4:27:48 [Warning] Too many connections
120720 4:27:50 [Warning] Too many connections
120720 4:27:50 [Warning] Too many connections
120720 4:27:52 [Warning] Too many connections
120720 4:27:53 [Warning] Too many connections
120720 4:27:58 [Warning] Too many connections
120720 4:27:58 [Warning] Too many connections
120720 4:28:00 [Warning] Too many connections
120720 4:28:02 [Warning] Too many connections
120720 4:28:02 [Warning] Too many connections
120720 5:06:28 [Warning] Too many connections
120720 5:13:51 [Warning] Too many connections
120720 5:19:12 [Warning] Too many connections
--- CUT ---
my.cnf:
--- CUT ---
[client]
port = 3306
socket = /var/run/
[mysqld_safe]
socket = /var/run/
nice = 0
[mysqld]
user = mysql
pid-file = /var/run/
socket = /var/run/
port = 3306
basedir = /usr
datadir = /var/lib/mysql
tmpdir = /tmp
language = /usr/share/
skip-external-
key_buffer = 32M
thread_stack = 192K
thread_cache_size = 8
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_flush_method = O_DIRECT
transaction-
innodb_
table_open_cache = 8000
sort_buffer_size = 32M
join_buffer_size = 16M
tmp_table_size = 512M
max_heap_table_size = 512M
max_connections = 300
max_allowed_packet = 64M
query_cache_limit = 1M
query_cache_size = 128M
expire_logs_days = 10
max_binlog_size = 100M
[mysqldump]
quick
quote-names
max_allowed_packet = 16M
[mysql]
[isamchk]
key_buffer = 16M
!includedir /etc/mysql/conf.d/
--- CUT ---
Related branches
- Alexey Kopytov (community): Needs Information
- Laurynas Biveinis (community): Needs Information
-
Diff: 55 lines (+15/-6)1 file modifiedPercona-Server/storage/innobase/buf/buf0lru.c (+15/-6)
tags: | added: contribution |
This looks like a bug in non-lazy drop of table -- lock ordering is not preserved leading to deadlock (I presume you have tables being dropped around the time? ).
Does adding innodb_ lazy_drop_ table=ON (it is also dynamic, so no need to restart server) help?
Regarding the lock wait itself (in non lazy situation):
--Thread 140476533987072 has waited at buf0buf.c line 2529 for 303.00 seconds the semaphore: >page_hash_ latch' workspace/ percona- server- 5.5-debs/ label_exp/ debian6- 64/target/ Percona- Server- 5.5.24- rel26.0/ storage/ innobase/ buf/buf0lru. c line 629
S-lock on RW-latch at 0x416f048 '&buf_pool-
a writer (thread id 140476533987072) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0buf.c line 2529
Last time write locked in file /home/jenkins/
Both the waiter and the thread waited upon are same - 140476533987072. The reason being drop table path (buf0lru.c:629) also has buf0buf.c:2529 in it -- the root being buf_LRU_ remove_ all_pages for both.
In other words,
at buf0buf.c:2529 in buf_page_get_gen:
rw_lock_ s_lock( &buf_pool- >page_hash_ latch); --> it is already holding X-latch here, which it acquired at buf0lru.c:629
In btr_search_ drop_page_ hash_when_ freed, they are already accounting for this kind of lock ordering but they are checking only for block->lock I believe.
"""
/* If the caller has a latch on the page, then the caller must
have a x-latch on the page and it must have already dropped
the hash index for the page. Because of the x-latch that we
are possibly holding, we cannot s-latch the page, but must
(recursively) x-latch it, even though we are only reading. */
"""