[MDEV-28984] Optimizer picking the wrong table for order of join Created: 2022-06-29  Updated: 2022-06-29

Status: Open
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 10.4.22, 10.6.8
Fix Version/s: 10.4, 10.6

Type: Bug Priority: Major
Reporter: Amir Sarabadani Assignee: Sergei Petrunia
Resolution: Unresolved Votes: 1
Labels: None
Environment:

debian bullseye



 Description   

For Wikimedia production, we have recentchanges table that is rather short but it joins to large tables such as actor ("user" basically). Suddenly in a rather important wiki, the frontend to this table started timing out.

Here is the query:

SELECT  rc_id,rc_timestamp,rc_namespace,rc_title,rc_minor,rc_bot,rc_new,rc_cur_id,rc_this_oldid,rc_last_oldid,rc_type,rc_source,rc_patrolled,rc_ip,rc_old_len,rc_new_len,rc_deleted,rc_logid,rc_log_type,rc_log_action,rc_params,rc_actor,recentchanges_actor.actor_user AS `rc_user`,recentchanges_actor.actor_name AS `rc_user_text`,comment_rc_comment.comment_text AS `rc_comment_text`,comment_rc_comment.comment_data AS `rc_comment_data`,comment_rc_comment.comment_id AS `rc_comment_cid`,rc_title,rc_namespace,page_latest,(SELECT  GROUP_CONCAT(ctd_name SEPARATOR ',')  FROM `change_tag` JOIN `change_tag_def` ON ((ct_tag_id=ctd_id))   WHERE ct_rc_id=rc_id  ) AS `ts_tags`  FROM `recentchanges` JOIN `actor` `recentchanges_actor` ON ((actor_id=rc_actor)) JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) LEFT JOIN `page` ON ((rc_cur_id=page_id))   WHERE rc_bot = 0 AND (rc_type != 6) AND (rc_source != 'wb') AND (rc_namespace NOT IN (1198,1199,866,867)) AND (rc_timestamp >= '20220622213111') AND rc_new IN (0,1)   ORDER BY rc_timestamp DESC LIMIT 50

