Bug #101705 Optimizer spends several seconds to produce query plan
Submitted: 21 Nov 2020 8:01 Modified: 23 Nov 2020 14:30
Reporter: Aftab Khan Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S2 (Serious)
Version:5.7.32 OS:Any
Assigned to: CPU Architecture:Any

[21 Nov 2020 8:01] Aftab Khan
Description:
Testing an upgrade from 5.6 to 5.7.32, we found an issue with the IN clause. Two large IN-LISTs cause optimizer to spend several seconds. However the same query in 5.6.34 produce results in 0.2 seconds.

How to repeat:

mysql> source slow_in_query << long query
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows  | filtered | Extra                       |
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
|  1 | SIMPLE      | bar   | NULL       | ALL  | PRIMARY       | NULL | NULL    | NULL | 27280 |     2.50 | Using where; Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
1 row in set, 2 warnings (0.10 sec)

mysql> show warnings limit 1;
+---------+------+-------------------------------------------------------------------------------------------------------------------------------+
| Level   | Code | Message                                                                                                                       |
+---------+------+-------------------------------------------------------------------------------------------------------------------------------+
| Warning | 3170 | Memory capacity of 8388608 bytes for 'range_optimizer_max_mem_size' exceeded. Range optimization was not done for this query. |
+---------+------+-------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> set range_optimizer_max_mem_size=8388608*2;
Query OK, 0 rows affected (0.00 sec)

mysql> source slow_in_query_foo
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows  | filtered | Extra                       |
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
|  1 | SIMPLE      | bar   | NULL       | ALL  | PRIMARY       | NULL | NULL    | NULL | 27280 |     9.90 | Using where; Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
1 row in set, 1 warning (8.09 sec)

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.026733 |
| checking permissions | 0.000011 |
| Opening tables       | 0.000012 |
| init                 | 0.019610 |
| System lock          | 0.000018 |
| optimizing           | 0.002621 |
| statistics           | 7.721412 | <<<
| preparing            | 0.000840 |
| Sorting result       | 0.000014 |
| explaining           | 0.011732 |
| end                  | 0.000011 |
| query end            | 0.000007 |
| closing tables       | 0.000009 |
| freeing items        | 0.006310 |
| cleaning up          | 0.002349 |
+----------------------+----------+

mysql> show create table bar\G
*************************** 1. row ***************************
       Table: bar
Create Table: CREATE TABLE `bar` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `d` int(10) unsigned NOT NULL DEFAULT '0',
  `u` int(10) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=125016108654 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

mysql> select count(*) from bar;
+----------+
| count(*) |
+----------+
|    26967 |
+----------+
1 row in set (0.01 sec)

-- QUERY --

SELECT `id`
FROM `foo`.`bar` 
WHERE ((`id` in ('8808406970','27528136435'/* truncated 26992 ids */)))
AND (id IN ('8808406970','27528136435' /* truncated 26992 ids */)) AND ((d = FALSE))
ORDER BY `u` ASC, `id` ASC
[21 Nov 2020 8:03] Aftab Khan
table bar sql dump

Attachment: bar.sql (application/octet-stream, text), 738.28 KiB.

[21 Nov 2020 8:04] Aftab Khan
sql query

Attachment: slow_in_query.gz (application/x-gzip, text), 280.38 KiB.

[21 Nov 2020 14:37] Aftab Khan
simplified test:

echo 'create database bar;
CREATE TABLE `bar`.`foo` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `d` int(10) unsigned NOT NULL DEFAULT '0',
  `u` int(10) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB  DEFAULT CHARSET=utf8;
insert into bar.foo values();' | mysql -v

for t in {1..5}; do mysql bar -e 'insert into foo select null,1,0 from foo f1 inner join foo f2;' -vvv ; done

ids=$(mysql foo -Nse 'select id from foo where id between 1 and 25000' | awk '{printf fmt,$1}' fmt="%s\n" | paste -sd, - )

echo "set profiling=1;set range_optimizer_max_mem_size=8388608*2;explain select id from foo where id in ($ids) and id in ($ids) and u=False; show profile for query 2" | mysql foo -vv

--------------

id	select_type	table	partitions	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	SIMPLE	foo	NULL	range	PRIMARY	PRIMARY	8	NULL	24687	10.00	Using where
--------------
show profile for query 2
--------------

Status	Duration
starting	0.022625
checking permissions	0.000023
Opening tables	0.000068
init	0.008634
System lock	0.000029
optimizing	0.003491
statistics	4.897413 <<<
preparing	0.000722
explaining	0.007031
end	0.000005
query end	0.000248
closing tables	0.000009
freeing items	0.003310
cleaning up	0.001280
[23 Nov 2020 8:30] MySQL Verification Team
Hello Aftab,

Thank you for the report and testcase.

regards,
Umesh
[22 Sep 2022 17:18] Perry Harrington
Hi Umesh, after talking with Aftab and reading this bug report, I believe this should affect 8 as well.  I was the engineer who handled the original bug report that lead to the optimizer mem size limit.

Thanks,

--Perry