MySQL Bugs: #36345: Test 'func_misc' fails on RHAS3 x86

Bug #36345	Test 'func_misc' fails on RHAS3 x86_64
Submitted:	25 Apr 2008 14:30	Modified:	28 Jul 2008 17:52
Reporter:	Kent Boortz	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Tests	Severity:	S7 (Test Cases)
Version:	5.0.60-pre	OS:	Any
Assigned to:	Matthias Leich	CPU Architecture:	Any

Description:
Test 'func_misc' fails on RHAS3 x86_64, with a bit varying difference from
expected output. Happens in different test modes, 'normal', 'ps-protocol'
and 'debug', but it doesn't happen always. Diff is one of the two

@@ -130,7 +130,7 @@
 timediff(b, a) >= '00:00:03'
 1
 1
-1
+0
 drop table t2;
 drop table t1;
 set global query_cache_size=default;

or

@@ -129,7 +129,7 @@
 select timediff(b, a) >= '00:00:03' from t2;
 timediff(b, a) >= '00:00:03'
 1
-1
+0
 1
 drop table t2;
 drop table t1;

How to repeat:
Build and test on RHAS3 x86_64

This looks like the type of problem that you would expect on a virtual machine with jumpy timing. Likely not a code problem.

This is the test:
#
# Bug #12689: SLEEP() gets incorrectly cached/optimized-away
#
set global query_cache_size=1355776;
create table t1 (a int);
insert into t1 values (1),(1),(1);
create table t2 (a datetime default null, b datetime default null);
insert into t2 set a = now();
select a from t1 where sleep(1);
update t2 set b = now() where b is null;
insert into t2 set a = now();
select a from t1 where sleep(a);
update t2 set b = now() where b is null;
insert into t2 set a = now();
select a from t1 where sleep(1);
update t2 set b = now() where b is null;
select timediff(b, a) >= '00:00:03' from t2;
drop table t2;
drop table t1;
set global query_cache_size=default;

I would suggest that we start by making the test printout the records of table t2 if the timediff is >= 3 seconds in any row. That would make it possible to determine proper cause. I.e is this just a vm problem.

Normally it looks like this:
+select * from t2;
+a      b
+2008-04-25 18:37:20    2008-04-25 18:37:23
+2008-04-25 18:37:23    2008-04-25 18:37:26
+2008-04-25 18:37:26    2008-04-25 18:37:29

The use of timing is not necessary, test case should show 'Qcache_queries_in_cache', 'Qcache_inserts' and 'Qcache_not_cached' to ensure that the query was not cached. The test case query_cache.test has a lot of examples on this.

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/46432

ChangeSet@1.2613, 2008-05-06 18:40:13-04:00, pcrews@pcrews-mac-local.local +1 -0
  Bug#36345 - Test 'func_misc' fails on RHAS3 x86_64
  
  Added code to the .test file so that we are provided with a view
  of the table's contents on a bad test run.
  
  This is *not* a fix per se, but a way of gaining additional insight into the problem.
  Could not duplicate the error on my personal machines -- suspect this could be a VM issue
  as noted in the Bug comments.

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/46532

ChangeSet@1.2623, 2008-05-08 14:26:37-04:00, pcrews@pcrews-mac-local.local +2 -0
  Bug#36345 - Test 'func_misc' fials on RHAS3 x86_64
  
  Altered the test to incorporate qcache status variables as
  an extra check.
  
  Wanted to keep the check of actual SLEEP() performance to ensure
  no other optimizations affect this function.
  
  It was determined this bug was due to host timing issues, added
  a loop to provide the test 2 extra attempts to have a successful
  run.
  
  Will still output t2 contents in the event of a failure to assist
  with troubleshooting.

Experiments with parallel setting of system time
revealed that also the subtest for Bug#6760 is
vulnerable. This should be also fixed.

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/46966

ChangeSet@1.2616, 2008-05-22 19:56:38+02:00, mleich@five.local.lan +2 -0
  Fix for
     Bug#36345 Test 'func_misc' fails on RHAS3 x86_64
  and a second similar problem within this test found
  during experimenting.

Patch was pushed into
5.1-bugteam
6.0-bugteam
trees
BTW: If it is required to port the fix back to 5.0
     than the stuff using information_schema.processlist
     will not work because we do not have this table in 5.0.

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/47017

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/47189

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/47213

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/47226

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/47227

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/47228

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/47229

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/47230

Patch was pushed into
  5.0-bugteam
  5.1-bugteam
  6.0-bugteam
trees

Just a note:
------------
It looks like that the reason for the current bad
effect is a parallel manipulations of system time
(like ntpd etc.) on the testing box.
If this is the real reason than we have here a
massive bug within the setup of the testing environment
and NOT a weakness within any script or testing tool.

Pushed in 5.0.68, 5.1.28 and 6.0.7-alpha

Pushed into 5.0.64  (revid:mleich@mysql.com-20080529163810-4o3e2i2xllosor5o) (pib:2)
(Retry automatic marking, to ensure nothing is missed. cm01)

Pushed into 5.1.27  (revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (version source revid:joerg@mysql.com-20080626161101-h5hsaluwtf05xdr2) (pib:3)

Test case changes. No changelog entry needed.