(Formatted query: https://phabricator.wikimedia.org/P30631)

Explain:

*************************** 1. row ***************************
           id: 1
  select_type: PRIMARY
        table: recentchanges_actor
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 24679668
     filtered: 100.00
        Extra: Using temporary; Using filesort
*************************** 2. row ***************************
           id: 1
  select_type: PRIMARY
        table: recentchanges
         type: ref
possible_keys: rc_timestamp,rc_name_type_patrolled_timestamp,rc_ns_actor,rc_actor,rc_namespace_title_timestamp,rc_new_name_timestamp
          key: rc_actor
      key_len: 8
          ref: metawiki.recentchanges_actor.actor_id
         rows: 16
     filtered: 100.00
        Extra: Using index condition; Using where
*************************** 3. row ***************************
           id: 1
  select_type: PRIMARY
        table: page
         type: eq_ref
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: metawiki.recentchanges.rc_cur_id
         rows: 1
     filtered: 100.00
        Extra: 
*************************** 4. row ***************************
           id: 1
  select_type: PRIMARY
        table: comment_rc_comment
         type: eq_ref
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 8
          ref: metawiki.recentchanges.rc_comment_id
         rows: 1
     filtered: 100.00
        Extra: 
*************************** 5. row ***************************
           id: 2
  select_type: DEPENDENT SUBQUERY
        table: change_tag
         type: ref
possible_keys: ct_rc_tag_id,ct_tag_id_id
          key: ct_rc_tag_id
      key_len: 5
          ref: metawiki.recentchanges.rc_id
         rows: 1
     filtered: 100.00
        Extra: Using index
*************************** 6. row ***************************
           id: 2
  select_type: DEPENDENT SUBQUERY
        table: change_tag_def
         type: eq_ref
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: metawiki.change_tag.ct_tag_id
         rows: 1
     filtered: 100.00
        Extra: 
6 rows in set, 2 warnings (0.002 sec)

Analyze:

{
  "query_block": {
    "select_id": 1,
    "r_loops": 1,
    "r_total_time_ms": 70227.23238,
    "filesort": {
      "sort_key": "recentchanges.rc_timestamp desc",
      "r_loops": 1,
      "r_total_time_ms": 8.816484672,
      "r_limit": 50,
      "r_used_priority_queue": true,
      "r_output_rows": 51,
      "r_sort_mode": "sort_key,rowid",
      "temporary_table": {
        "table": {
          "table_name": "recentchanges_actor",
          "access_type": "ALL",
          "possible_keys": ["PRIMARY"],
          "r_loops": 1,
          "rows": 24679658,
          "r_rows": 35749188,
          "r_table_time_ms": 14751.19318,
          "r_other_time_ms": 3142.874176,
          "filtered": 100,
          "r_filtered": 100
        },
        "table": {
          "table_name": "recentchanges",
          "access_type": "ref",
          "possible_keys": [
            "rc_timestamp",
            "rc_name_type_patrolled_timestamp",
            "rc_ns_actor",
            "rc_actor",
            "rc_namespace_title_timestamp",
            "rc_new_name_timestamp"
          ],
          "key": "rc_actor",
          "key_length": "8",
          "used_key_parts": ["rc_actor"],
          "ref": ["metawiki.recentchanges_actor.actor_id"],
          "r_loops": 35749188,
          "rows": 16,
          "r_rows": 0.001382353,
          "r_table_time_ms": 51395.8372,
          "r_other_time_ms": 767.0172278,
          "filtered": 100,
          "r_filtered": 28.39451212,
          "index_condition": "recentchanges.rc_timestamp >= '20220622213111'",
          "attached_condition": "recentchanges.rc_bot = 0 and recentchanges.rc_type <> 6 and recentchanges.rc_source <> 'wb' and recentchanges.rc_namespace not in (1198,1199,866,867) and recentchanges.rc_new in (0,1)"
        },
        "table": {
          "table_name": "page",
          "access_type": "eq_ref",
          "possible_keys": ["PRIMARY"],
          "key": "PRIMARY",
          "key_length": "4",
          "used_key_parts": ["page_id"],
          "ref": ["metawiki.recentchanges.rc_cur_id"],
          "r_loops": 14032,
          "rows": 1,
          "r_rows": 0.81299886,
          "r_table_time_ms": 27.33096909,
          "r_other_time_ms": 4.45577502,
          "filtered": 100,
          "r_filtered": 100
        },
        "table": {
          "table_name": "comment_rc_comment",
          "access_type": "eq_ref",
          "possible_keys": ["PRIMARY"],
          "key": "PRIMARY",
          "key_length": "8",
          "used_key_parts": ["comment_id"],
          "ref": ["metawiki.recentchanges.rc_comment_id"],
          "r_loops": 14032,
          "rows": 1,
          "r_rows": 1,
          "r_table_time_ms": 26.1279084,
          "r_other_time_ms": 10.89051682,
          "filtered": 100,
          "r_filtered": 100
        },
        "subqueries": [
          {
            "expression_cache": {
              "state": "disabled",
              "r_loops": 0,
              "query_block": {
                "select_id": 2,
                "r_loops": 14032,
                "r_total_time_ms": 66.74385352,
                "table": {
                  "table_name": "change_tag",
                  "access_type": "ref",
                  "possible_keys": ["ct_rc_tag_id", "ct_tag_id_id"],
                  "key": "ct_rc_tag_id",
                  "key_length": "5",
                  "used_key_parts": ["ct_rc_id"],
                  "ref": ["metawiki.recentchanges.rc_id"],
                  "r_loops": 14032,
                  "rows": 1,
                  "r_rows": 0.729190422,
                  "r_table_time_ms": 38.10037738,
                  "r_other_time_ms": 7.266748412,
                  "filtered": 100,
                  "r_filtered": 100,
                  "using_index": true
                },
                "table": {
                  "table_name": "change_tag_def",
                  "access_type": "eq_ref",
                  "possible_keys": ["PRIMARY"],
                  "key": "PRIMARY",
                  "key_length": "4",
                  "used_key_parts": ["ctd_id"],
                  "ref": ["metawiki.change_tag.ct_tag_id"],
                  "r_loops": 10232,
                  "rows": 1,
                  "r_rows": 1,
                  "r_table_time_ms": 10.34536649,
                  "r_other_time_ms": 3.346125674,
                  "filtered": 100,
                  "r_filtered": 100
                }
              }
            }
          }
        ]
      }
    }
  }
}

You can also make queries to this table (a bit different version but pretty similar) on https://quarry.wmcloud.org (the database being metawiki_p)

Here is the ticket in wikimedia: https://phabricator.wikimedia.org/T311360



 Comments   
Comment by Amir Sarabadani [ 2022-06-29 ]

For example, with straight join:

MariaDB [metawiki]> explain SELECT STRAIGHT_JOIN rc_id,rc_timestamp,rc_namespace,rc_title,rc_minor,rc_bot,rc_new,rc_cur_id,rc_this_oldid,rc_last_oldid,rc_type,rc_source,rc_patrolled,rc_ip,rc_old_len,rc_new_len,rc_deleted,rc_logid,rc_log_type,rc_log_action,rc_params,rc_actor,recentchanges_actor.actor_user AS `rc_user`,recentchanges_actor.actor_name AS `rc_user_text`,comment_rc_comment.comment_text AS `rc_comme
 `change_tag` JOIN `change_tag_def` ON ((ct_tag_id=ctd_id))   WHERE ct_rc_id=rc_id  ) AS `ts_tags`  FROM `recentchanges` JOIN `actor` `recentchanges_actor` ON ((actor_id=rc_actor)) JOIN `comment` `comment_rc_comme                                                                                                                                                                                                119
+------+--------------------+---------------------+--------+-----------------------------------------------------------------------------------------------------------------------+--------------+---------+--------------------------------------+--------+-------------+
| id   | select_type        | table               | type   | possible_keys                                                                                                         | key          | key_len | ref                                  | rows   | Extra       |
+------+--------------------+---------------------+--------+-----------------------------------------------------------------------------------------------------------------------+--------------+---------+--------------------------------------+--------+-------------+
|    1 | PRIMARY            | recentchanges       | range  | rc_timestamp,rc_name_type_patrolled_timestamp,rc_ns_actor,rc_actor,rc_namespace_title_timestamp,rc_new_name_timestamp | rc_timestamp | 14      | NULL                                 | 100260 | Using where |
|    1 | PRIMARY            | recentchanges_actor | eq_ref | PRIMARY                                                                                                               | PRIMARY      | 8       | metawiki.recentchanges.rc_actor      | 1      |             |
|    1 | PRIMARY            | comment_rc_comment  | eq_ref | PRIMARY                                                                                                               | PRIMARY      | 8       | metawiki.recentchanges.rc_comment_id | 1      |             |
|    1 | PRIMARY            | page                | eq_ref | PRIMARY                                                                                                               | PRIMARY      | 4       | metawiki.recentchanges.rc_cur_id     | 1      |             |
|    2 | DEPENDENT SUBQUERY | change_tag          | ref    | ct_rc_tag_id,ct_tag_id_id                                                                                             | ct_rc_tag_id | 5       | metawiki.recentchanges.rc_id         | 1      | Using index |
|    2 | DEPENDENT SUBQUERY | change_tag_def      | eq_ref | PRIMARY                                                                                                               | PRIMARY      | 4       | metawiki.change_tag.ct_tag_id        | 1      |             |
+------+--------------------+---------------------+--------+-----------------------------------------------------------------------------------------------------------------------+--------------+---------+--------------------------------------+--------+-------------+
6 rows in set (0.002 sec)

Generated at Thu Feb 08 10:04:58 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.