Bug #90631 perfschema.statement_digest_query_sample test fails sporadically
Submitted: 25 Apr 2018 12:57 Modified: 25 Apr 2018 15:10
Reporter: Valeriy Kravchuk Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Performance Schema Severity:S3 (Non-critical)
Version:8.0.11 OS:Ubuntu (14.04)
Assigned to: CPU Architecture:x86
Tags: perfschema.statement_digest_query_sample, test

[25 Apr 2018 12:57] Valeriy Kravchuk
Description:
The perfschema.statement_digest_query_sample test fails for me with MySQL 8.0.11 built from source on Ubuntu 14.04, once in while. Like this:

openxs@ao756:~/dbs/8.0/mysql-test$ ./mtr --repeat=10 perfschema.statement_digest_query_sample
Logging: ./mtr  --repeat=10 perfschema.statement_digest_query_sample
2018-04-25T12:45:11.793055Z 0 [Warning] [MY-010139] [Server] Changed limits: max_open_files: 1024 (requested 8161)
2018-04-25T12:45:11.793195Z 0 [Warning] [MY-010142] [Server] Changed limits: table_open_cache: 431 (requested 4000)
2018-04-25T12:45:11.793635Z 0 [System] [MY-010116] [Server] /home/openxs/dbs/8.0/bin/mysqld (mysqld 8.0.11) starting as process 32726
MySQL Version 8.0.11
Checking supported features...
 - SSL connections supported
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/openxs/dbs/8.0/mysql-test/var'...
Installing system database...
Using parallel: 1

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
perfschema.statement_digest_query_sample [ pass ]  70139
perfschema.statement_digest_query_sample [ pass ]  70401
perfschema.statement_digest_query_sample [ pass ]  71149
perfschema.statement_digest_query_sample [ fail ]
        Test ended at 2018-04-25 15:50:52

CURRENT_TEST: perfschema.statement_digest_query_sample
--- /home/openxs/dbs/8.0/mysql-test/suite/perfschema/r/statement_digest_query_sample.result     2017-09-23 16:01:41.000000000 +0300
+++ /home/openxs/dbs/8.0/mysql-test/var/log/statement_digest_query_sample.reject2018-04-25 15:50:52.341777630 +0300
@@ -251,11 +251,11 @@
 # Max timer wait 1 = max wait 2
 SELECT @max_timer_wait_1 = @max_timer_wait_2 AS 'Expect 1 because query is not sampled';
 Expect 1 because query is not sampled
-1
+0

 SELECT @query_sample_timer_wait_1 = @query_sample_timer_wait_2 AS 'Expect 1 because query is not sampled';
 Expect 1 because query is not sampled
-1
+0

 SELECT @last_seen_1 < @last_seen_2 AS 'Expect 1 because a more recent query with same digest was queried';
 Expect 1 because a more recent query with same digest was queried
@@ -272,7 +272,7 @@
 # Query_2: Not sampled, age not expired, max_timer_wait not exceeded, no change
 SELECT @query_sample_text_2 AS 'Expect UPDATE t1 SET s1 = 700';
 Expect UPDATE t1 SET s1 = 700
-UPDATE t1 SET s1 = 700
+UPDATE t1 SET s1 = 800

 ##### TEST 4 - QUERY SAMPLED WHEN MAX SAMPLE AGE DOES NOT EXPIRE BUT MAX WAIT IS EXCEEDED

mysqltest: Result content mismatch

safe_process[388]: Child process: 389, exit: 1

 - the logfile can be found in '/home/openxs/dbs/8.0/mysql-test/var/log/perfschema.statement_digest_query_sample/statement_digest_query_sample.log'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 211.689 of 341 seconds executing testcases

Completed: Failed 1/4 tests, 75.00% were successful.

Failing test(s): perfschema.statement_digest_query_sample

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases
openxs@ao756:~/dbs/8.0/mysql-test$ ls -l suite/perfschema/t/statement_digest_query_sample.*
-rw-rw-r-- 1 openxs openxs 14506 вер 23  2017 suite/perfschema/t/statement_digest_query_sample.test
openxs@ao756:~/dbs/8.0/mysql-test$

How to repeat:
Build MySQL 8.0.11 from GitHub source using the followi8ng cmake command line:

cmake . -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_CONFIG=mysql_release -DFEATURE_SET=community -DWITH_EMBEDDED_SERVER=OFF -DCMAKE_INSTALL_PREFIX=/home/openxs/dbs/8.0 -DWITH_BOOST=/home/openxs/boost -DDOWNLOAD_BOOST=1  -DENABLE_DOWNLOADS=1 -DWITH_UNIT_TESTS=OFF

Run the test multiple times:

openxs@ao756:~/dbs/8.0/mysql-test$ ./mtr --repeat=10 perfschema.statement_digest_query_sample

Suggested fix:
Do something for this test not to fail, no matter how many times it is repeated, alone or in frames of entire perfschema suite.
[25 Apr 2018 15:10] MySQL Verification Team
Thank you for the bug report.
miguel@tikal:~/dbs/8.0/mysql-test $ ./mtr --repeat=10 perfschema.statement_digest_query_sample
Logging: ./mtr  --repeat=10 perfschema.statement_digest_query_sample
2018-04-25T14:22:47.833587Z 0 [System] [MY-010116] [Server] /home/miguel/dbs/8.0/bin/mysqld (mysqld 8.0.12) starting as process 7291
MySQL Version 8.0.12
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/miguel/dbs/8.0/mysql-test/var'...
Installing system database...
Using parallel: 1

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
perfschema.statement_digest_query_sample [ pass ]  54919
perfschema.statement_digest_query_sample [ pass ]  56057
perfschema.statement_digest_query_sample [ pass ]  55553
perfschema.statement_digest_query_sample [ pass ]  55458
perfschema.statement_digest_query_sample [ pass ]  55802
perfschema.statement_digest_query_sample [ pass ]  55915
perfschema.statement_digest_query_sample [ pass ]  56164
perfschema.statement_digest_query_sample [ fail ]
        Test ended at 2018-04-25 11:30:56

CURRENT_TEST: perfschema.statement_digest_query_sample
--- /home/miguel/dbs/8.0/mysql-test/suite/perfschema/r/statement_digest_query_sample.result     2018-04-18 17:09:18.000000000 +0300
+++ /home/miguel/dbs/8.0/mysql-test/var/log/statement_digest_query_sample.reject        2018-04-25 17:30:56.346924796 +0300
@@ -318,7 +318,7 @@
 ## The second query is expected to be slower
 SELECT @max_timer_wait_1 < @max_timer_wait_2 AS "check_wait";
 check_wait