Bug #80607 main.log_tables-big unstable on loaded hosts

Description:
main.log_tables-big                      w4 [ fail ]
        Test ended at 2016-03-02 10:44:16

CURRENT_TEST: main.log_tables-big
--- /mnt/workspace/mysql-5.7-param/BUILD_TYPE/release/Host/debian-jessie-64bit/mysql-test/r/log_tables-big.result	2016-03-01 19:44:59.428030231 +0300
+++ /mnt/workspace/mysql-5.7-param/BUILD_TYPE/release/Host/debian-jessie-64bit/build/mysql-test/var/4/log/log_tables-big.reject	2016-03-02 18:44:16.183238108 +0300
@@ -24,6 +24,7 @@
 0
 select if (query_time between '00:01:40' and '00:01:50', 'OK', 'WRONG') as qt, sql_text from mysql.slow_log;
 qt	sql_text
+WRONG	truncate table mysql.slow_log
 OK	select get_lock('bug27638', 101)
 select release_lock('bug27638');
 release_lock('bug27638')

The gist of the testcase is

truncate table mysql.slow_log;
select get_lock('bug27638', 2);
select if (query_time between '00:00:01' and '00:00:10', 'OK', 'WRONG') as qt, sql_text from mysql.slow_log;
... repeated with different get_lock timeouts ...

Two things can go wrong here, on a very loaded host:
1) truncate table may take >1 s to complete, getting logged into slow log table as in the output above
2) get_lock may take than timeout + 10 s to complete

How to repeat:
Testcase analysis. Not sure if MTR --repeat --parallel high on this testcase alone will help to repeat as the testcase spends most of the time sleeping.

Suggested fix:
1) add WHERE sql_text = "get_lock ... " to the mysql.slow_log selects
2) test only the lower time bound

Hello Laurynas,

Thank you for the report.
Observed this with 5.6.31 daily build.

Thanks,
Umesh

Bug 80607 fix

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug80607.patch (application/octet-stream, text), 2.84 KiB.

Posted by developer:
 
This test was disabled for a long time. It was fixed and enabled on MySQL 5.7 - bug#11756699. Evaluate if that fix was similar or if this contribution should be accepted

The commit for 11756699 changes log destination to TABLE, whereas my patch filters the slow log for get_lock only (so that other testsuite commands running unexpectedly slowly do not interfere), and removes the upper time bound for get_lock, as it may be arbitrarily slow on a loaded host. Thus unless I am missing something, 11756699 commit and my fix are unrelated.

Posted by developer:
 
Noted in 5.5.55, 5.6.36, 5.7.18, 8.0.1 changelogs.

The main.log_tables-big test case could be unstable on highly loaded
hosts. Thanks to Laurynas Biveinis for the patch.