[MDEV-7352] main.kill_processlist-6619 fails sporadically in buildbot Created: 2014-12-19  Updated: 2015-01-23  Resolved: 2015-01-23

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.0
Fix Version/s: 10.0.16

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Kristian Nielsen
Resolution: Fixed Votes: 0
Labels: buildbot, tests

Issue Links:
Relates
relates to MDEV-7069 Fix buildbot failures in main server ... Stalled

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-deb-trusty-x86/builds/635/steps/test_4/logs/stdio

main.kill_processlist-6619               w4 [ fail ]
        Test ended at 2014-12-19 09:24:08
 
CURRENT_TEST: main.kill_processlist-6619
--- /usr/share/mysql/mysql-test/r/kill_processlist-6619.result	2014-12-19 07:30:49.000000000 +0000
+++ /run/shm/var/4/log/kill_processlist-6619.reject	2014-12-19 09:24:08.017590004 +0000
@@ -10,5 +10,5 @@
 ERROR 70100: Query execution was interrupted
 SHOW PROCESSLIST;
 Id	User	Host	db	Command	Time	State	Info	Progress
-#	root	#	test	Sleep	#	#	NULL	0.000
+#	root	#	test	Query	#	#	KILL QUERY 1638	0.000
 #	root	#	test	Query	#	#	SHOW PROCESSLIST	0.000
 
mysqltest: Result length mismatch

Happened twice in a few months, so it's very rare.



 Comments   
Comment by Kristian Nielsen [ 2015-01-23 ]

This patch makes the failure easy to reproduce:

=== modified file 'mysql-test/r/kill_processlist-6619.result'
--- mysql-test/r/kill_processlist-6619.result	2015-01-19 13:07:41 +0000
+++ mysql-test/r/kill_processlist-6619.result	2015-01-23 12:23:34 +0000
@@ -3,6 +3,8 @@ SHOW PROCESSLIST;
 Id	User	Host	db	Command	Time	State	Info	Progress
 #	root	#	test	Sleep	#	#	NULL	0.000
 #	root	#	test	Query	#	#	SHOW PROCESSLIST	0.000
+SET @old_dbug= @@debug_dbug;
+SET debug_dbug="+d,inject_knielsen";
 SET DEBUG_SYNC='before_execute_sql_command WAIT_FOR go';
 SHOW PROCESSLIST;
 connection default;
@@ -10,6 +12,8 @@ KILL QUERY con_id;
 SET DEBUG_SYNC='now SIGNAL go';
 connection con1;
 ERROR 70100: Query execution was interrupted
+SET debug_dbug= @old_dbug;
+SET DEBUG_SYNC='reset';
 SHOW PROCESSLIST;
 Id	User	Host	db	Command	Time	State	Info	Progress
 #	root	#	test	Sleep	#	#	NULL	0.000
 
=== modified file 'mysql-test/t/kill_processlist-6619.test'
--- mysql-test/t/kill_processlist-6619.test	2015-01-19 13:07:41 +0000
+++ mysql-test/t/kill_processlist-6619.test	2015-01-23 12:23:02 +0000
@@ -9,6 +9,8 @@
 --let $con_id = `SELECT CONNECTION_ID()`
 --replace_column 1 # 3 # 6 # 7 #
 SHOW PROCESSLIST;
+SET @old_dbug= @@debug_dbug;
+SET debug_dbug="+d,inject_knielsen";
 SET DEBUG_SYNC='before_execute_sql_command WAIT_FOR go';
 send SHOW PROCESSLIST;
 --connection default
@@ -18,5 +20,7 @@ SET DEBUG_SYNC='now SIGNAL go';
 --connection con1
 --error ER_QUERY_INTERRUPTED
 reap;
+SET debug_dbug= @old_dbug;
+SET DEBUG_SYNC='reset';
 --replace_column 1 # 3 # 6 # 7 #
 SHOW PROCESSLIST;
 
=== modified file 'sql/sql_parse.cc'
--- sql/sql_parse.cc	2015-01-21 11:03:02 +0000
+++ sql/sql_parse.cc	2015-01-23 12:35:39 +0000
@@ -1124,6 +1124,7 @@ bool dispatch_command(enum enum_server_c
   thd->enable_slow_log= TRUE;
   thd->query_plan_flags= QPLAN_INIT;
   thd->lex->sql_command= SQLCOM_END; /* to avoid confusing VIEW detectors */
+DBUG_EXECUTE_IF("inject_knielsen", my_sleep(50000););
   thd->reset_kill_query();
 
   DEBUG_SYNC(thd,"dispatch_command_before_set_time");
 

So it seems that the problem happens when the connection con1 is delayed for
some reason. Then the KILL sent by the default connection is reset at the
start of the SHOW PROCESSLIST query.

Comment by Kristian Nielsen [ 2015-01-23 ]

http://lists.askmonty.org/pipermail/commits/2015-January/007323.html

Generated at Thu Feb 08 07:18:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.