Bug #112728 MySQL optimizer generated an incorrect execution plan
Submitted: 15 Oct 2023 9:51 Modified: 18 Oct 2023 10:09
Reporter: xichao li (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S3 (Non-critical)
Version:8.0 OS:Any
Assigned to: CPU Architecture:Any

[15 Oct 2023 9:51] xichao li
Description:
The MySQL optimizer generated an incorrect execution plan, causing the execution time to change from 300 seconds to 19000 seconds.

How to repeat:
CREATE TABLE `t4` (
  `id` int(11) DEFAULT NULL,
  `c1` varchar(20) DEFAULT NULL,
  `c2` varchar(40) DEFAULT NULL,
  `c3` varchar(20) DEFAULT NULL,
  KEY `idx_c3` (`c3`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

mysql> insert into t4 values(1,'a','1','2023-10-13');

mysql> insert into t4 values(2,'b','2','2023-10-13');

mysql> insert into t4 values(3,'c','3','2023-10-13');

insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
// Until the contents of the t4 table reach about 229152 (this number of rows is more important).

// test-1
[m_3306]> select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+------+-----------------+
| id   | avg(length(c1)) |
+------+-----------------+
|    1 |          1.0000 |
|    2 |          1.0000 |
|    3 |          1.0000 |
+------+-----------------+
3 rows in set (4.94 sec)

[m_3306]> desc select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+----+-------------+-------+------------+------+---------------+--------+---------+-------+--------+----------+--------------------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key    | key_len | ref   | rows   | filtered | Extra                                                  |
+----+-------------+-------+------------+------+---------------+--------+---------+-------+--------+----------+--------------------------------------------------------+
|  1 | SIMPLE      | t4    | NULL       | ref  | idx_c3        | idx_c3 | 83      | const | 114576 |   100.00 | Using index condition; Using temporary; Using filesort |
+----+-------------+-------+------------+------+---------------+--------+---------+-------+--------+----------+--------------------------------------------------------+
1 row in set, 1 warning (0.26 sec)

// test-2
[m_3306]> select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
+------+-----------------+
| id   | avg(length(c1)) |
+------+-----------------+
|    1 |          1.0000 |
|    2 |          1.0000 |
|    3 |          1.0000 |
+------+-----------------+
3 rows in set (2.58 sec)

[m_3306]> desc select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows   | filtered | Extra                                        |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
|  1 | SIMPLE      | t4    | NULL       | ALL  | NULL          | NULL | NULL    | NULL | 229152 |   100.00 | Using where; Using temporary; Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
1 row in set, 1 warning (0.00 sec)

In contrast, it is found that the above case test-1 uses the execution plan generated by MySQL, and because the condition contains c3='2023-10-13', MySQL chooses to use idx_c3. The final execution took 4.94 seconds
By the case test-2 if we force MySQL not to use index idx_c3, then its execution time will only take 2.58 seconds.

However, MySQL own optimizer chose to use idx_c3 instead of using a full table scan, resulting in the actual SQL execution of the business almost doubling. In the production environment, due to the larger tables, the execution time increased by a factor of 63.

Suggested fix:
Based on the above calculation process, we find that when the function btr_estimate_n_rows_in_range_low() evaluates the rows that the index scan needs to access, if the total number of rows scanned by the index in the early evaluation exceeds 1/2 of the total number of rows of the table, the number of evaluated rows will be set to 1/2 of the number of rows of the table.
We have not analyzed other scenarios, but for this case, it seems that when the total number of rows scanned by the current evaluation index exceeds the total number of rows of the table, the number of rows evaluated will be set to the number of rows of the table (instead of 1/2 of the total number of rows of the table).
  
$ diff orig_code/percona-server-5.7.21-20/storage/innobase/btr/btr0cur.cc percona-5.7.21/storage/innobase/btr/btr0cur.cc -u
--- orig_code/percona-server-5.7.21-20/storage/innobase/btr/btr0cur.cc  2018-02-16 15:57:38.000000000 +0800
+++ percona-5.7.21/storage/innobase/btr/btr0cur.cc  2023-10-15 17:34:51.235000000 +0800
@@ -5935,9 +5935,9 @@
      to over 1 / 2 of the estimated rows in the whole
      table */
 
-     if (n_rows > table_n_rows / 2 && !is_n_rows_exact) {
+     if (n_rows > table_n_rows  && !is_n_rows_exact) {
 
-       n_rows = table_n_rows / 2;
+       n_rows = table_n_rows ;
 
        /* If there are just 0 or 1 rows in the table,
        then we estimate all rows are in the range */

[m_3306]> select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+------+-----------------+
| id   | avg(length(c1)) |
+------+-----------------+
|    1 |          1.0000 |
|    2 |          1.0000 |
|    3 |          1.0000 |
+------+-----------------+
3 rows in set (2.48 sec)

[m_3306]> desc select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows   | filtered | Extra                                        |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
|  1 | SIMPLE      | t4    | NULL       | ALL  | idx_c3        | NULL | NULL    | NULL | 229152 |   100.00 | Using where; Using temporary; Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
[16 Oct 2023 13:08] MySQL Verification Team
Hi Mr. li,

Thank you for your bug report.

However, you are using some old releases.

If you would use 8.0.34 or 8.1, you would have got the following results:

id	avg(length(c1))
1	1.0000
2	1.0000
3	1.0000
id	select_type	table	partitions	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	SIMPLE	t4	NULL	ALL	idx_c3	NULL	NULL	NULL	24	100.00	Using where; Using temporary
id	avg(length(c1))
1	1.0000
2	1.0000
3	1.0000
id	select_type	table	partitions	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	SIMPLE	t4	NULL	ALL	NULL	NULL	NULL	NULL	24	100.00	Using where; Using temporary

Hence, this bug is already fixed.

However, thank you for your effort !!!!!
[17 Oct 2023 5:21] xichao li
It seems that your test case does not match the actual situation, and I also conducted the test in 8.0.34, and found that this problem still exists. 

The complete test case is:
CREATE TABLE `t4` (
`id` int(11) DEFAULT NULL,
`c1` varchar(20) DEFAULT NULL,
`c2` varchar(40) DEFAULT NULL,
`c3` varchar(20) DEFAULT NULL,
KEY `idx_c3` (`c3`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

mysql> insert into t4 values(1,'a','1','2023-10-13');

mysql> insert into t4 values(2,'b','2','2023-10-13');

mysql> insert into t4 values(3,'c','3','2023-10-13');

insert into t4 select * from t4;
//....
insert into t4 select * from t4;
// Until the contents of the t4 table reach about 229152 (this number of rows is more important).  <<-------------  This is very important (about 16 repetitions required)

Then execute:

// test-1
select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
desc select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;

// test-2
select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
desc select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
[17 Oct 2023 10:11] MySQL Verification Team
Hi Mr. li,

We do not think that we understood you fully.

Are you instructing us to repeat:

insert into t4 select * from t4;

16 (sixteen) times ???

Thanks in advance.
[17 Oct 2023 10:41] xichao li
Sorry, I should have provided the following complete sql statement the first time:

CREATE TABLE `t4` (
`id` int(11) DEFAULT NULL,
`c1` varchar(20) DEFAULT NULL,
`c2` varchar(40) DEFAULT NULL,
`c3` varchar(20) DEFAULT NULL,
KEY `idx_c3` (`c3`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

insert into t4 values(1,'a','1','2023-10-13');

insert into t4 values(2,'b','2','2023-10-13');

insert into t4 values(3,'c','3','2023-10-13');

insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;

Then execute:

// test-1
select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
desc select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;

// test-2
select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
desc select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
[17 Oct 2023 11:29] MySQL Verification Team
Hi Mr. Li,

We were still not able to repeat the behaviour with latest 8.0 and 8.1:

id	avg(length(c1))
1	1.0000
2	1.0000
3	1.0000
4	1.0000
id	select_type	table	partitions	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	SIMPLE	t4	NULL	ref	idx_c3	idx_c3	23	const	131072	100.00	Using temporary
id	avg(length(c1))
1	1.0000
2	1.0000
3	1.0000
4	1.0000
id	select_type	table	partitions	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	SIMPLE	t4	NULL	ALL	NULL	NULL	NULL	NULL	262144	100.00	Using where; Using temporary

We have even more rows then you had asked for. We were not able to get exactly 229152 rows, but we managed to get even more rows.

We must also inform you that execution speed of both queries were smaller then 0.3 seconds. Hence, the differences in the performance are negligible .......
[17 Oct 2023 15:40] xichao li
First of all, thank you very much for verifying again.

In the actual production environment, there was indeed an sql that changed the execution time from 300 seconds to 19,000 seconds due to this execution problem.

I recreated the test data locally, but still not as large as the production environment. Its execution time has changed from 13 seconds to 169 seconds.

In addition, the greater the volume of data, the higher the rate of slowdowns.

Finally, I recorded my configuration and test records in the test environment. For your reference:

mysql> select version();
+-----------+
| version() |
+-----------+
| 8.0.34    |
+-----------+
1 row in set (0.00 sec)

mysql> system ps -ef | grep mysqld
mysql    22468 22397 63 18:18 pts/7    00:05:58 ./mysqld --defaults-file=/home/mysql/my.cnf
mysql    24204 22572  0 18:28 pts/1    00:00:00 sh -c  ps -ef | grep mysqld
mysql    24206 24204  0 18:28 pts/1    00:00:00 grep mysqld

mysql> system cat /home/mysql/my.cnf
[mysqld]
datadir=/mysql/data
socket=/tmp/mysql.sock
log-error=/opt/logs/mysql_error.log
binlog-format=ROW
log_bin=on
innodb_file_per_table=1
enforce_gtid_consistency=on
gtid_mode=on
transaction_isolation=READ-COMMITTED
#transaction_isolation=REPEATABLE-READ
#innodb_deadlock_detect = off
innodb_lock_wait_timeout = 10000
#innodb_rollback_on_timeout = on
innodb_thread_concurrency=2
long_query_time                           = 0.1
min_examined_row_limit = 100
slow_query_log = 1
binlog_transaction_dependency_tracking=WRITESET

CREATE TABLE `t4` (
`id` int(11) DEFAULT NULL,
`c1` varchar(20) DEFAULT NULL,
`c2` varchar(40) DEFAULT NULL,
`c3` varchar(20) DEFAULT NULL,
KEY `idx_c3` (`c3`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

insert into t4 values(1,'a','1','2023-10-13');

insert into t4 values(2,'b','2','2023-10-13');

insert into t4 values(3,'c','3','2023-10-13');

insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4;
insert into t4 select * from t4; 

mysql> desc t4;
+-------+-------------+------+-----+---------+-------+
| Field | Type        | Null | Key | Default | Extra |
+-------+-------------+------+-----+---------+-------+
| id    | int         | YES  |     | NULL    |       |
| c1    | varchar(20) | YES  |     | NULL    |       |
| c2    | varchar(40) | YES  |     | NULL    |       |
| c3    | varchar(20) | YES  | MUL | NULL    |       |
+-------+-------------+------+-----+---------+-------+

mysql> select id,c1,c2,c3,count(1) from t4 group by id,c1,c2,c3;
+------+------+------+------------+----------+
| id   | c1   | c2   | c3         | count(1) |
+------+------+------+------------+----------+
|    1 | a    | 1    | 2023-10-13 |  4194304 |
|    2 | b    | 2    | 2023-10-13 |  4194304 |
|    3 | c    | 3    | 2023-10-13 |  4194304 |
+------+------+------+------------+----------+

mysql> show variables like '%innodb_buffer_pool_size%';
+-------------------------+-----------+
| Variable_name           | Value     |
+-------------------------+-----------+
| innodb_buffer_pool_size | 134217728 |
+-------------------------+-----------+

mysql> select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+------+-----------------+
| id   | avg(length(c1)) |
+------+-----------------+
|    1 |          1.0000 |
|    2 |          1.0000 |
|    3 |          1.0000 |
+------+-----------------+
3 rows in set (2 min 49.09 sec)  <<-------------------------------------------------

mysql> desc select id,avg(length(c1)) from t4 where c3='2023-10-13' group by id;
+----+-------------+-------+------------+------+---------------+--------+---------+-------+---------+----------+-----------------+
| id | select_type | table | partitions | type | possible_keys | key    | key_len | ref   | rows    | filtered | Extra           |
+----+-------------+-------+------------+------+---------------+--------+---------+-------+---------+----------+-----------------+
|  1 | SIMPLE      | t4    | NULL       | ref  | idx_c3        | idx_c3 | 83      | const | 6130883 |   100.00 | Using temporary |
+----+-------------+-------+------------+------+---------------+--------+---------+-------+---------+----------+-----------------+

mysql> select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
+------+-----------------+
| id   | avg(length(c1)) |
+------+-----------------+
|    1 |          1.0000 |
|    2 |          1.0000 |
|    3 |          1.0000 |
+------+-----------------+
3 rows in set (13.28 sec) <<-------------------------------------------------

mysql> desc select id,avg(length(c1)) from t4 where concat(c3,'')='2023-10-13' group by id;
+----+-------------+-------+------------+------+---------------+------+---------+------+----------+----------+------------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows     | filtered | Extra                        |
+----+-------------+-------+------------+------+---------------+------+---------+------+----------+----------+------------------------------+
|  1 | SIMPLE      | t4    | NULL       | ALL  | NULL          | NULL | NULL    | NULL | 12261767 |   100.00 | Using where; Using temporary |
+----+-------------+-------+------------+------+---------------+------+---------+------+----------+----------+------------------------------+
[18 Oct 2023 9:56] MySQL Verification Team
Hi Mr. li,

Sorry, but even with your new test case, we get the very similar performance.

This is due to the differences in MySQL configuration, which is out of the scope of the bug report.
[18 Oct 2023 10:09] MySQL Verification Team
Hi Mr. li,

Actually, we had to add more rows and tune to some sub-optimal  configuration, which helped us reproduce the behaviour.

Since 5.7 is no longer maintained this is an Optimiser bug in 8.0 and higher.

This is now a verified Optimiser bug for 8.0 and higher.