MySQL Bugs: #73921: mysql deadlocks itself sometimes

Bug #73921	mysql deadlocks itself sometimes
Submitted:	15 Sep 2014 13:32	Modified:	24 May 2018 13:20
Reporter:	Viacheslav Romanov	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:	5.5.34	OS:	Linux (Ubuntu)
Assigned to:		CPU Architecture:	Any
Tags:	hangs

Description:
I am running a mysql server for almost a year, and a month ago it started to freeze once in 2-3 days with bunch of semaphores waiting for the locks. I think it is a bug in mysql because I do not use transactions - only single line queries (selects or updates or inserts).

I have mysql server monitored by zabbix - and it has no clues what is going on. I've tried to tweak several things - like now I switched off adaptive hash index, but it have not helped yet.

How it can be I have deadlock without having transactions?

How to repeat:
I don't know, it occurs under the normal or high load. But recently it hangs only at evening times - at the highest load level.

I am having server that runs a lot of simple request like this:
1) select * from users where userId = 222;
2) update users set name='dfdf' where userId = 333;
3) insert into users values (444, 'hello')

Number of rows inserted 4734264766, updated 27816634675, deleted 1054032407, read 801227142950
12.42 inserts/s, 83.50 updates/s, 0.03 deletes/s, 658.40 reads/

Start of SHOW ENGINE INNODB STATUS

*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
140914 23:28:40 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 36 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 21893011 1_second, 21892880 sleeps, 2189285 10_second, 15091 background, 15091 flush
srv_master_thread log flush and writes: 22098576
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2904643908, signal count 1609487365
--Thread 139583144167168 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583333746432 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583292086016 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583524013824 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583399978752 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139595676866304 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583503140608 has waited at que0que.c line 1344 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583274624768 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583418042112 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
wait has ended
--Thread 139583505549056 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583298909952 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583497721600 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
wait has ended
--Thread 139595652982528 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583427475200 has waited at trx0trx.c line 845 for 1.00 seconds the semaphore:
Mutex at 0x7f07d06ad8e0 created file trx0rseg.c line 210, lock var 1
waiters flag 1
--Thread 139583242712832 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583373084416 has waited at lock0lock.c line 4005 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583439918848 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583604496128 has waited at trx0trx.c line 1112 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583527626496 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583453566720 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139595363706624 has waited at trx0trx.c line 931 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583309260544 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583331137280 has waited at trx0trx.c line 1112 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583494108928 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583300916992 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583492904704 has waited at trx0trx.c line 1112 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583349802752 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583590647552 has waited at trx0undo.c line 1758 for 4.00 seconds the semaphore:
Mutex at 0x7f07d0674120 created file trx0rseg.c line 210, lock var 1
waiters flag 1
--Thread 139596725970688 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
wait has ended
--Thread 139583302924032 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583230871296 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583430084352 has waited at trx0trx.c line 754 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
--Thread 139583593858816 has waited at trx0trx.c line 1684 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
wait has ended
--Thread 139583236089600 has waited at trx0trx.c line 931 for 0.00 seconds the semaphore:
Mutex at 0x7f076f3ab278 created file srv0srv.c line 1024, lock var 1
waiters flag 0
wait has ended
--Thread 139583289476864 has waited at trx0trx.c line 861 for 1.00 seconds the semaphore:
Mutex at 0x7f07d0680f60 created file trx0rseg.c line 210, lock var 1
waiters flag 1

End of semaphores section:

--Thread 139596734600960 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583313475328 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583111251712 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583456376576 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583216219904 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583184709376 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583228462848 has waited at btr0cur.c line 535 for 2.00 seconds the semaphore:
S-lock on RW-latch at 0x7ef4c4230338 created in file dict0dict.c line 1838
a writer (thread id 139583383521024) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0cur.c line 535
Last time write locked in file /build/buildd/mysql-5.5-5.5.34/storage/innobase/btr/btr0cur.c line 528
--Thread 139583295297280 has waited at trx0undo.c line 1758 for 1.00 seconds the semaphore:
Mutex at 0x7f07d0679cc0 created file trx0rseg.c line 210, lock var 1
waiters flag 1
Mutex spin waits 154788061942, rounds 460879911043, OS waits 2400383865
RW-shared spins 695257164, rounds 10020057339, OS waits 269461680
RW-excl spins 195901709, rounds 7586466350, OS waits 150625032
Spin rounds per wait: 2.98 mutex, 14.41 RW-shared, 38.73 RW-excl

Thank you for the report.

Looks like I missed it in September. Is this same issue which you wrote about to Moscow-MUG mailing list? If yes, can you confirm that increasing innodb_io_capacity helped and we can close the report?

Hi!

Increasing innodb_io_capacity = 2000 helped for 4 months)

Now I have the same problem - I increased innodb_io_capacity once again to 8000, and switching to file_per_table.

Hope this will help

Are you tried with high version than 5.5 i.e: 5.7?. Thanks.

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".