MySQL Bugs: #53625: Deadlock with log_output=TABLE, partitioned table, trigger and auto-inc

Bug #53625	Deadlock with log_output=TABLE, partitioned table, trigger and auto-inc
Submitted:	13 May 2010 17:46	Modified:	4 Feb 2011 16:17
Reporter:	Elena Stepanova	Email Updates:
Status:	Won't fix	Impact on me:	None
Category:	MySQL Server: Locking	Severity:	S2 (Serious)
Version:	5.1.49, 5.5.3-m3, 5.6.99	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
- Table tb1_eng1 has AUTO_INCREMENT PK i1 and is partitioned by hash(i1);
- Tables tb1_logs and t1 do not have indexes, partitions, AUTO_INCREMENTs;
- Tables tb1_eng1 and tb1_logs are empty at start, table t1 contains 1 row;
- Trigger after insert on tb1_eng1 writes into tb1_logs.

- several connections execute concurrently the following statement:
INSERT INTO systest1.tb1_eng1 (f1,f2,f3,f4)
SELECT f1, f2, f3, f4
FROM systest1.t1;

If log_output is set to TABLE and STATEMENT-based or MIXED binary log format is used, the flow deadlocks soon after it starts.

Reproducible with InnoDB and MyISAM tables.
Also reproducible on 5.1.40sp1.

In the provided test case, I could not exclude partitions, SBR/MBR, auto-increment and trigger, so am not quite if it belongs to 'Locking', but setting the category to it for now.

How to repeat:
- unpack the attached archive in <mysql-basedir>/mysql-test. It should create
'stress_test_basedir' folder;
- run as
perl ./stress_test_basedir/run.pl

Notes:
run.pl is a wrapper for MTR to start server, and mysql-stress-test
to run a multi-thread stress test.
For mysql-stress-test you need to have perl with threads on the top of your path

Please use
perl ./stress_test_basedir/run.pl --help
for the list of available options (if default configuration is not suitable for you).

STDOUT should contain usual MTR output for server startup
(unless you chose to skip server start), then it will briefly go through
preparation/initialization/configuration stages marked accordingly,
and then will start rapidly producing lines like

test_loop[0:0 0:84]: TID 5 test: 'stress1' Errors: No Errors. Test Passed OK

test_loop[0:0 0:85]: TID 4 test: 'stress1' Errors: No Errors. Test Passed OK

main: Thread ID 6 TID 6 started
ok
test_loop[0:0 0:86]: TID 3 test: 'stress1' Errors: No Errors. Test Passed OK

etc.

If the deadlock is reached, the output stops.
Usually it happens during the first minute of the first attempt, but sometimes it takes 2 or 3 test runs.

If deadlock does not happen, the test finishes in 2 min saying
EXIT
Terminated

bt for all threads

Attachment: 53625_threads.out (application/octet-stream, text), 27.33 KiB.

bt full for all threads

Attachment: 53625_threads_full.out (application/octet-stream, text), 89.33 KiB.

mysql-stress-test-based test

Attachment: 53625_stress_test_basedir.tar.gz (application/gzip, text), 14.38 KiB.

Elena,

starting with 5.5, the performance schema can also provide details about the dead lock.
Have you tried to see:
- what each thread waits for (SELECT * from EVENTS_WAITS_CURRENT)
- who locks each mutex (SELECT * from MUTEX_INSTANCES)
from another connection ?

This will help to narrow down the bug.

Hi Marc,

The problem is that as soon as the deadlock happens, I cannot connect to the server anymore, and if I already have a connection, I cannot execute a query, including those from P_S.

Another note on versions:
with the provided test case, I get the deadlock regularly on 5.5.3-m3 and current 5.5.5, but could not reproduce it so far on 5.5.4-m3.

Not being able to connect and not being able to issue commands is typical for deadlocks where log_output=TABLE, because the log table gets locked out too. The solution is to connect the client before the deadlock has formed and issue SET SESSION log_output=file . SHOW PROCESSLIST and selecting from PERFORMANCE SCHEMA should then work.

I thought about it before, but the manual (http://dev.mysql.com/doc/refman/5.5/en/server-options.html#option_mysqld_log-output) says that the scope of log_output variable is only global, so I did not try. I can still check it out if there is a suspicion it can be set on session level.

Could not reproduce it on the final version of 5.5.5-m3 -- there have been some changes in the area (e.g. WL#5419, bug#50589, etc.), apparently the problem was along with them; not closing it though because it is still easily reproducible on current 5.1.

Issue is addressed in 5.5