[MDEV-20374] innodb.innodb_mysql fails sporadically in BB Created: 2019-08-18  Updated: 2019-08-20  Resolved: 2019-08-19

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4.8, 10.5.0

Type: Bug Priority: Major
Reporter: Sergei Petrunia Assignee: Sergei Petrunia
Resolution: Fixed Votes: 0
Labels: None


 Description   

In July and 1th -18th August 2019, it happened only in 10.4/10.5-based trees.

The failure looks like this:

innodb.innodb_mysql 'innodb'             w2 [ fail ]
        Test ended at 2019-07-28 17:33:47
 
CURRENT_TEST: innodb.innodb_mysql
--- /mnt/buildbot/build/mariadb-10.4.7/mysql-test/suite/innodb/r/innodb_mysql.result	2019-07-28 07:49:28.000000000 -0400
+++ /mnt/buildbot/build/mariadb-10.4.7/mysql-test/suite/innodb/r/innodb_mysql.reject	2019-07-28 17:33:46.613429422 -0400
@@ -394,7 +394,7 @@
 # Masking (#) number in "rows" column of the following EXPLAIN output, as it may vary (bug#47746).
 EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
 id	select_type	table	type	possible_keys	key	key_len	ref	rows	Extra
-1	SIMPLE	t1	range	name	name	44	NULL	#	Using where; Using index for group-by
+1	SIMPLE	t1	ref	name	name	22	const	#	Using where; Using index
 SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
 name	dept
 DROP TABLE t1;
 
mysqltest: Result length mismatch
 
 - skipping '/mnt/buildbot/build/mariadb-10.4.7/mysql-test/var/2/log/innodb.innodb_mysql-innodb/'
worker[2] > Restart  - not started

the second failure pattern is:

CURRENT_TEST: innodb.innodb_mysql
--- /home/psergey/dev-git/10.4-rel/mysql-test/suite/innodb/r/innodb_mysql.result        2019-08-18 16:35:19.017153458 +0300
+++ /home/psergey/dev-git/10.4-rel/mysql-test/suite/innodb/r/innodb_mysql.reject        2019-08-18 16:52:26.506107962 +0300
@@ -3180,7 +3180,7 @@
 (SELECT * FROM t1 FORCE INDEX (idx,PRIMARY)
 WHERE a BETWEEN 2 AND 7 OR pk=1000000) AS t;
 id     select_type     table   type    possible_keys   key     key_len ref     rows    Extra
-1      PRIMARY <derived2>      ALL     NULL    NULL    NULL    NULL    1537
+1      PRIMARY <derived2>      ALL     NULL    NULL    NULL    NULL    1536
 2      DERIVED t1      index_merge     PRIMARY,idx     idx,PRIMARY     5,4     NULL    1537    Using sort_union(idx,PRIMARY); Using where
 SELECT COUNT(*) FROM
 (SELECT * FROM t1 FORCE INDEX (idx,PRIMARY)
 
mysqltest: Result content mismatch

Both failures occur randomly, are not common (every 10th run? 20th run?)



 Comments   
Comment by Sergei Petrunia [ 2019-08-18 ]

Investigation log from Slack:

https://lists.mysql.com/commits/19658
the original patch had
+EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
+id select_type table type possible_keys key key_len ref rows Extra
+1 SIMPLE t1 range name name 44 NULL 2 Using where; Using index for group-by
+SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
+name dept
+rs5 cs10
+rs5 cs9
+DELETE FROM t1;
+EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
+id select_type table type possible_keys key key_len ref rows Extra
+1 SIMPLE t1 range name name 44 NULL 2 Using where; Using index for group-by
+SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
current .result file
EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE t1 ref name name 22 const 2 Using where; Using index
SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
name dept
rs5 cs10
rs5 cs9
DELETE FROM t1;
# Masking (#) number in "rows" column of the following EXPLAIN output, as it may vary (bug#47746).
EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE t1 range name name 44 NULL # Using where; Using index for group-by
SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
failures are like so (edited)
CURRENT_TEST: innodb.innodb_mysql
— /mnt/buildbot/build/mariadb-10.5.0/mysql-test/suite/innodb/r/innodb_mysql.result 2019-08-12 10:44:01.000000000 -0400
+++ /mnt/buildbot/build/mariadb-10.5.0/mysql-test/suite/innodb/r/innodb_mysql.reject 2019-08-12 15:00:09.173704512 -0400
@@ -394,7 +394,7 @@
\ # Masking (#) number in "rows" column of the following EXPLAIN output, as it may vary (bug#47746).
EXPLAIN SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
id select_type table type possible_keys key key_len ref rows Extra
-1 SIMPLE t1 range name name 44 NULL # Using where; Using index for group-by
+1 SIMPLE t1 ref name name 22 const # Using where; Using index
SELECT DISTINCT t1.name, t1.dept FROM t1 WHERE t1.name='rs5';
name dept
DROP TABLE t1;
hmm it fails only in 10.4/10.5 (edited)
Suggestions:
* Doing ANALYZE TABLE ... PERSISTENT FOR ALL might help (as it fixes some of the statistics)
* There is now DBUG_EXECUTE_IF("force_group_by",...) in opt_range.cc which forces LooseScan
. It was added for a different purpose but could be reused for this testcase
... yeah, innodb_mysql fails in 10.4 and 10.5 only

well, it is important that the testcase uses LooseScan
14:29
if it doesn't, the original test coverage is lost
14:30
(so #rows is not imporat, but "Using index for group by" is important)
14:30
when ref access is used, it's no good.

Generated at Thu Feb 08 08:58:59 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.