[MDEV-20646] 10.3.18 is slower than 10.3.17 Created: 2019-09-23 Updated: 2019-12-06 Resolved: 2019-11-13 |
|
| Status: | Closed |
| Project: | MariaDB Server |
| Component/s: | Optimizer |
| Affects Version/s: | 10.3.18 |
| Fix Version/s: | 10.3.21 |
| Type: | Bug | Priority: | Critical |
| Reporter: | JaviN | Assignee: | Sergei Petrunia |
| Resolution: | Fixed | Votes: | 3 |
| Labels: | performance, regression | ||
| Environment: |
Centos 7 |
||
| Attachments: |
|
||||||||||||
| Issue Links: |
|
||||||||||||
| Description |
|
Hi, I work in a hosting company; we mainly offer hosting for Prestashop sites. We were using 10.3.17 and last week I updated to 10.3.18. After the update, we experienced a slowdown in several Prestashop sites in different servers, I suspected the problem appeared with the MariaDB upgrade, so I downgraded to 10.3.17 and the problem was gone. I have been debugging in a test server and I can confirm that one query generated by Prestashop was executing in 0m0.055s in 10.3.17 and in 1m16.021s in 10.3.18. Here are my tests:
Attached is the query. Thank you in advance |
| Comments |
| Comment by Christian Ciach [ 2019-10-11 ] | ||||||||||||||||||||||||
|
I can confirm this extreme performance issue after updating from 10.3.17 to 10.3.18. We had to do an immediate downgrade of all systems because of this (CentOS 7). I cannot give you concrete example queries at the moment, but I suspect that issue lies with the very long ` WHERE IN(...)` expressions that we're using a lot. EDIT: Every query that is slow with 10.3.18 does indeed include a very long list of IN-parameters. | ||||||||||||||||||||||||
| Comment by Axel Schwenke [ 2019-10-15 ] | ||||||||||||||||||||||||
|
I tried to reproduce the problem, but the provided query is of no use for me because I don't have the data it is running on. So I tried with some synthetic data, but could not reproduce the slowness you're seeing. My guess is, that the optimizer executes the IN () predicate differently in 10.3.18. Or maybe it's using a different table order and this has nothing to do with the long IN () list. Please provide the output from EXPLAIN FORMAT=JSON SELECT ... (insert your problem SELECT here) for both MariaDB 10.3.17 and 10.3.18. This kind of problem might be very hard to pinpoint even with EXPLAIN output. Is it possible that you share the data with us? This needn't be complete or live data. Just a dataset that demonstrates the problem. | ||||||||||||||||||||||||
| Comment by JaviN [ 2019-10-15 ] | ||||||||||||||||||||||||
|
Can I send you the data by email? I do not want to share it here. | ||||||||||||||||||||||||
| Comment by Axel Schwenke [ 2019-10-15 ] | ||||||||||||||||||||||||
|
Hi javii I suggest you upload your data to ftp://ftp.mariadb.com/uploads. You can also use ftps://.. to get transport encryption. This is a write-only location so nobody except MariaDB staff can read it. | ||||||||||||||||||||||||
| Comment by JaviN [ 2019-10-16 ] | ||||||||||||||||||||||||
|
Hi, I have uploaded the data to the ftp with More information: Output from EXPLAIN FORMAT=JSON SELECT with MariaDb 10.3.17: \n }\n },\n "duplicates_removal": {\n "table": {\n "table_name": "cp",\n "access_type": "ref",\n "possible_keys": ["PRIMARY", "id_product", "id_category"],\n "key": "id_product",\n "key_length": "4",\n "used_key_parts": ["id_product"],\n "ref": ["prestashop_1.product_shop.id_product"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "cg",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY", "id_category", "id_group"],\n "key": "PRIMARY",\n "key_length": "8",\n "used_key_parts": ["id_category", "id_group"],\n "ref": ["prestashop_1.cp.id_category", "const"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "p",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY"],\n "key": "PRIMARY",\n "key_length": "4",\n "used_key_parts": ["id_product"],\n "ref": ["prestashop_1.product_shop.id_product"],\n "rows": 1,\n "filtered": 100\n }\n },\n "table": {\n "table_name": "product_attribute_shop",\n "access_type": "ref",\n "possible_keys": ["id_product"],\n "key": "id_product",\n "key_length": "10",\n "used_key_parts": ["id_product", "id_shop", "default_on"],\n "ref": ["prestashop_1.product_shop.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "<subquery3>",\n "access_type": "eq_ref",\n "possible_keys": ["distinct_key"],\n "key": "distinct_key",\n "key_length": "4",\n "used_key_parts": ["_col_1"],\n "ref": ["func"],\n "rows": 1,\n "filtered": 100,\n "attached_condition": "product_shop.id_product = tvc_0._col_1",\n "materialized": {\n "unique": 1,\n "query_block": {\n "select_id": 3,\n "table": {\n "table_name": "<derived4>",\n "access_type": "ALL",\n "rows": 25742,\n "filtered": 100,\n "materialized": {\n "query_block": {\n "union_result": {\n "table_name": "<unit4>",\n "access_type": "ALL",\n "query_specifications": [\n {\n "query_block": {\n "select_id": 4,\n "table": {\n "message": "No tables used"\n }\n }\n }\n ]\n }\n }\n }\n }\n }\n }\n },\n "table": {\n "table_name": "stock",\n "access_type": "eq_ref",\n "possible_keys": [\n "product_sqlstock",\n "id_shop",\n "id_shop_group",\n "id_product",\n "id_product_attribute"\n ],\n "key": "product_sqlstock",\n "key_length": "16",\n "used_key_parts": [\n "id_product",\n "id_product_attribute",\n "id_shop",\n "id_shop_group"\n ],\n "ref": ["prestashop_1.product_shop.id_product", "const", "const", "const"],\n "rows": 1,\n "filtered": 100\n },\n "table": {\n "table_name": "pl",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY", "id_lang"],\n "key": "PRIMARY",\n "key_length": "12",\n "used_key_parts": ["id_product", "id_shop", "id_lang"],\n "ref": ["prestashop_1.product_shop.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100\n },\n "table": {\n "table_name": "image_shop",\n "access_type": "ref",\n "possible_keys": ["id_product", "id_shop"],\n "key": "id_product",\n "key_length": "10",\n "used_key_parts": ["id_product", "id_shop", "cover"],\n "ref": ["prestashop_1.product_shop.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "il",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY", "id_image"],\n "key": "PRIMARY",\n "key_length": "8",\n "used_key_parts": ["id_image", "id_lang"],\n "ref": ["prestashop_1.image_shop.id_image", "const"],\n "rows": 1,\n "filtered": 100,\n "attached_condition": "trigcond(trigcond(image_shop.id_image is not null))"\n },\n "table": {\n "table_name": "m",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY"],\n "key": "PRIMARY",\n "key_length": "4",\n "used_key_parts": ["id_manufacturer"],\n "ref": ["prestashop_1.p.id_manufacturer"],\n "rows": 1,\n "filtered": 100,\n "attached_condition": "trigcond(trigcond(p.id_manufacturer is not null))"\n }\n }\n} Output from EXPLAIN FORMAT=JSON SELECT with MariaDb 10.3.18: ,\n "table": {\n "table_name": "cp",\n "access_type": "ref",\n "possible_keys": ["PRIMARY", "id_product", "id_category"],\n "key": "PRIMARY",\n "key_length": "4",\n "used_key_parts": ["id_category"],\n "ref": ["prestashop_1.cg.id_category"],\n "rows": 75,\n "filtered": 100,\n "using_index": true\n }\n }\n }\n },\n "table": {\n "table_name": "p",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY"],\n "key": "PRIMARY",\n "key_length": "4",\n "used_key_parts": ["id_product"],\n "ref": ["prestashop_1.cp.id_product"],\n "rows": 1,\n "filtered": 100\n },\n "duplicates_removal": {\n "table": {\n "table_name": "<derived4>",\n "access_type": "ref",\n "possible_keys": ["key0"],\n "key": "key0",\n "key_length": "4",\n "used_key_parts": ["_col_1"],\n "ref": ["prestashop_1.cp.id_product"],\n "rows": 10,\n "filtered": 100,\n "attached_condition": "cp.id_product = tvc_0._col_1",\n "materialized": {\n "query_block": {\n "union_result": {\n "table_name": "<unit4>",\n "access_type": "ALL",\n "query_specifications": [\n {\n "query_block": {\n "select_id": 4,\n "table": {\n "message": "No tables used"\n }\n }\n }\n ]\n }\n }\n }\n }\n },\n "block-nl-join": {\n "table": {\n "table_name": "product_shop",\n "access_type": "ALL",\n "possible_keys": ["PRIMARY"],\n "rows": 5060,\n "filtered": 75,\n "attached_condition": "product_shop.active = 1 and product_shop.show_price = 1 and product_shop.id_shop = 1 and product_shop.visibility in ('both','catalog')"\n },\n "buffer_type": "flat",\n "buffer_size": "512Kb",\n "join_type": "BNL",\n "attached_condition": "product_shop.id_product = cp.id_product"\n },\n "table": {\n "table_name": "product_attribute_shop",\n "access_type": "ref",\n "possible_keys": ["id_product"],\n "key": "id_product",\n "key_length": "10",\n "used_key_parts": ["id_product", "id_shop", "default_on"],\n "ref": ["prestashop_1.cp.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "stock",\n "access_type": "eq_ref",\n "possible_keys": [\n "product_sqlstock",\n "id_shop",\n "id_shop_group",\n "id_product",\n "id_product_attribute"\n ],\n "key": "product_sqlstock",\n "key_length": "16",\n "used_key_parts": [\n "id_product",\n "id_product_attribute",\n "id_shop",\n "id_shop_group"\n ],\n "ref": ["prestashop_1.cp.id_product", "const", "const", "const"],\n "rows": 1,\n "filtered": 100\n },\n "table": {\n "table_name": "pl",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY", "id_lang"],\n "key": "PRIMARY",\n "key_length": "12",\n "used_key_parts": ["id_product", "id_shop", "id_lang"],\n "ref": ["prestashop_1.cp.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100\n },\n "table": {\n "table_name": "image_shop",\n "access_type": "ref",\n "possible_keys": ["id_product", "id_shop"],\n "key": "id_product",\n "key_length": "10",\n "used_key_parts": ["id_product", "id_shop", "cover"],\n "ref": ["prestashop_1.cp.id_product", "const", "const"],\n "rows": 1,\n "filtered": 100,\n "using_index": true\n },\n "table": {\n "table_name": "il",\n "access_type": "eq_ref",\n "possible_keys": ["PRIMARY", "id_image"],\n "key": "PRIMARY",\n "key_length": "8",\n "used_key_parts": ["id_image", "id_lang"],\n "ref": ["prestashop_1.image_shop.id_image", "const"],\n "rows": 1,\n "filtered": 100,\n "attached_condition": "trigcond(trigcond(image_shop.id_image is not null))"\n },\n "block-nl-join": {\n "table": {\n "table_name": "m",\n "access_type": "ALL",\n "possible_keys": ["PRIMARY"],\n "rows": 3,\n "filtered": 100\n },\n "buffer_type": "flat",\n "buffer_size": "512Kb",\n "join_type": "BNL",\n "attached_condition": "trigcond(m.id_manufacturer = p.id_manufacturer)"\n }\n }\n }\n }\n} Thank you. Kind regards | ||||||||||||||||||||||||
| Comment by Axel Schwenke [ 2019-10-17 ] | ||||||||||||||||||||||||
|
javii thanks for the data set. I reproduced the problem. The query executes in ~100ms on 10.3.17, but needs ~5 sec on 10.3.18. | ||||||||||||||||||||||||
| Comment by Axel Schwenke [ 2019-10-17 ] | ||||||||||||||||||||||||
|
I traced this regression to this commit
The execution plan of the query changed completely. And it takes now 50 times longer on my test system and more than 1000 times longer on the customer system. | ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-04 ] | ||||||||||||||||||||||||
|
So far I haven't been able to reproduce, for me the query runs in ~0.8 sec (on a debug build) both before and after the patch: | ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-05 ] | ||||||||||||||||||||||||
|
Taking EXPLAIN outputs provided in this comment https://jira.mariadb.org/browse/MDEV-20646?focusedCommentId=136050&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-136050 https://gist.github.com/spetrunia/fec6c0f54339964f2a11461f78f1f8e1 | ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-05 ] | ||||||||||||||||||||||||
|
The query's outline
| ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-05 ] | ||||||||||||||||||||||||
|
Outline of the EXPLAIN posted for 10.3.17:
Note that the plan may short-circuit the ORDER BY ... LIMIT execution. Most of the tables have rows:1, with exception of "Materialized" node which is created from a long IN-list (which is likely to be materialized anyhow). | ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-05 ] | ||||||||||||||||||||||||
|
Outline of the posted EXPLAIN from 10.3.18:
| ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-05 ] | ||||||||||||||||||||||||
| ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-06 ] | ||||||||||||||||||||||||
|
The questionable line is this one in Sj_materialization_picker::check_qep:
| ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-06 ] | ||||||||||||||||||||||||
|
The optimizer constructs a join prefix:
enters advance_sj_state, enters Sj_materialization_picker::check_qep. Now,
The above line just removes mat_info->rows_with_duplicates from the fanout. What is left is the fanout of table p, which uses eq_ref access, and and has fanout=1. (The logic used by the problematic line would have applied if table p used an "independent" access method. But it fails when it refers to the fields in the subquery ) | ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-13 ] | ||||||||||||||||||||||||
1. Problem descriptionConsider a query
and this (possibly partial) join order:
What is its output cardinality? This question is important, because in MySQL/MariaDB optimizer the cost of query plan has this component:
and this component often is a big (or even biggest) part of the query plan cost. 2. Removing subquery's fanoutAs we saw, the output cardinality of this join prefix
must not include subquery's fanout. This is trivial when tables ot_i do not use ref access that refers to the materialized table. We can just compute Product{over_i}(ot_i.records_read) . A more interesting case is when ot_i does use ref access(es) that refer to the materialized table. 2.1. A wrong approachAn approach that seems tempting is to take the output cardinality of the join order of
(without the subquery in front) and use that. But this is not a good idea, consider this example:
and the join order
Here, just taking the cardinality of "people" will be a vast over-estimation as most people dont own airplanes. 2.2. Towards something betterSo, the code we had before the patch for
| ||||||||||||||||||||||||
| Comment by Sergei Petrunia [ 2019-11-13 ] | ||||||||||||||||||||||||
|
ANALYZE output for the example query on the patched version: https://gist.github.com/spetrunia/b4cb8d7d7a625ed51b86448f731ba50b |