Details
-
Bug
-
Status: In Progress (View Workflow)
-
Critical
-
Resolution: Unresolved
-
10.11.14
-
MariaDB 10.11.14, Debian Bookwoorm, bare metal
Description
We've got the following two tables on English Wikipedia:
cumin2024@db1169.eqiad.wmnet[enwiki]> show create table actor; show create table logging;
|
+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
| Table | Create Table >
|
+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
| actor | CREATE TABLE `actor` (
|
`actor_id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
|
`actor_user` int(10) unsigned DEFAULT NULL,
|
`actor_name` varbinary(255) NOT NULL,
|
PRIMARY KEY (`actor_id`),
|
UNIQUE KEY `actor_name` (`actor_name`),
|
UNIQUE KEY `actor_user` (`actor_user`)
|
) ENGINE=InnoDB AUTO_INCREMENT=238227785 DEFAULT CHARSET=binary ROW_FORMAT=COMPRESSED |
|
+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
1 row in set (0.001 sec)
|
|
|
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
| Table | Create Table >
|
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
| logging | CREATE TABLE `logging` (
|
`log_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
|
`log_type` varbinary(32) NOT NULL DEFAULT '',
|
`log_action` varbinary(32) NOT NULL DEFAULT '',
|
`log_timestamp` binary(14) NOT NULL DEFAULT '19700101000000',
|
`log_namespace` int(11) NOT NULL DEFAULT 0,
|
`log_title` varbinary(255) NOT NULL DEFAULT '',
|
`log_comment_id` bigint(20) unsigned NOT NULL,
|
`log_params` blob NOT NULL,
|
`log_deleted` tinyint(3) unsigned NOT NULL DEFAULT 0,
|
`log_actor` bigint(20) unsigned NOT NULL,
|
`log_page` int(10) unsigned DEFAULT NULL,
|
PRIMARY KEY (`log_id`),
|
KEY `log_page_id_time` (`log_page`,`log_timestamp`),
|
KEY `log_actor_type_time` (`log_actor`,`log_type`,`log_timestamp`),
|
KEY `log_type_action` (`log_type`,`log_action`,`log_timestamp`),
|
KEY `log_type_time` (`log_type`,`log_timestamp`),
|
KEY `log_actor_time` (`log_actor`,`log_timestamp`),
|
KEY `log_page_time` (`log_namespace`,`log_title`,`log_timestamp`),
|
KEY `log_times` (`log_timestamp`)
|
) ENGINE=InnoDB AUTO_INCREMENT=174074740 DEFAULT CHARSET=binary ROW_FORMAT=COMPRESSED |
|
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->
|
1 row in set (0.001 sec)
|
|
|
cumin2024@db1169.eqiad.wmnet[enwiki]> select count(*) from actor; select count(*) from logging;
|
+-----------+
|
| count(*) |
|
+-----------+
|
| 116714292 |
|
+-----------+
|
1 row in set (27.083 sec)
|
|
|
+-----------+
|
| count(*) |
|
+-----------+
|
| 156160809 |
|
+-----------+
|
1 row in set (40.553 sec)
|
We've got this query:
cumin2024@db1169.eqiad.wmnet[enwiki]> explain SELECT log_id,log_type,log_action,log_timestamp,log_deleted FROM `logging` JOIN `actor` ON ((actor_id=log_actor)) WHERE (log_type NOT IN ('spamblacklist','titleblacklist','urlshortener','abusefilterprivatedetails','abusefilterblockeddomainhit','abusefilter-protected-vars','oath','checkuser-temporary-account','checkuser-private-event','ipinfo','suppress')) AND actor_name = 'DGG' AND ((log_deleted & 4) != 4) ORDER BY log_timestamp DESC,log_id DESC LIMIT 2;
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+------+-------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+------+-------------+
|
| 1 | SIMPLE | actor | const | PRIMARY,actor_name | actor_name | 257 | const | 1 | Using index |
|
| 1 | SIMPLE | logging | index | log_actor_type_time,log_type_action,log_type_time,log_actor_time | log_times | 14 | NULL | 1281 | Using where |
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+------+-------------+
|
2 rows in set (0.003 sec)
|
The running explain shows:
SELECT log_id,log_type,log_action,log_timestamp,log_deleted FROM `logging` JOIN `actor` ON ((actor_id=log_actor)) WHERE (log_type NOT IN ('spamblacklist','titleblacklist','urlshortener','abusefilterprivatedetails','abusefilterblockeddomainhit','abusefilter-protected-vars','oath','checkuser-temporary-account','checkuser-private-event','ipinfo','suppress')) AND actor_name = 'DGG' AND ((log_deleted & 4) != 4) ORDER BY log_timestamp DESC,log_id DESC LIMIT 2
|
|
|
cumin2024@db1169.eqiad.wmnet[enwiki]> show explain for 2640969;
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+-----------+-------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+-----------+-------------+
|
| 1 | SIMPLE | actor | const | PRIMARY,actor_name | actor_name | 257 | const | 1 | Using index |
|
| 1 | SIMPLE | logging | index | log_actor_type_time,log_type_action,log_type_time,log_actor_time | log_times | 14 | NULL | 112332602 | Using where |
|
+------+-------------+---------+-------+------------------------------------------------------------------+------------+---------+-------+-----------+-------------+
|
2 rows in set, 1 warning (0.001 sec)
|
The table stats are up-to-date:
cumin2024@db1169.eqiad.wmnet[enwiki]> SELECT * FROM mysql.innodb_index_stats WHERE table_name='logging'; SELECT * FROM mysql.innodb_index_stats WHERE table_name='actor';
|
+---------------+------------+---------------------+---------------------+--------------+------------+-------------+----------------------------------------------+
|
| database_name | table_name | index_name | last_update | stat_name | stat_value | sample_size | stat_description |
|
+---------------+------------+---------------------+---------------------+--------------+------------+-------------+----------------------------------------------+
|
| enwiki | logging | PRIMARY | 2025-11-11 17:37:32 | n_diff_pfx01 | 150002552 | 20 | log_id |
|
| enwiki | logging | PRIMARY | 2025-11-11 17:37:32 | n_leaf_pages | 1363040 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | PRIMARY | 2025-11-11 17:37:32 | size | 1471552 | NULL | Number of pages in the index |
|
| enwiki | logging | log_actor_time | 2025-11-11 17:37:32 | n_diff_pfx01 | 55746598 | 20 | log_actor |
|
| enwiki | logging | log_actor_time | 2025-11-11 17:37:32 | n_diff_pfx02 | 130345567 | 20 | log_actor,log_timestamp |
|
| enwiki | logging | log_actor_time | 2025-11-11 17:37:32 | n_diff_pfx03 | 147813703 | 20 | log_actor,log_timestamp,log_id |
|
| enwiki | logging | log_actor_time | 2025-11-11 17:37:32 | n_leaf_pages | 415908 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_actor_time | 2025-11-11 17:37:32 | size | 455295 | NULL | Number of pages in the index |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | n_diff_pfx01 | 61528502 | 20 | log_actor |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | n_diff_pfx02 | 55982478 | 20 | log_actor,log_type |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | n_diff_pfx03 | 101053759 | 20 | log_actor,log_type,log_timestamp |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | n_diff_pfx04 | 148663055 | 20 | log_actor,log_type,log_timestamp,log_id |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | n_leaf_pages | 532938 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_actor_type_time | 2025-11-11 17:37:32 | size | 582720 | NULL | Number of pages in the index |
|
| enwiki | logging | log_page_id_time | 2025-11-11 17:37:32 | n_diff_pfx01 | 45599699 | 20 | log_page |
|
| enwiki | logging | log_page_id_time | 2025-11-11 17:37:32 | n_diff_pfx02 | 135454772 | 20 | log_page,log_timestamp |
|
| enwiki | logging | log_page_id_time | 2025-11-11 17:37:32 | n_diff_pfx03 | 155755867 | 20 | log_page,log_timestamp,log_id |
|
| enwiki | logging | log_page_id_time | 2025-11-11 17:37:32 | n_leaf_pages | 326122 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_page_id_time | 2025-11-11 17:37:32 | size | 353408 | NULL | Number of pages in the index |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | n_diff_pfx01 | 4632 | 20 | log_namespace |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | n_diff_pfx02 | 106810443 | 20 | log_namespace,log_title |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | n_diff_pfx03 | 150320637 | 20 | log_namespace,log_title,log_timestamp |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | n_diff_pfx04 | 156841851 | 20 | log_namespace,log_title,log_timestamp,log_id |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | n_leaf_pages | 665430 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_page_time | 2025-11-11 17:37:32 | size | 723903 | NULL | Number of pages in the index |
|
| enwiki | logging | log_times | 2025-11-11 17:37:32 | n_diff_pfx01 | 109263790 | 20 | log_timestamp |
|
| enwiki | logging | log_times | 2025-11-11 17:37:32 | n_diff_pfx02 | 148643480 | 20 | log_timestamp,log_id |
|
| enwiki | logging | log_times | 2025-11-11 17:37:32 | n_leaf_pages | 232947 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_times | 2025-11-11 17:37:32 | size | 253376 | NULL | Number of pages in the index |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | n_diff_pfx01 | 10805 | 20 | log_type |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | n_diff_pfx02 | 28139 | 20 | log_type,log_action |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | n_diff_pfx03 | 138896987 | 20 | log_type,log_action,log_timestamp |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | n_diff_pfx04 | 154234038 | 20 | log_type,log_action,log_timestamp,log_id |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | n_leaf_pages | 375448 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_type_action | 2025-11-11 17:37:32 | size | 398144 | NULL | Number of pages in the index |
|
| enwiki | logging | log_type_time | 2025-11-11 17:37:32 | n_diff_pfx01 | 11162 | 20 | log_type |
|
| enwiki | logging | log_type_time | 2025-11-11 17:37:32 | n_diff_pfx02 | 126611336 | 20 | log_type,log_timestamp |
|
| enwiki | logging | log_type_time | 2025-11-11 17:37:32 | n_diff_pfx03 | 156016272 | 20 | log_type,log_timestamp,log_id |
|
| enwiki | logging | log_type_time | 2025-11-11 17:37:32 | n_leaf_pages | 303770 | NULL | Number of leaf pages in the index |
|
| enwiki | logging | log_type_time | 2025-11-11 17:37:32 | size | 321088 | NULL | Number of pages in the index |
|
+---------------+------------+---------------------+---------------------+--------------+------------+-------------+----------------------------------------------+
|
40 rows in set (0.003 sec)
|
|
|
+---------------+------------+------------+---------------------+--------------+------------+-------------+-----------------------------------+
|
| database_name | table_name | index_name | last_update | stat_name | stat_value | sample_size | stat_description |
|
+---------------+------------+------------+---------------------+--------------+------------+-------------+-----------------------------------+
|
| enwiki | actor | PRIMARY | 2025-11-11 17:30:34 | n_diff_pfx01 | 114487418 | 20 | actor_id |
|
| enwiki | actor | PRIMARY | 2025-11-11 17:30:34 | n_leaf_pages | 424893 | NULL | Number of leaf pages in the index |
|
| enwiki | actor | PRIMARY | 2025-11-11 17:30:34 | size | 462271 | NULL | Number of pages in the index |
|
| enwiki | actor | actor_name | 2025-11-11 17:30:34 | n_diff_pfx01 | 114600323 | 20 | actor_name |
|
| enwiki | actor | actor_name | 2025-11-11 17:30:34 | n_leaf_pages | 311668 | NULL | Number of leaf pages in the index |
|
| enwiki | actor | actor_name | 2025-11-11 17:30:34 | size | 339904 | NULL | Number of pages in the index |
|
| enwiki | actor | actor_user | 2025-11-11 17:30:34 | n_diff_pfx01 | 62734020 | 20 | actor_user |
|
| enwiki | actor | actor_user | 2025-11-11 17:30:34 | n_leaf_pages | 123789 | NULL | Number of leaf pages in the index |
|
| enwiki | actor | actor_user | 2025-11-11 17:30:34 | size | 136383 | NULL | Number of pages in the index |
|
+---------------+------------+------------+---------------------+--------------+------------+-------------+-----------------------------------+
|
9 rows in set (0.002 sec)
|
If we ignore the index log_times the optimizer chooses the better index log_actor_time which runs the query in milliseconds
cumin2024@db1169.eqiad.wmnet[enwiki]> explain SELECT log_id,log_type,log_action,log_timestamp,log_deleted FROM `logging` ignore index (log_times) JOIN `actor` ON ((actor_id=log_actor)) WHERE (log_type NOT IN ('spamblacklist','titleblacklist','urlshortener','abusefilterprivatedetails','abusefilterblockeddomainhit','abusefilter-protected-vars','oath','checkuser-temporary-account','checkuser-private-event','ipinfo','suppress')) AND actor_name = 'DGG' AND ((log_deleted & 4) != 4) ORDER BY log_timestamp DESC,log_id DESC LIMIT 2;
|
+------+-------------+---------+-------+------------------------------------------------------------------+----------------+---------+-------+--------+-------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+---------+-------+------------------------------------------------------------------+----------------+---------+-------+--------+-------------+
|
| 1 | SIMPLE | actor | const | PRIMARY,actor_name | actor_name | 257 | const | 1 | Using index |
|
| 1 | SIMPLE | logging | range | log_actor_type_time,log_type_action,log_type_time,log_actor_time | log_actor_time | 8 | NULL | 188652 | Using where |
|
+------+-------------+---------+-------+------------------------------------------------------------------+----------------+---------+-------+--------+-------------+
|
2 rows in set (0.003 sec)
|
|
|
cumin2024@db1169.eqiad.wmnet[enwiki]> SELECT log_id,log_type,log_action,log_timestamp,log_deleted FROM `logging` ignore index (log_times) JOIN `actor` ON ((actor_id=log_actor)) WHERE (log_type NOT IN ('spamblacklist','titleblacklist','urlshortener','abusefilterprivatedetails','abusefilterblockeddomainhit','abusefilter-protected-vars','oath','checkuser-temporary-account','checkuser-private-event','ipinfo','suppress')) AND actor_name = 'DGG' AND ((log_deleted & 4) != 4) ORDER BY log_timestamp DESC,log_id DESC LIMIT 2;
|
|
|
|
|
<snipped>
|
|
|
2 rows in set (0.003 sec)
|
The optimizer traces are way too long to be pasted here, so I've left them at: https://phabricator.wikimedia.org/P85260
Is it normal that in the bad plan trace, both log_actor_time and log_times are marked "chosen": true under "possible_keys".?
Also, The bad plan reports: rows = 1781 for the logging table using log_times,
whereas the good plan (using log_actor_type_time) estimates: rows = 188652
The stats are up-to-date as shown above, so I am not sure what's going on here either.