Page MenuHomePhabricator

Possibly disable optimizer flag: rowid_filter on 10.4
Closed, ResolvedPublic

Description

I have noticed the following slow API query on 10.4 (db1107):

SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501 /* ebd959f27d0c6fd989d1561b40ae8a3b db1107 enwiki 24s */

That query on 10.4 takes around 28 seconds, whereas on 10.1 takes around 0.1.

Examining the query plan, it is identical, but 10.4 shows the following difference:

+------+-------------+---------------+--------------+-----------------------------------------------+----------------------+---------+------------------------------+----------+-------------------------------------------------+
| id   | select_type | table         | type         | possible_keys                                 | key                  | key_len | ref                          | rows     | Extra                                           |
+------+-------------+---------------+--------------+-----------------------------------------------+----------------------+---------+------------------------------+----------+-------------------------------------------------+
|    1 | SIMPLE      | externallinks | range|filter | el_from,el_index,el_index_60,el_from_index_60 | el_index|el_index_60 | 62|62   | NULL                         | 553 (0%) | Using where; Using filesort; **Using rowid filter** |
|    1 | SIMPLE      | page          | eq_ref       | PRIMARY                                       | PRIMARY              | 4       | enwiki.externallinks.el_from | 1        |                                                 |
+------+-------------+---------------+--------------+-----------------------------------------------+----------------------+---------+------------------------------+----------+-------------------------------------------------+
2 rows in set (0.00 sec)

Looks like it is a new feature on 10.4: https://mariadb.com/kb/en/rowid-filtering-optimization/ but in this case it is causing the query to run slower.
By, changing it on the optimizer and running the query again, it runs as fast as 10.1:

root@db1107.eqiad.wmnet[enwiki]> select @@optimizer_switch;
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| @@optimizer_switch                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=on,mrr_cost_based=on,mrr_sort_keys=on,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

root@db1107.eqiad.wmnet[enwiki]> set session optimizer_switch='index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=on,mrr_cost_based=on,mrr_sort_keys=on,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=off,condition_pushdown_from_having=on';
Query OK, 0 rows affected (0.00 sec)

<query snip>
501 rows in set (0.00 sec)


root@db1107.eqiad.wmnet[enwiki]> explain SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501 /* ebd959f27d0c6fd989d1561b40ae8a3b db1107 enwiki 24s */;
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
| id   | select_type | table         | type   | possible_keys                                 | key      | key_len | ref                          | rows | Extra                       |
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
|    1 | SIMPLE      | externallinks | range  | el_from,el_index,el_index_60,el_from_index_60 | el_index | 62      | NULL                         | 553  | Using where; Using filesort |
|    1 | SIMPLE      | page          | eq_ref | PRIMARY                                       | PRIMARY  | 4       | enwiki.externallinks.el_from | 1    |                             |
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
2 rows in set (0.00 sec)

Logging out from that session, and running the query again with the original optimizer settings:

501 rows in set (25.38 sec)

Event Timeline

