|
formatting the query:
SELECT
|
main.*
|
FROM `ibf_core_search_index` AS `main`
|
WHERE
|
(
|
index_class IN ('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply')
|
OR
|
index_class= 'IPS\\forums\\Topic\\Post'
|
OR
|
index_class IN ('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review')
|
)
|
AND
|
(
|
( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') AND index_is_last_comment=1 )
|
OR
|
( index_class='IPS\\forums\\Topic\\Post' AND index_is_last_comment=1 )
|
OR
|
( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment') AND index_is_last_comment=1 )
|
)
|
AND
|
(
|
index_permissions = '*' OR
|
( FIND_IN_SET(24,index_permissions) OR FIND_IN_SET('m39839',index_permissions) )
|
)
|
AND
|
index_hidden=0
|
AND
|
index_date_updated>1466861141
|
|
ORDER BY
|
index_date_updated DESC
|
LIMIT 0,25;
|
|
|
The query with non-important parts removed:
SELECT
|
main.*
|
FROM
|
`ibf_core_search_index` AS `main`
|
WHERE
|
...
|
AND
|
index_hidden=0
|
AND
|
index_date_updated>1466861141
|
ORDER BY
|
index_date_updated DESC
|
LIMIT 0,25;
|
both index_hidden and index_date_updated seem to have indexes (see possible_keys).
|
|
The posted slow query log shows that
1. it uses a ref(const) scan on "index_hidden=0"
2. 1.6M rows are scanned
3. filesort is used to satisfy ORDER BY ... LIMIT
The choice looks odd. The optimizer should get a fairly precise estimate on how many rows match "index_hidden=0" condition. If the condition is not selective, why did we pick it at all? Doing a full table scan would be cheaper.
|
|
Venâncio Ferreira, are you running with the default @@optimizer_switch setting? If not, please post your setting for that parameter.
Also, is it possible to get output for the following commands (it doesn't matter if they are run against 10.0.15 or 10.0.14):
SHOW CREATE TABLE ibf_core_search_index;
|
explain select * from ibf_core_search_index where index_hidden=0;
|
explain select * from ibf_core_search_index force index (index_hidden) where index_hidden=0;
|
explain select * from ibf_core_search_index where index_date_updated>1466861141;
|
explain select * from ibf_core_search_index force index(index_date_updated) where index_date_updated>1466861141;
|
It will also help us to get the output of ANALYZE FORMAT=JSON for the query, in both 10.1.14, and 10.1.15, or in whatever server you have running (but please indicate which one it is):
ANALYZE FORMAT=JSON SELECT main.* FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) ) AND ( ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) AND index_is_last_comment=1 ) OR ( index_class='IPS\\forums\\Topic\\Post' AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment') ) AND index_is_last_comment=1 ) ) AND ( index_permissions = '*' OR ( FIND_IN_SET(24,index_permissions) OR FIND_IN_SET('m39839',index_permissions) ) ) AND index_hidden=0 AND index_date_updated>1466861141 ORDER BY index_date_updated DESC LIMIT 0,25;
|
|
|
@Sergei Petrunia im using the default optimizer_switch.
In case it might help, here is my.cnf:
[mysqld]
|
datadir=/var/lib/mysql
|
socket=/var/lib/mysql/mysql.sock
|
user=mysql
|
symbolic-links=0
|
max_connections=120
|
max_user_connections=120
|
wait_timeout=300
|
interactive_timeout=300
|
skip-name-resolve
|
max-connect-errors=1000000
|
|
#Slow Queries
|
slow_query_log = 1
|
slow_query_log_file=/var/log/mysq-slow.log
|
long_query_time=1
|
log_slow_verbosity=Query_plan,explain,Innodb
|
|
#InnoDB
|
innodb_file_per_table
|
innodb_flush_method=O_DIRECT
|
innodb_flush_log_at_trx_commit=0
|
innodb_buffer_pool_size =4G
|
innodb_log_file_size=256M
|
innodb_read_io_threads=4
|
innodb_write_io_threads=4
|
innodb_buffer_pool_instances=4
|
innodb_buffer_pool_dump_at_shutdown = 1
|
innodb_buffer_pool_load_at_startup = 1
|
transaction-isolation = READ-COMMITTED
|
innodb_flush_neighbors=0
|
innodb-defragment=0
|
innodb_file_format=BARRACUDA
|
innodb_large_prefix=1
|
|
#MyISAM
|
key_buffer_size=32M
|
aria_pagecache_buffer_size=256M
|
ft_min_word_len=3
|
|
#Thread Cache
|
thread_handling = pool-of-threads
|
|
#Table cache
|
table_open_cache=1000
|
open_files_limit=2000
|
|
#Buffers
|
join_buffer_size=2M
|
read_buffer_size=128K
|
sort_buffer_size=256K
|
|
#Query Cache
|
query_cache_type=1
|
query_cache_size=128M
|
query_cache_limit=6M
|
query_cache_strip_comments=1
|
|
#Temporary Tables
|
tmp_table_size=256M
|
max_heap_table_size=256M
|
Here are the output of the commands running against 10.1.14
SHOW CREATE TABLE ibf_core_search_index;
|
|
ibf_core_search_index | CREATE TABLE `ibf_core_search_index` (
|
`index_class` varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL COMMENT 'Content type class e.g. \\IPS\\forums\\Topic',
|
`index_id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT 'Primary key',
|
`index_object_id` int(10) unsigned NOT NULL DEFAULT '0' COMMENT 'The ID of the object. pid for posts, tid for topics etc',
|
`index_item_id` int(10) unsigned NOT NULL DEFAULT '0' COMMENT 'For comments and reviews, the ID of the item it pertains to. For \\IPS\\Content\\Item this would just be NULL',
|
`index_container_id` int(10) unsigned NOT NULL DEFAULT '0' COMMENT 'The id of the container for items/comments/reviews',
|
`index_content` mediumtext COLLATE utf8mb4_unicode_ci NOT NULL COMMENT 'The plain-text content to search',
|
`index_permissions` text COLLATE utf8mb4_unicode_ci NOT NULL COMMENT 'A comma-delimited list of groups which have permission to view',
|
`index_author` int(10) unsigned NOT NULL DEFAULT '0' COMMENT 'The object author id',
|
`index_title` varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL COMMENT 'Content title',
|
`index_date_created` int(10) unsigned NOT NULL DEFAULT '0' COMMENT 'The object creation date',
|
`index_date_updated` int(10) unsigned DEFAULT NULL COMMENT 'Object last updated date',
|
`index_hidden` tinyint(1) NOT NULL DEFAULT '0' COMMENT '0 = visible, -1 = hidden (previously visible), 1 = unapproved, 2 = parent item hidden',
|
`index_item_index_id` bigint(20) unsigned DEFAULT NULL COMMENT 'The index ID of the item',
|
`index_item_author` mediumint(8) DEFAULT NULL COMMENT 'The author of the item',
|
`index_is_last_comment` tinyint(1) NOT NULL DEFAULT '0' COMMENT 'Is this the last comment/review on an item?',
|
PRIMARY KEY (`index_id`),
|
UNIQUE KEY `object` (`index_class`(181),`index_object_id`),
|
KEY `author_lookup` (`index_author`,`index_hidden`,`index_date_updated`),
|
KEY `index_date_updated` (`index_date_updated`),
|
KEY `index_date_created` (`index_date_created`),
|
KEY `index_hidden` (`index_hidden`),
|
KEY `item` (`index_class`(181),`index_item_id`),
|
KEY `container` (`index_class`(181),`index_container_id`),
|
FULLTEXT KEY `index_content` (`index_content`,`index_title`),
|
FULLTEXT KEY `index_title` (`index_title`)
|
) ENGINE=InnoDB AUTO_INCREMENT=1664302 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci ROW_FORMAT=DYNAMIC
|
explain select * from ibf_core_search_index where index_hidden=0;
|
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
| 1 | SIMPLE | ibf_core_search_index | ref | index_hidden | index_hidden | 1 | const | 864536 | |
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
explain select * from ibf_core_search_index force index (index_hidden) where index_hidden=0;
|
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
| 1 | SIMPLE | ibf_core_search_index | ref | index_hidden | index_hidden | 1 | const | 864536 | |
|
+------+-------------+-----------------------+------+---------------+--------------+---------+-------+--------+-------+
|
explain select * from ibf_core_search_index where index_date_updated>1466861141;
|
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
| 1 | SIMPLE | ibf_core_search_index | range | index_date_updated | index_date_updated | 5 | NULL | 2287 | Using index condition |
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
explain select * from ibf_core_search_index force index(index_date_updated) where index_date_updated>1466861141;
|
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
| 1 | SIMPLE | ibf_core_search_index | range | index_date_updated | index_date_updated | 5 | NULL | 2289 | Using index condition |
|
+------+-------------+-----------------------+-------+--------------------+--------------------+---------+------+------+-----------------------+
|
The following query is running with 10.1.14. I can't find anymore 10.1.15 rpm in MariaDB download section.
ANALYZE FORMAT=JSON SELECT main.* FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) ) AND ( ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) AND index_is_last_comment=1 ) OR ( index_class='IPS\\forums\\Topic\\Post' AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment') ) AND index_is_last_comment=1 ) ) AND ( index_permissions = '*' OR ( FIND_IN_SET(24,index_permissions) OR FIND_IN_SET('m39839',index_permissions) ) ) AND index_hidden=0 AND index_date_updated>1466861141 ORDER BY index_date_updated DESC LIMIT 0,25;
|
|
{
|
"query_block": {
|
"select_id": 1,
|
"r_loops": 1,
|
"r_total_time_ms": 3.5166,
|
"table": {
|
"table_name": "main",
|
"access_type": "range",
|
"possible_keys": [
|
"object",
|
"index_date_updated",
|
"index_hidden",
|
"item",
|
"container"
|
],
|
"key": "index_date_updated",
|
"key_length": "5",
|
"used_key_parts": ["index_date_updated"],
|
"r_loops": 1,
|
"rows": 2300,
|
"r_rows": 161,
|
"r_total_time_ms": 2.8552,
|
"filtered": 75,
|
"r_filtered": 15.528,
|
"attached_condition": "((main.index_hidden = 0) and ((main.index_class in ('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply')) or (main.index_class = 'IPS\\forums\\Topic\\Post') or (main.index_class in ('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review'))) and (((main.index_is_last_comment = 1) and (main.index_class in ('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply'))) or ((main.index_is_last_comment = 1) and (main.index_class = 'IPS\\forums\\Topic\\Post')) or ((main.index_is_last_comment = 1) and (main.index_class in ('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment')))) and ((main.index_permissions = '*') or find_in_set(24,main.index_permissions) or find_in_set('m39839',main.index_permissions)) and (main.index_date_updated > 1466861141))"
|
}
|
}
|
}
|
|
|
Venâncio Ferreira, thanks for the posted information. It allows to investigate.
|
|
Debugging the optimizer with simulated row counts as posted above, found one odd thing:
I get query plans like this:
+------+-------------+-------+------+---------------------------------+--------------+---------+-------+------+-----------------------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+-------+------+---------------------------------+--------------+---------+-------+------+-----------------------------+
|
| 1 | SIMPLE | main | ref | index_date_updated,index_hidden | index_hidden | 1 | const | 1 | Using where; Using filesort |
|
+------+-------------+-------+------+---------------------------------+--------------+---------+-------+------+-----------------------------+
|
with rows=1. Breakpoint in ha_innobase::records_in_range() catches the call for index_date_updated, but not for index_hidden.
Investigating where rows=1 could come from, located this patch:
https://github.com/MariaDB/server/commit/1859caf60b725f81f2ac6091eb44cb848a4a439a
The patch itself looks harmless. However, things don't work as the patch intended.
(gdb) p table->key_info[5]
|
$124 = {key_length = 1, flags = 0,
|
user_defined_key_parts = 1,
|
usable_key_parts = 1,
|
ext_key_parts = 1,
|
ext_key_flags = 0,
|
ext_key_part_map = 0,
|
block_size = 0,
|
name_length = 12, algorithm = HA_KEY_ALG_UNDEF, is_statistics_from_stat_tables = false, {parser = 0x0, parser_name = 0x0},
|
key_part = 0x7fff5001a098,
|
name = 0x7fff5001fa4c "index_hidden", cache_name = 0x7fff50011ff8 "j21", rec_per_key = 0x7fff5004a048, read_stats = 0x0, collected_stats = 0x0, handler = {bdb_return_if_eq = 0}, table = 0x7fff500154a0, comment = {str = 0x0, length = 0}, option_list = 0x0, option_struct = 0x0}
|
Why do we have user_defined_key_parts==ext_key_parts=1 ??? The keys are defined as
KEY `index_hidden` (`index_hidden`),
|
...
|
PRIMARY KEY (`index_id`),
|
So I would have expected ext_key_parts=2. with ext_key_parts==1 the optimizer assumes the condition "index_hidden=0" is a unique key condition, and produces a query plan with rows=1 which is a vast under-estimate.
|
|
Indeed.. when I create a test table with keys like this:
key(col1, col2),
|
primary key(pk1, pk2,pk3)
|
I get
(gdb) p param->table->key_info[1]
|
$134 = {key_length = 10, flags = 64,
|
user_defined_key_parts = 2,
|
usable_key_parts = 5, ext_key_parts = 5, <<<----------
|
ext_key_flags = 131136, ext_key_part_map = 7,
|
|
|
I've narrowed it down to two tables, with identical columns and indexes, except
that the order of indexes is different:
create table t200 (
|
index_id bigint(20) unsigned NOT NULL AUTO_INCREMENT ,
|
index_class varchar(265) COLLATE latin1_general_ci DEFAULT NULL ,
|
index_object_id int(10) unsigned NOT NULL DEFAULT '0' ,
|
index_date_updated int(10) unsigned DEFAULT NULL ,
|
|
PRIMARY KEY (index_id),
|
KEY object (index_class(181),index_object_id),
|
KEY index_date_updated (index_date_updated)
|
) engine=innodb;
|
create table t200swp (
|
index_id bigint(20) unsigned NOT NULL AUTO_INCREMENT ,
|
index_class varchar(265) COLLATE latin1_general_ci DEFAULT NULL ,
|
index_object_id int(10) unsigned NOT NULL DEFAULT '0' ,
|
index_date_updated int(10) unsigned DEFAULT NULL ,
|
|
PRIMARY KEY (index_id),
|
KEY index_date_updated (index_date_updated),
|
KEY object (index_class(181),index_object_id)
|
) engine=innodb;
|
Now, look at the key defintions.
(gdb) p table->s.table_name
|
$209 = {str = 0x7fff501ae65c "t200", length = 4}
|
(gdb) p table->key_info[0]
|
$210 = {key_length = 8, flags = 1, user_defined_key_parts = 1,
|
usable_key_parts = 1, ext_key_parts = 1, ext_key_flags = 1,
|
ext_key_part_map = 0, ... name = 0x7fff501a4f99 "PRIMARY",... }
|
(gdb) p table->key_info[1]
|
$211 = {key_length = 188, flags = 104, user_defined_key_parts = 2,
|
usable_key_parts = 2, ext_key_parts = 2, ext_key_flags = 104,
|
ext_key_part_map = 0, ... name = 0x7fff501a4fa1 "object" ... }
|
(gdb) p table->key_info[2]
|
$212 = {key_length = 5, flags = 64, user_defined_key_parts = 1,
|
usable_key_parts = 1, ext_key_parts = 1, ext_key_flags = 64,
|
ext_key_part_map = 0, ... name = 0x7fff501a4fa8 "index_date_updated"}
|
(gdb) p table->s.table_name
|
$216 = {str = 0x7fff501b25bc "t200swp", length = 7}
|
(gdb) p table->key_info[0]
|
$217 = {key_length = 8, flags = 1, user_defined_key_parts = 1,
|
usable_key_parts = 1, ext_key_parts = 1, ext_key_flags = 1,
|
ext_key_part_map = 0, ... name = 0x7fff501b4479 "PRIMARY"}
|
(gdb) p table->key_info[1]
|
$218 = {key_length = 5, flags = 64, user_defined_key_parts = 1,
|
usable_key_parts = 2, ext_key_parts = 2, ext_key_flags = 131136,
|
ext_key_part_map = 1, ... name = 0x7fff501b4481 "index_date_updated"}
|
(gdb) p table->key_info[2]
|
$219 = {key_length = 188, flags = 104, user_defined_key_parts = 2,
|
usable_key_parts = 2, ext_key_parts = 2, ext_key_flags = 104,
|
ext_key_part_map = 0, ... name = 0x7fff501b4494 "object", }
|
Compare the attributes of 'index_date_updated' key:
t200swp has user_defined_key_parts=1, ext_key_parts=2, correct.
t200 has: user_defined_key_parts=1, ext_key_parts=1. Why 1?
I could understand that there may be some limitations that prevent inclusion of
PK components into the secondary key (like maximum index tuple length
perhaps?)
What I don't understand is why the order of indexes in the table plays a role.
BTW, this particular bug could be fixed by adjusting the patch 1859caf60b725f81f2ac6091eb44cb848a4a439a
to check ext_key_part_map.
if ext_key_part_map doesn't cover all PK components, then UNIQUE_RANGE flag should not be set.
|
|
Hmm, use of ext_key_part_map that I've proposed in the last comment won't be entirely correct. The docs say:
/*
|
Parts of primary key that are in the extension of this index.
|
|
Example: if this structure describes idx1, which is defined as
|
INDEX idx1 (pk2, col2)
|
and pk is defined as:
|
PRIMARY KEY (pk1, pk2)
|
then
|
pk1 is in the extension idx1, ext_key_part_map.is_set(0) == true
|
pk2 is explicitly present in idx1, it is not in the extension, so
|
ext_key_part_map.is_set(1) == false
|
*/
|
key_part_map ext_key_part_map;
|
|
|
Ok, the reason behind key attributes depending on the order of
keys in the table is how add_first_key_parts variable is handled
inside TABLE_SHARE::init_from_binary_frm_image().
The function has a piece of logic starting with text
Do not extend the key that contains a component
|
defined over the beginning of a field.
|
That piece sets add_first_key_parts=0 and never resets it for the subsequent indexes.
|
|
Found this:
/* This flag can be used only in KEY::ext_key_flags */
|
#define HA_EXT_NOSAME 131072
|
maybe, this is the check that should have been used in 1859caf60b725f81f2ac6091eb44cb848a4a439a.
|
|
Committed a fix for this particular bug using HA_EXT_NOSAME: http://lists.askmonty.org/pipermail/commits/2016-July/009538.html
Branching off the part about the order of indexes into MDEV-10360.
|
|
@Sergei Petrunia i can confirm the issue is fixed with MariaDB 10.1.16.
Many thanks for the fast fixing.
|
|
Venâncio Ferreira, our pleasure. Thanks for the confirmation that the fix is working!
|