[MDEV-26872] perfschema.prepared_statements non-deterministic test failure Created: 2021-10-21  Updated: 2022-10-19  Resolved: 2022-10-19

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.5.12
Fix Version/s: 10.5.18

Type: Bug Priority: Major
Reporter: Maxim C. Assignee: Andrew Hutchings
Resolution: Fixed Votes: 0
Labels: None
Environment:

GNU Guix

Attachments: File mariadb-10.5.12.drv.failure.log     File perfschema.prepared_statements.tar.xz    

 Description   

The full build log is attached. Here's an excerpt:

URRENT_TEST: perfschema.prepared_statements
 
safe_process[14728]: parent_pid: 24921
 
safe_process[14728]: Started child 14731, terminated: 0
 
--- /tmp/guix-build-mariadb-10.5.12.drv-0/mariadb-10.5.12/mysql-test/suite/perfschema/r/prepared_statements.result      1970-01-01 00:00:01.000000000 +0000
 
+++ /tmp/guix-build-mariadb-10.5.12.drv-0/mariadb-10.5.12/mysql-test/suite/perfschema/r/prepared_statements.reject      2021-10-21 01:16:45.017364295 +0000
 
@@ -12,29 +12,29 @@
 
 PREPARE st4 FROM
 
 '(SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a';
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+STATEMENT_NAME st3
 
+SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
+STATEMENT_NAME st4
 
+SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st3
 
-SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st4
 
-SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
@@ -119,20 +119,6 @@
 
 80
 
 90
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
-COUNT_REPREPARE        0
 
-COUNT_EXECUTE  1
 
-SUM_ROWS_SENT  1
 
-SUM_SELECT_SCAN        0
 
-SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
-COUNT_REPREPARE        0
 
-COUNT_EXECUTE  1
 
-SUM_ROWS_SENT  5
 
-SUM_SELECT_SCAN        1
 
-SUM_NO_INDEX_USED      1
 
 STATEMENT_NAME st3
 
 SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
@@ -147,6 +133,20 @@
 
 SUM_ROWS_SENT  10
 
 SUM_SELECT_SCAN        3
 
 SUM_NO_INDEX_USED      1
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+COUNT_REPREPARE        0
 
+COUNT_EXECUTE  1
 
+SUM_ROWS_SENT  1
 
+SUM_SELECT_SCAN        0
 
+SUM_NO_INDEX_USED      0
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
+COUNT_REPREPARE        0
 
+COUNT_EXECUTE  1
 
+SUM_ROWS_SENT  5
 
+SUM_SELECT_SCAN        1
 
+SUM_NO_INDEX_USED      1
 
 SELECT EVENT_NAME, SQL_TEXT, OBJECT_TYPE, OBJECT_SCHEMA, OBJECT_NAME FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA='db' ;
 
 EVENT_NAME statement/sql/truncate
 
 SQL_TEXT   TRUNCATE TABLE performance_schema.events_statements_history_long
 
@@ -246,29 +246,29 @@
 
 OBJECT_NAME    NULL
 
 TRUNCATE TABLE performance_schema.prepared_statements_instances ;
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+STATEMENT_NAME st3
 
+SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
+STATEMENT_NAME st4
 
+SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st3
 
-SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st4
 
-SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 
 
mysqltest: Result content mismatch
 
 
 
safe_process[14728]: Got signal 17, child_pid: 14731
 
safe_process[14728]: Killing child: 14731
 
safe_process[14728]: Child exit: 1
 
 
 
worker[15] mroonga/storage.index_multiple_column_select_string w15 worker[15] [ pass ]    684
 
worker[11] Started [check-mysqld_1 - pid: 14899, winpid: 14899]
 
perfschema.prepared_statements           w18 [ fail ]
 
        Test ended at 2021-10-21 01:16:45
 
 
 
CURRENT_TEST: perfschema.prepared_statements
 
safe_process[14728]: parent_pid: 24921
 
safe_process[14728]: Started child 14731, terminated: 0
 
--- /tmp/guix-build-mariadb-10.5.12.drv-0/mariadb-10.5.12/mysql-test/suite/perfschema/r/prepared_statements.result      1970-01-01 00:00:01.000000000 +0000
 
+++ /tmp/guix-build-mariadb-10.5.12.drv-0/mariadb-10.5.12/mysql-test/suite/perfschema/r/prepared_statements.reject      2021-10-21 01:16:45.017364295 +0000
 
@@ -12,29 +12,29 @@
 
 PREPARE st4 FROM
 
 '(SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a';
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+STATEMENT_NAME st3
 
+SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
+STATEMENT_NAME st4
 
+SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st3
 
-SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st4
 
-SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
@@ -119,20 +119,6 @@
 
 80
 
 90
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
-COUNT_REPREPARE        0
 
-COUNT_EXECUTE  1
 
-SUM_ROWS_SENT  1
 
-SUM_SELECT_SCAN        0
 
-SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
-COUNT_REPREPARE        0
 
-COUNT_EXECUTE  1
 
-SUM_ROWS_SENT  5
 
-SUM_SELECT_SCAN        1
 
-SUM_NO_INDEX_USED      1
 
 STATEMENT_NAME st3
 
 SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
@@ -147,6 +133,20 @@
 
 SUM_ROWS_SENT  10
 
 SUM_SELECT_SCAN        3
 
 SUM_NO_INDEX_USED      1
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+COUNT_REPREPARE        0
 
+COUNT_EXECUTE  1
 
+SUM_ROWS_SENT  1
 
+SUM_SELECT_SCAN        0
 
+SUM_NO_INDEX_USED      0
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
+COUNT_REPREPARE        0
 
+COUNT_EXECUTE  1
 
+SUM_ROWS_SENT  5
 
+SUM_SELECT_SCAN        1
 
+SUM_NO_INDEX_USED      1
 
 SELECT EVENT_NAME, SQL_TEXT, OBJECT_TYPE, OBJECT_SCHEMA, OBJECT_NAME FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA='db' ;
 
 EVENT_NAME statement/sql/truncate
 
 SQL_TEXT   TRUNCATE TABLE performance_schema.events_statements_history_long
 
@@ -246,29 +246,29 @@
 
 OBJECT_NAME    NULL
 
 TRUNCATE TABLE performance_schema.prepared_statements_instances ;
 
 SELECT STATEMENT_NAME, SQL_TEXT, COUNT_REPREPARE, COUNT_EXECUTE, SUM_ROWS_SENT, SUM_SELECT_SCAN, SUM_NO_INDEX_USED FROM performance_schema.prepared_statements_instances ;
 
-STATEMENT_NAME st1
 
-SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
+STATEMENT_NAME st3
 
+SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st2
 
-SQL_TEXT   SELECT * FROM t1
 
+STATEMENT_NAME st4
 
+SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st3
 
-SQL_TEXT   INSERT INTO t1 SELECT * FROM t1 WHERE a<=?
 
+STATEMENT_NAME st1
 
+SQL_TEXT   SELECT SQRT(POW(?,2) + POW(?,2)) AS hypotenuse
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 SUM_SELECT_SCAN        0
 
 SUM_NO_INDEX_USED      0
 
-STATEMENT_NAME st4
 
-SQL_TEXT   (SELECT a FROM t1) UNION (SELECT a+10 FROM t1) ORDER BY RAND()*0+a
 
+STATEMENT_NAME st2
 
+SQL_TEXT   SELECT * FROM t1
 
 COUNT_REPREPARE        0
 
 COUNT_EXECUTE  0
 
 SUM_ROWS_SENT  0
 
 
 
mysqltest: Result content mismatch
 
 
 
safe_process[14728]: Got signal 17, child_pid: 14731
 
safe_process[14728]: Killing child: 14731
 
safe_process[14728]: Child exit: 1
 
 
 
 - saving '/tmp/guix-build-mariadb-10.5.12.drv-0/build/mysql-test/var/18/log/perfschema.prepared_statements/' to '/tmp/guix-build-mariadb-10.5.12.drv-0/build/mysql-test/var/log/perfschema.prepared_statements/'
 
worker[18] > Stopping all servers...
 
worker[5] Got [check-mysqld_1 - pid: 14888, winpid: 14888, exit: 0]
 
worker[15] > Stopping all servers...
 
worker[5] mroonga/wrapper.fulltext_order_transaction 'innodb' w5 worker[5] [ pass ]    797
 
worker[8] Got [check-mysqld_1 - pid: 14889, winpid: 14889, exit: 0]
 
worker[5] > Stopping all servers...
 
 
 
Only  4466  of 5901 completed.
 
--------------------------------------------------------------------------
 
The servers were restarted 791 times
 
Spent 3515.353 of 213 seconds executing testcases
 
 
 
Failure: Failed 1/2642 tests, 99.96% were successful.
 
 
 
Failing test(s): perfschema.prepared_statements


Generated at Thu Feb 08 09:48:35 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.