Mentioned in SAL (#wikimedia-operations) [2020-02-18T08:06:23Z] <marostegui@cumin1001> dbctl commit (dc=all): 'Depool db1107 to temporary change optimizer options - T245489', diff saved to https://phabricator.wikimedia.org/P10440 and previous config saved to /var/cache/conftool/dbconfig/20200218-080623-marostegui.json

Mentioned in SAL (#wikimedia-operations) [2020-02-18T08:08:16Z] <marostegui> Restart MySQL to pick up optimizer_switch changes - T245489

Mentioned in SAL (#wikimedia-operations) [2020-02-18T08:09:53Z] <marostegui@cumin1001> dbctl commit (dc=all): 'Slowly repool db1107 after temporary change optimizer options - T245489', diff saved to https://phabricator.wikimedia.org/P10441 and previous config saved to /var/cache/conftool/dbconfig/20200218-080952-marostegui.json

Change 572811 had a related patch set uploaded (by Marostegui; owner: Marostegui):
[operations/puppet@production] production.my.cnf: Disable rowid_filter on 10.4

https://gerrit.wikimedia.org/r/572811

Change 572811 merged by Marostegui:
[operations/puppet@production] production.my.cnf: Disable rowid_filter on 10.4

https://gerrit.wikimedia.org/r/572811

I have disabled it on puppet for 10.4 for production hosts for now. It will also be needed for multiinstance if we finally decide to go for 10.4

Marostegui triaged this task as Medium priority.Feb 18 2020, 8:21 AM
Marostegui moved this task from Triage to In progress on the DBA board.

Mentioned in SAL (#wikimedia-operations) [2020-02-18T08:23:07Z] <marostegui@cumin1001> dbctl commit (dc=all): 'Slowly repool db1107 after temporary change optimizer options - T245489', diff saved to https://phabricator.wikimedia.org/P10442 and previous config saved to /var/cache/conftool/dbconfig/20200218-082306-marostegui.json

Mentioned in SAL (#wikimedia-operations) [2020-02-18T09:13:44Z] <marostegui@cumin1001> dbctl commit (dc=all): 'Fully repool db1107 after temporary change optimizer options - T245489', diff saved to https://phabricator.wikimedia.org/P10444 and previous config saved to /var/cache/conftool/dbconfig/20200218-091343-marostegui.json

root@db1107.eqiad.wmnet[enwiki]> explain SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501 /* ebd959f27d0c6fd989d1561b40ae8a3b db1107 enwiki 24s */;
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
| id   | select_type | table         | type   | possible_keys                                 | key      | key_len | ref                          | rows | Extra                       |
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
|    1 | SIMPLE      | externallinks | range  | el_from,el_index,el_index_60,el_from_index_60 | el_index | 62      | NULL                         | 553  | Using where; Using filesort |
|    1 | SIMPLE      | page          | eq_ref | PRIMARY                                       | PRIMARY  | 4       | enwiki.externallinks.el_from | 1    |                             |
+------+-------------+---------------+--------+-----------------------------------------------+----------+---------+------------------------------+------+-----------------------------+
2 rows in set (0.00 sec)

The plan it really should be using is

wikiadmin@10.64.0.214(enwiki)> explain SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;
+------+-------------+---------------+--------+-----------------------------------------------+-------------+---------+------------------------------+------+------------------------------------+
| id   | select_type | table         | type   | possible_keys                                 | key         | key_len | ref                          | rows | Extra                              |
+------+-------------+---------------+--------+-----------------------------------------------+-------------+---------+------------------------------+------+------------------------------------+
|    1 | SIMPLE      | externallinks | range  | el_from,el_index,el_index_60,el_from_index_60 | el_index_60 | 62      | NULL                         | 553  | Using index condition; Using where |
|    1 | SIMPLE      | page          | eq_ref | PRIMARY                                       | PRIMARY     | 4       | enwiki.externallinks.el_from | 1    |                                    |
+------+-------------+---------------+--------+-----------------------------------------------+-------------+---------+------------------------------+------+------------------------------------+

i.e. using the el_index_60 index instead of el_index.

We can now actually try to see what the optimizer is really doing:

root@db1107.eqiad.wmnet[(none)]> set session optimizer_trace=1;
Query OK, 0 rows affected (0.00 sec)

root@db1107.eqiad.wmnet[(none)]> use enwiki
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
root@db1107.eqiad.wmnet[enwiki]> SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;

<snip>

root@db1107.eqiad.wmnet[enwiki]> select * from information_schema.optimizer_trace\G
*************************** 1. row ***************************
                            QUERY: SELECT  el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501
                            TRACE: {
  "steps": [
    {
      "join_preparation": {
        "select_id": 1,
        "steps": [
          {
            "expanded_query": "select externallinks.el_index_60 AS el_index_60,externallinks.el_id AS el_id,`page`.page_id AS page_id,`page`.page_namespace AS page_namespace,`page`.page_title AS page_title,externallinks.el_to AS el_to from `page` join externallinks where `page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' order by externallinks.el_index_60,externallinks.el_id limit 501"
          }
        ]
      }
    },
    {
      "join_optimization": {
        "select_id": 1,
        "steps": [
          {
            "condition_processing": {
              "condition": "WHERE",
              "original_condition": "`page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'",
              "steps": [
                {
                  "transformation": "equality_propagation",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                },
                {
                  "transformation": "constant_propagation",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                },
                {
                  "transformation": "trivial_condition_removal",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                }
              ]
            }
          },
          {
            "table_dependencies": [
              {
                "table": "page",
                "row_may_be_null": false,
                "map_bit": 0,
                "depends_on_map_bits": []
              },
              {
                "table": "externallinks",
                "row_may_be_null": false,
                "map_bit": 1,
                "depends_on_map_bits": []
              }
            ]
          },
          {
            "ref_optimizer_key_uses": [
              {
                "table": "page",
                "field": "page_id",
                "equals": "externallinks.el_from",
                "null_rejecting": false
              },
              {
                "table": "page",
                "field": "page_id",
                "equals": "externallinks.el_from",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              }
            ]
          },
          {
            "rows_estimation": [
              {
                "table": "page",
                "table_scan": {
                  "rows": 42067094,
                  "cost": 405050
                }
              },
              {
                "table": "externallinks",
                "range_analysis": {
                  "table_scan": {
                    "rows": 138921832,
                    "cost": 3.03e7
                  },
                  "potential_range_indexes": [
                    {
                      "index": "PRIMARY",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_from",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_to",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_index",
                      "usable": true,
                      "key_parts": ["el_index"]
                    },
                    {
                      "index": "el_index_60",
                      "usable": true,
                      "key_parts": ["el_index_60", "el_id"]
                    },
                    {
                      "index": "el_from_index_60",
                      "usable": false,
                      "cause": "not applicable"
                    }
                  ],
                  "setup_range_conditions": [],
                  "group_index_range": {
                    "chosen": false,
                    "cause": "not single_table"
                  },
                  "analyzing_range_alternatives": {
                    "range_scan_alternatives": [
                      {
                        "index": "el_index",
                        "ranges": [
                          "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                        ],
                        "rowid_ordered": false,
                        "using_mrr": false,
                        "index_only": false,
                        "rows": 553,
                        "cost": 697.95,
                        "chosen": true
                      },
                      {
                        "index": "el_index_60",
                        "ranges": [
                          "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                        ],
                        "rowid_ordered": false,
                        "using_mrr": false,
                        "index_only": false,
                        "rows": 553,
                        "cost": 696.97,
                        "chosen": true
                      }
                    ],
                    "analyzing_roworder_intersect": {
                      "cause": "too few roworder scans"
                    },
                    "analyzing_index_merge_union": []
                  },
                  "chosen_range_access_summary": {
                    "range_access_plan": {
                      "type": "range_scan",
                      "index": "el_index_60",
                      "rows": 553,
                      "ranges": [
                        "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                      ]
                    },
                    "rows_for_plan": 553,
                    "cost_for_plan": 696.97,
                    "chosen": true
                  }
                }
              },
              {
                "selectivity_for_indexes": [
                  {
                    "index_name": "el_index",
                    "selectivity_from_index": 4e-6
                  },
                  {
                    "index_name": "el_index_60",
                    "selectivity_from_index": 4e-6
                  }
                ],
                "selectivity_for_columns": [],
                "cond_selectivity": 2e-11
              }
            ]
          },
          {
            "considered_execution_plans": [
              {
                "plan_prefix": [],
                "table": "externallinks",
                "best_access_path": {
                  "considered_access_paths": [
                    {
                      "access_type": "range",
                      "resulting_rows": 0.0022,
                      "cost": 807.57,
                      "chosen": true,
                      "use_tmp_table": true
                    }
                  ],
                  "chosen_access_method": {
                    "type": "range",
                    "records": 0.0022,
                    "cost": 807.57,
                    "uses_join_buffering": false,
                    "filter_used": false
                  }
                },
                "rows_for_plan": 0.0022,
                "cost_for_plan": 807.57,
                "rest_of_plan": [
                  {
                    "plan_prefix": ["externallinks"],
                    "table": "page",
                    "best_access_path": {
                      "considered_access_paths": [
                        {
                          "access_type": "eq_ref",
                          "index": "PRIMARY",
                          "rows": 1,
                          "cost": 0.0022,
                          "chosen": true
                        },
                        {
                          "type": "scan",
                          "chosen": false,
                          "cause": "cost"
                        }
                      ],
                      "chosen_access_method": {
                        "type": "eq_ref",
                        "records": 1,
                        "cost": 0.0022,
                        "uses_join_buffering": false,
                        "filter_used": false
                      }
                    },
                    "rows_for_plan": 0.0022,
                    "cost_for_plan": 807.58,
                    "estimated_join_cardinality": 0.0022
                  }
                ]
              },
              {
                "plan_prefix": [],
                "table": "page",
                "best_access_path": {
                  "considered_access_paths": [
                    {
                      "access_type": "scan",
                      "resulting_rows": 4.21e7,
                      "cost": 405050,
                      "chosen": true
                    }
                  ],
                  "chosen_access_method": {
                    "type": "scan",
                    "records": 4.21e7,
                    "cost": 405050,
                    "uses_join_buffering": false,
                    "filter_used": false
                  }
                },
                "rows_for_plan": 4.21e7,
                "cost_for_plan": 8.82e6,
                "pruned_by_cost": true
              }
            ]
          },
          {
            "best_join_order": ["externallinks", "page"]
          },
          {
            "attaching_conditions_to_tables": {
              "original_condition": "`page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'",
              "attached_conditions_computation": [],
              "attached_conditions_summary": [
                {
                  "table": "externallinks",
                  "attached": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'"
                },
                {
                  "table": "page",
                  "attached": null
                }
              ]
            }
          }
        ]
      }
    },
    {
      "join_execution": {
        "select_id": 1,
        "steps": []
      }
    }
  ]
}

I don't quite fully understand why it chooses el_index instead, even if the cost is a big higher, but it seems to consider both indexes as usable, but it sticks to el_index. The query is still as fast as the one with el_index_60 though.

We can now actually try to see what the optimizer is really doing:

Cool! Bookmarked.

I don't quite fully understand why it chooses el_index instead, even if the cost is a big higher, but it seems to consider both indexes as usable, but it sticks to el_index. The query is still as fast as the one with el_index_60 though.

I think the cost estimates are so close that tiny variations can cause it to make a different decision. I ran the same thing you did and got this (trimmed) output:

"analyzing_range_alternatives": {
  "range_scan_alternatives": [
    {
      "index": "el_index",
      "ranges": [
        "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
      ],
      "rowid_ordered": false,
      "using_mrr": false,
      "index_only": false,
      "rows": 553,
      "cost": 697.95,
      "chosen": true
    },
    {
      "index": "el_index_60",
      "ranges": [
        "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
      ],
      "rowid_ordered": false,
      "using_mrr": false,
      "index_only": false,
      "rows": 553,
      "cost": 697.97,
      "chosen": false,
      "cause": "cost"
    }
  ],
  "analyzing_roworder_intersect": {
    "cause": "too few roworder scans"
  },
  "analyzing_index_merge_union": []
},
"chosen_range_access_summary": {
  "range_access_plan": {
    "type": "range_scan",
    "index": "el_index",
    "rows": 553,
    "ranges": [
      "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
    ]
  },
  "rows_for_plan": 553,
  "cost_for_plan": 697.95,
  "chosen": true
}

Here el_index scored 697.95 versus 697.97 for el_index_60.

Yeah, in this case it makes little observable difference whether it fetches 501 rows via el_index_60, or fetches 553 rows via el_index and filesorts them. I suppose more interesting would be output that makes it choose the merged index plan that you found to be very slow.

FYI, histograms and other query optimizer configurations that should be now available on 10.4+ should be able to help tuning filtering conditions in some cases, although I haven't checked if it is the case here.

Yeah, in this case it makes little observable difference whether it fetches 501 rows via el_index_60, or fetches 553 rows via el_index and filesorts them. I suppose more interesting would be output that makes it choose the merged index plan that you found to be very slow.

Done - and it looks like there is a bigger cost difference on that case:

"range_scan_alternatives": [
  {
    "index": "el_index",
    "ranges": [
      "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
    ],
    "rowid_ordered": false,
    "using_mrr": false,
    "index_only": false,
    "rows": 553,
    "cost": 696.95,
    "chosen": true
  },
  {
    "index": "el_index_60",
    "ranges": [
      "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
    ],
    "rowid_ordered": false,
    "using_mrr": false,
    "index_only": false,
    "rows": 553,
    "cost": 697.97,
    "chosen": false,
    "cause": "cost"

I believe that rowid filter calculation could be making the query even slower (which is what we are seeing) when switching that flag on and off.

Full trace:

set session optimizer_switch='index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=on,mrr_cost_based=on,mrr_sort_keys=on,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on';
Query OK, 0 rows affected (0.00 sec)

root@db1107.eqiad.wmnet[enwiki]> set session optimizer_trace=1;
Query OK, 0 rows affected (0.00 sec)

root@db1107.eqiad.wmnet[enwiki]> SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;

<cut>


root@db1107.eqiad.wmnet[enwiki]> select * from information_schema.optimizer_trace\G
*************************** 1. row ***************************
                            QUERY: SELECT  el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501
                            TRACE: {
  "steps": [
    {
      "join_preparation": {
        "select_id": 1,
        "steps": [
          {
            "expanded_query": "select externallinks.el_index_60 AS el_index_60,externallinks.el_id AS el_id,`page`.page_id AS page_id,`page`.page_namespace AS page_namespace,`page`.page_title AS page_title,externallinks.el_to AS el_to from `page` join externallinks where `page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' order by externallinks.el_index_60,externallinks.el_id limit 501"
          }
        ]
      }
    },
    {
      "join_optimization": {
        "select_id": 1,
        "steps": [
          {
            "condition_processing": {
              "condition": "WHERE",
              "original_condition": "`page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'",
              "steps": [
                {
                  "transformation": "equality_propagation",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                },
                {
                  "transformation": "constant_propagation",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                },
                {
                  "transformation": "trivial_condition_removal",
                  "resulting_condition": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`' and multiple equal(`page`.page_id, externallinks.el_from)"
                }
              ]
            }
          },
          {
            "table_dependencies": [
              {
                "table": "page",
                "row_may_be_null": false,
                "map_bit": 0,
                "depends_on_map_bits": []
              },
              {
                "table": "externallinks",
                "row_may_be_null": false,
                "map_bit": 1,
                "depends_on_map_bits": []
              }
            ]
          },
          {
            "ref_optimizer_key_uses": [
              {
                "table": "page",
                "field": "page_id",
                "equals": "externallinks.el_from",
                "null_rejecting": false
              },
              {
                "table": "page",
                "field": "page_id",
                "equals": "externallinks.el_from",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              },
              {
                "table": "externallinks",
                "field": "el_from",
                "equals": "`page`.page_id",
                "null_rejecting": false
              }
            ]
          },
          {
            "rows_estimation": [
              {
                "table": "page",
                "table_scan": {
                  "rows": 42067094,
                  "cost": 405050
                }
              },
              {
                "table": "externallinks",
                "range_analysis": {
                  "table_scan": {
                    "rows": 138944656,
                    "cost": 3.03e7
                  },
                  "potential_range_indexes": [
                    {
                      "index": "PRIMARY",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_from",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_to",
                      "usable": false,
                      "cause": "not applicable"
                    },
                    {
                      "index": "el_index",
                      "usable": true,
                      "key_parts": ["el_index"]
                    },
                    {
                      "index": "el_index_60",
                      "usable": true,
                      "key_parts": ["el_index_60", "el_id"]
                    },
                    {
                      "index": "el_from_index_60",
                      "usable": false,
                      "cause": "not applicable"
                    }
                  ],
                  "setup_range_conditions": [],
                  "group_index_range": {
                    "chosen": false,
                    "cause": "not single_table"
                  },
                  "analyzing_range_alternatives": {
                    "range_scan_alternatives": [
                      {
                        "index": "el_index",
                        "ranges": [
                          "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                        ],
                        "rowid_ordered": false,
                        "using_mrr": false,
                        "index_only": false,
                        "rows": 553,
                        "cost": 696.95,
                        "chosen": true
                      },
                      {
                        "index": "el_index_60",
                        "ranges": [
                          "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                        ],
                        "rowid_ordered": false,
                        "using_mrr": false,
                        "index_only": false,
                        "rows": 553,
                        "cost": 697.97,
                        "chosen": false,
                        "cause": "cost"
                      }
                    ],
                    "analyzing_roworder_intersect": {
                      "cause": "too few roworder scans"
                    },
                    "analyzing_index_merge_union": []
                  },
                  "chosen_range_access_summary": {
                    "range_access_plan": {
                      "type": "range_scan",
                      "index": "el_index",
                      "rows": 553,
                      "ranges": [
                        "(http://edu.utexas.cs.www./) <= (el_index) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                      ]
                    },
                    "rows_for_plan": 553,
                    "cost_for_plan": 696.95,
                    "chosen": true
                  }
                }
              },
              {
                "selectivity_for_indexes": [
                  {
                    "index_name": "el_index",
                    "selectivity_from_index": 4e-6
                  },
                  {
                    "index_name": "el_index_60",
                    "selectivity_from_index": 4e-6
                  }
                ],
                "selectivity_for_columns": [],
                "cond_selectivity": 2e-11
              }
            ]
          },
          {
            "considered_execution_plans": [
              {
                "plan_prefix": [],
                "table": "externallinks",
                "best_access_path": {
                  "considered_access_paths": [
                    {
                      "access_type": "range",
                      "resulting_rows": 0.0022,
                      "cost": 250.93,
                      "chosen": true,
                      "use_tmp_table": true
                    }
                  ],
                  "chosen_access_method": {
                    "type": "range",
                    "records": 0.0022,
                    "cost": 250.93,
                    "uses_join_buffering": false,
                    "filter_used": true
                  }
                },
                "rows_for_plan": 0.0022,
                "cost_for_plan": 250.93,
                "rest_of_plan": [
                  {
                    "plan_prefix": ["externallinks"],
                    "table": "page",
                    "best_access_path": {
                      "considered_access_paths": [
                        {
                          "access_type": "eq_ref",
                          "index": "PRIMARY",
                          "rows": 1,
                          "cost": 0.0022,
                          "chosen": true
                        },
                        {
                          "type": "scan",
                          "chosen": false,
                          "cause": "cost"
                        }
                      ],
                      "chosen_access_method": {
                        "type": "eq_ref",
                        "records": 1,
                        "cost": 0.0022,
                        "uses_join_buffering": false,
                        "filter_used": false
                      }
                    },
                    "rows_for_plan": 0.0022,
                    "cost_for_plan": 250.94,
                    "estimated_join_cardinality": 0.0022
                  }
                ]
              },
              {
                "plan_prefix": [],
                "table": "page",
                "best_access_path": {
                  "considered_access_paths": [
                    {
                      "access_type": "scan",
                      "resulting_rows": 4.21e7,
                      "cost": 405050,
                      "chosen": true
                    }
                  ],
                  "chosen_access_method": {
                    "type": "scan",
                    "records": 4.21e7,
                    "cost": 405050,
                    "uses_join_buffering": false,
                    "filter_used": false
                  }
                },
                "rows_for_plan": 4.21e7,
                "cost_for_plan": 8.82e6,
                "pruned_by_cost": true
              }
            ]
          },
          {
            "best_join_order": ["externallinks", "page"]
          },
          {
            "table": "externallinks",
            "range_analysis": {
              "table_scan": {
                "rows": 138944656,
                "cost": 2e308
              },
              "potential_range_indexes": [
                {
                  "index": "PRIMARY",
                  "usable": false,
                  "cause": "not applicable"
                },
                {
                  "index": "el_from",
                  "usable": false,
                  "cause": "not applicable"
                },
                {
                  "index": "el_to",
                  "usable": false,
                  "cause": "not applicable"
                },
                {
                  "index": "el_index",
                  "usable": false,
                  "cause": "not applicable"
                },
                {
                  "index": "el_index_60",
                  "usable": true,
                  "key_parts": ["el_index_60", "el_id"]
                },
                {
                  "index": "el_from_index_60",
                  "usable": false,
                  "cause": "not applicable"
                }
              ],
              "setup_range_conditions": [],
              "analyzing_range_alternatives": {
                "range_scan_alternatives": [
                  {
                    "index": "el_index_60",
                    "ranges": [
                      "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                    ],
                    "rowid_ordered": false,
                    "using_mrr": false,
                    "index_only": false,
                    "rows": 553,
                    "cost": 697.97,
                    "chosen": true
                  }
                ]
              },
              "chosen_range_access_summary": {
                "range_access_plan": {
                  "type": "range_scan",
                  "index": "el_index_60",
                  "rows": 553,
                  "ranges": [
                    "(http://edu.utexas.cs.www./) <= (el_index_60) <= (http://edu.utexas.cs.www./\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF)"
                  ]
                },
                "rows_for_plan": 553,
                "cost_for_plan": 697.97,
                "chosen": true
              }
            }
          },
          {
            "attaching_conditions_to_tables": {
              "original_condition": "`page`.page_id = externallinks.el_from and externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'",
              "attached_conditions_computation": [],
              "attached_conditions_summary": [
                {
                  "table": "externallinks",
                  "attached": "externallinks.el_index_60 like 'http://edu.utexas.cs.www./%' escape '`' and externallinks.el_index like 'http://edu.utexas.cs.www./%' escape '`'"
                },
                {
                  "table": "page",
                  "attached": null
                }
              ]
            }
          },
          {
            "reconsidering_access_paths_for_index_ordering": {
              "clause": "ORDER BY",
              "fanout": 1,
              "read_time": 250.93,
              "table": "externallinks",
              "rows_estimation": 553,
              "possible_keys": [
                {
                  "index": "PRIMARY",
                  "can_resolve_order": false,
                  "cause": "not usable index for the query"
                },
                {
                  "index": "el_from",
                  "can_resolve_order": false,
                  "cause": "not usable index for the query"
                },
                {
                  "index": "el_to",
                  "can_resolve_order": false,
                  "cause": "not usable index for the query"
                },
                {
                  "index": "el_index",
                  "can_resolve_order": false,
                  "cause": "not usable index for the query"
                },
                {
                  "index": "el_index_60",
                  "can_resolve_order": true,
                  "updated_limit": 138944656,
                  "range_scan_time": 697.97,
                  "index_scan_time": 697.97,
                  "usable": false,
                  "cause": "cost"
                },
                {
                  "index": "el_from_index_60",
                  "can_resolve_order": false,
                  "cause": "order can not be resolved by key"
                }
              ]
            }
          }
        ]
      }
    },
    {
      "join_execution": {
        "select_id": 1,
        "steps": []
      }
    }
  ]
}
MISSING_BYTES_BEYOND_MAX_MEM_SIZE: 0
          INSUFFICIENT_PRIVILEGES: 0

The execution itself doesn't seem to be reading too many rows,

wikiadmin@10.64.0.214(enwiki)> SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;
[snip]
501 rows in set (1 min 43.77 sec)

wikiadmin@10.64.0.214(enwiki)> SHOW STATUS LIKE 'Hand%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 0     |
| Handler_icp_attempts       | 0     |
| Handler_icp_match          | 0     |
| Handler_mrr_init           | 0     |
| Handler_mrr_key_refills    | 0     |
| Handler_mrr_rowid_refills  | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 448   |
| Handler_read_last          | 0     |
| Handler_read_next          | 1106  |
| Handler_read_prev          | 0     |
| Handler_read_retry         | 0     |
| Handler_read_rnd           | 501   |
| Handler_read_rnd_deleted   | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_tmp_delete         | 0     |
| Handler_tmp_update         | 0     |
| Handler_tmp_write          | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
27 rows in set (0.00 sec)

That suggests whatever is being slow is in the logic for doing the filtering rather than in the row fetching itself.

That suggests whatever is being slow is in the logic for doing the filtering rather than in the row fetching itself.

Yeah, that's why I believe that Using rowid filter might be the expensive operation here.
I also double checked with a show explain for that it wasn't lying to us, and it is indeed not scanning many.

I asked MariaDB and looks like they think they'll be able to include this fix on the next 10.4.13 that is scheduled to be shipped by the end of April

10.4.13 is about to be released (it was scheduled for 27th) but looks like this issue won't make it to that release, despite what the developer initially said - it seems they MyISAM is also affected by this bug.

Sergei Golubchik closed MDEV-21794.
-----------------------------------
    Fix Version/s: 10.4.13
                   10.5.3
                       (was: 10.4)
                       (was: 10.5)
       Resolution: Fixed

Not closing this until I can verify it is indeed fixed for us.

Marostegui claimed this task.

This looks fixed on 10.4.13 - just tried on db2102

Running 10.4.12:

root@db2102.codfw.wmnet[ops]> set session optimizer_switch='index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=on,mrr_cost_based=on,mrr_sort_keys=on,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on';
Query OK, 0 rows affected (0.03 sec)

SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;

501 rows in set (26.42 sec)

Upgraded to 10.4.13:

root@db2102.codfw.wmnet[enwiki]> set session optimizer_switch='index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=on,mrr_cost_based=on,mrr_sort_keys=on,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on';
Query OK, 0 rows affected (0.04 sec)

SELECT /* ApiQueryExtLinksUsage::run */ el_index_60, el_id, page_id, page_namespace, page_title, el_to FROM `page`, `externallinks` WHERE (page_id=el_from) AND (el_index_60 LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) AND (el_index LIKE 'http://edu.utexas.cs.www./%' ESCAPE '`' ) ORDER BY el_index_60, el_id LIMIT 501;

501 rows in set (0.12 sec)