MySQL Bugs: #39851: race between check_testcase and tests running 'show processlist'

Bug #39851	race between check_testcase and tests running 'show processlist'
Submitted:	4 Oct 2008 8:27	Modified:	30 Jan 2009 17:35
Reporter:	Sven Sandberg	Email Updates:
Status:	Closed	Impact on me:	None
Category:	Tests	Severity:	S7 (Test Cases)
Version:	5.1-rpl	OS:	Any
Assigned to:	Sven Sandberg	CPU Architecture:	Any
Tags:	51rpl, check_testcase, mtr, pushbuild, test failure

Description:
pushbuild failure in main.not_embedded_server:

main.not_embedded_server                 [ fail ]

CURRENT_TEST: main.not_embedded_server
--- /data0/pushbuild/pb/bzr_mysql-5.1-rpl/48/mysql-5.1.28-pb48/mysql-test/r/not_embedded_server.result	2008-09-05 18:37:26.000000000 +0300
+++ /data0/pushbuild/pb/bzr_mysql-5.1-rpl/48/mysql-5.1.28-pb48/mysql-test/r/not_embedded_server.reject	2008-09-05 20:17:21.000000000 +0300
@@ -2,6 +2,7 @@
 execute stmt1;
 ID	USER	HOST	DB	COMMAND	TIME	STATE	INFO
 number	root	localhost	test	Query	time	executing	SELECT * FROM INFORMATION_SCHEMA.PROCESSLIST WHERE COMMAND!='Daemon'
+number	root	localhost	NULL	Query	time	Writing to net	call mtr.check_testcase()
 deallocate prepare stmt1;
 FLUSH STATUS;
 Value of com_select did not change

mysqltest: Result length mismatch

 - saving '/dev/shm/var-n_mix-120/4/log/main.not_embedded_server/' to '/dev/shm/var-n_mix-120/log/main.not_embedded_server/'

Retrying test, attempt(2/3)...

How to repeat:
https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-rpl&order=48 'sapsrv2' -max/n_mix

Suggested fix:
The underlying reason is that a query issued by check-testcase.test (executed automatically by mtr) sends ack before the process stops. So there is a race in test cases that run "SHOW PROCESSLIST".

Tests should not need to be aware of mtr's internal commands. Here is a suggested patch that makes mtr's check-testcase behave nicer:

=== modified file 'mysql-test/include/check-testcase.test'
--- mysql-test/include/check-testcase.test	2008-04-09 10:27:39 +0000
+++ mysql-test/include/check-testcase.test	2008-10-04 08:23:21 +0000
@@ -9,6 +9,9 @@
 #
 --disable_query_log
 call mtr.check_testcase();
+while (`SHOW PROCESSLIST WHERE COMMAND = 'call mtr.check_testcase()'`) {  
+  sleep 0.1;
+}
 --enable_query_log

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/55305

2668 Sven Sandberg	2008-10-04
      BUG#39851: race between check_testcase and tests running 'show processlist'
      Problem: check_testcase executes a query to the server. Subsequent test cases may
      run SHOW PROCESSLIST, which may print the process executing the query (the query
      sends 'ack' to the client before the process dies). So there is a race.
      Fix: check_testcase should wait until the process is dead.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/55311

2668 Sven Sandberg	2008-10-04
      BUG#39851: race between check_testcase and tests running 'show processlist'
      Problem: check_testcase executes a query to the server. Subsequent test cases
      that run SHOW PROCESSLIST may print the process executing the query (the query
      sends 'ack' to the client before the process dies). So there is a race.
      Fix: check_testcase should wait until the process is dead.

Not approved, would probably just lead to another query shoing up in SHOW PROCESSLIST

Discussed on IRC and concluded to remove the part of the test case that causes thi, since it's not testing what it's supposed to anyway.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/56524

2682 Sven Sandberg	2008-10-18
      BUG#39851: race between check_testcase and tests running 'show processlist'
      Problem 1: not_embedded_server runs SELECT FROM I_S.PROCESSLIST near the beginning.
      check_testcase executes a query to the server before that. There is a race here,
      because there is no guarantee that the thread executing check_testcase's query is
      finished.
      Problem 2: The SELECT FROM I_S.PROCESSLIST doens't seem very useful in the test.
      It's at least misplaced.
      Fix to both problems: Comment out SELECT FROM I_S.PROCESSLIST.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/56526

2712 Sven Sandberg	2008-10-18 [merge]
      merged fix for BUG#39851 from 5.1-rpl to 6.0-rpl

pushed to 5.1-rpl and 6.0-rpl

Pushed into 6.0.10-alpha (revid:luis.soares@sun.com-20090129165607-wiskabxm948yx463) (version source revid:luis.soares@sun.com-20090129163120-e2ntks4wgpqde6zt) (merge vers: 6.0.10-alpha) (pib:6)

Pushed into 5.1.32 (revid:luis.soares@sun.com-20090129165946-d6jnnfqfokuzr09y) (version source revid:sven@mysql.com-20081018183634-ffbr36w8ndyf3wav) (merge vers: 5.1.30) (pib:6)

Test case changes. No changelog entry needed.

Pushed into 5.1.32-ndb-6.3.23 (revid:tomas.ulin@sun.com-20090217131017-6u8qz1edkjfiobef) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

Pushed into 5.1.32-ndb-6.4.3 (revid:tomas.ulin@sun.com-20090217134419-5ha6xg4dpedrbmau) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

Pushed into 5.1.32-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090217134216-5699eq74ws4oxa0j) (version source revid:tomas.ulin@sun.com-20090201210519-vehobc4sy3g9s38e) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)