| Iniquity | |
| Feb 5 2023, 1:51 AM |
| F36731876: image.png | |
| Feb 5 2023, 1:51 AM |
Steps to replicate the issue (include links if applicable):
What happens?:
There is an error about a long wait for a response
What should have happened instead?:
A list of edits should be shown.
Software version (skip for WMF-hosted wikis like Wikipedia):
Other information (browser name/version, screenshots, etc.):
| Subject | Repo | Branch | Lines +/- | |
|---|---|---|---|---|
| Mentor filters: Work around MariaDB query planner fail | mediawiki/extensions/GrowthExperiments | master | +28 -7 |
@Iniquity thanks for reporting this.
Follow up from T318457: Enable "Your unstarred mentees" at the biggest Growth wikis. @Urbanecm_WMF would you be able to have a look at this?
@Iniquity Thanks for reporting this!
I briefly investigated this issue. Most importantly, I was able to reproduce the issue using my volunteer cswiki account. Here is the problematic query (which takes 30+ seconds, and is stopped by the RDBMS; at analytics replicas, it took 17 minutes 48 seconds to complete):
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`, wl_user, wl_notificationtimestamp, we_expiry, 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`, ores_damaging_cls.oresc_probability AS `ores_damaging_score`, ores_goodfaith_cls.oresc_probability AS `ores_goodfaith_score` FROM `recentchanges` STRAIGHT_JOIN `actor` `recentchanges_actor` ON ( (actor_id = rc_actor) ) STRAIGHT_JOIN `comment` `comment_rc_comment` ON ( ( comment_rc_comment.comment_id = rc_comment_id ) ) LEFT JOIN `watchlist` ON ( wl_user = 275298 AND (wl_title = rc_title) AND (wl_namespace = rc_namespace) ) LEFT JOIN `watchlist_expiry` ON ( (wl_id = we_item) ) LEFT JOIN `page` ON ( (rc_cur_id = page_id) ) LEFT JOIN `ores_classification` `ores_damaging_cls` ON ( ores_damaging_cls.oresc_model = 12 AND ( ores_damaging_cls.oresc_rev = rc_this_oldid ) AND ores_damaging_cls.oresc_class = 1 ) LEFT JOIN `ores_classification` `ores_goodfaith_cls` ON ( ores_goodfaith_cls.oresc_model = 13 AND ( ores_goodfaith_cls.oresc_rev = rc_this_oldid ) AND ores_goodfaith_cls.oresc_class = 1 ) WHERE rc_bot = 0 AND (rc_type != 6) AND (rc_source != 'wb') AND ( recentchanges_actor.actor_user IN ( 184952, 301205, 351246, 357559, 426522, 453028, 460332, 467450, 468196, 469154, 479642, 484990, 485230, 492154, 503043, 504173, 513830, 515030, 543521, 550081, 553782, 556699, 558323, 567145, 569196, 573994, 583939, 584120, 587976, 589568, 590489, 594245, 600333, 601217, 601752, 601989, 605536, 605581, 605591, 605620, 605622, 605702, 605724, 605758, 605812, 605844, 605892, 605897, 605924, 605944, 605981, 606012, 606073, 606224, 606242, 606258, 606287, 606288, 606478, 606708, 606719, 606748, 606769, 606859, 606865, 606979, 606980, 607005, 607009, 607069, 607410, 607584, 607620, 607661, 607678, 607701, 607765, 607965, 607967, 607981, 607993, 608015, 608065, 608075, 608098, 608118, 608123, 608139, 608177, 608214, 608216, 608361, 608376, 608383, 608489, 608566, 608669, 608744, 608783, 608916, 609065, 609112, 609192, 609235, 609278, 609341, 609347, 609352, 609353, 609441, 609488, 609496, 609574, 609580, 609586, 609628, 609637, 609702 ) ) AND (rc_timestamp >= '20230114181347') AND rc_new IN (0, 1) ORDER BY rc_timestamp DESC LIMIT 250
That query finishes very quickly (~41 ms) if I remove the recentchanges_actor.actor_user clause.
Explain is here:
mysql:research@dbstore1007.eqiad.wmnet [cswiki]> EXPLAIN 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`,wl_user,wl_notificationtimestamp,we_expiry,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`,ores_damaging_cls.oresc_probability AS `ores_damaging_score`,ores_goodfaith_cls.oresc_probability AS `ores_goodfaith_score` FROM `recentchanges` STRAIGHT_JOIN `actor` `recentchanges_actor` ON ((actor_id=rc_actor)) STRAIGHT_JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) LEFT JOIN `watchlist` ON (wl_user = 275298 AND (wl_title=rc_title) AND (wl_namespace=rc_namespace)) LEFT JOIN `watchlist_expiry` ON ((wl_id = we_item)) LEFT JOIN `page` ON ((rc_cur_id=page_id)) LEFT JOIN `ores_classification` `ores_damaging_cls` ON (ores_damaging_cls.oresc_model = 12 AND (ores_damaging_cls.oresc_rev=rc_this_oldid) AND ores_damaging_cls.oresc_class = 1) LEFT JOIN `ores_classification` `ores_goodfaith_cls` ON (ores_goodfaith_cls.oresc_model = 13 AND (ores_goodfaith_cls.oresc_rev=rc_this_oldid) AND ores_goodfaith_cls.oresc_class = 1) WHERE rc_bot = 0 AND (rc_type != 6) AND (rc_source != 'wb') AND (recentchanges_actor.actor_user IN (184952,301205,351246,357559,426522,453028,460332,467450,468196,469154,479642,484990,485230,492154,503043,504173,513830,515030,543521,550081,553782,556699,558323,567145,569196,573994,583939,584120,587976,589568,590489,594245,600333,601217,601752,601989,605536,605581,605591,605620,605622,605702,605724,605758,605812,605844,605892,605897,605924,605944,605981,606012,606073,606224,606242,606258,606287,606288,606478,606708,606719,606748,606769,606859,606865,606979,606980,607005,607009,607069,607410,607584,607620,607661,607678,607701,607765,607965,607967,607981,607993,608015,608065,608075,608098,608118,608123,608139,608177,608214,608216,608361,608376,608383,608489,608566,608669,608744,608783,608916,609065,609112,609192,609235,609278,609341,609347,609352,609353,609441,609488,609496,609574,609580,609586,609628,609637,609702) ) AND (rc_timestamp >= '20230114181347') AND rc_new IN (0,1) ORDER BY rc_timestamp DESC LIMIT 250; +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+---------+---------------------------------------------------------------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+---------+---------------------------------------------------------------------+ | 1 | PRIMARY | recentchanges | range | rc_timestamp,rc_actor,rc_new_name_timestamp | rc_timestamp | 14 | NULL | 189886 | Using index condition; Using where; Using temporary; Using filesort | | 1 | PRIMARY | recentchanges_actor | eq_ref | PRIMARY,actor_user | PRIMARY | 8 | cswiki.recentchanges.rc_actor | 1 | Using where | | 1 | PRIMARY | watchlist | ref | wl_user,wl_user_notificationtimestamp,wl_namespace_title | wl_namespace_title | 261 | cswiki.recentchanges.rc_namespace,cswiki.recentchanges.rc_title | 1 | Using where | | 1 | PRIMARY | watchlist_expiry | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.watchlist.wl_id | 1 | Using where | | 1 | PRIMARY | comment_rc_comment | eq_ref | PRIMARY | PRIMARY | 8 | cswiki.recentchanges.rc_comment_id | 1 | | | 1 | PRIMARY | page | ALL | PRIMARY | NULL | NULL | NULL | 1485174 | Using where; Using join buffer (flat, BNL join) | | 1 | PRIMARY | ores_damaging_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 1 | PRIMARY | ores_goodfaith_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 2 | DEPENDENT SUBQUERY | change_tag | ref | ct_rc_tag_id,ct_tag_id_id | ct_rc_tag_id | 5 | cswiki.recentchanges.rc_id | 1 | Using index | | 2 | DEPENDENT SUBQUERY | change_tag_def | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.change_tag.ct_tag_id | 1 | | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+---------+---------------------------------------------------------------------+ 10 rows in set (0.002 sec) mysql:research@dbstore1007.eqiad.wmnet [cswiki]>
Not yet sure what exactly changed and why it doesn't work anymore.
The query completes significantly faster if we enumerate the list of users via their actor IDs, rather than user IDs. However, actor IDs seem to be (intentionally?) fairly difficult to obtain. It could be added as a field ActorStore populates for UserIdentity objects, but that's not going to be an easy project to work on.
@kostajh @Tgr Do you have any thoughts on how we might be able to make the query less expensive?
I don't think they are, just join the user and actor tables. Real users probably have an actor entry. Real users with an edit definitely have an actor entry, since the revision includes the actor ID.
So the important part of the query (without all the eq_ref joins that don't have any performance impact) is
FROM recentchanges JOIN actor ON (actor_id = rc_actor) WHERE rc_bot = 0 AND rc_type != 6 AND rc_source != 'wb' AND actor_user IN (<mentee id list>) AND rc_timestamp >= <paging ts> AND rc_new IN (0, 1) ORDER BY rc_timestamp DESC
with the relevant indexes being (rc_timestamp) and (rc_actor, rc_timestamp). I think that should be pretty fast: either scan all RC rows above the timestamp (a few million on enwiki, not great but not tragic) and do a primary-key lookup on the actor table for each row; or if the number of mentees is low, translate user IDs to actor IDs and do a bunch of range scans on the (rc_actor, rc_timestamp) index.
But what's actually happening is MariaDB doing an ALL on page (ie. scanning the full page table for every recentchanges row). That sounds like an orbital query planner fail.
If I add a FORCE index the ALL query just moves to another left-joined table. After forcing all of them, the query now has a reasonable plan and finishes in a second or so:
mysql:research@dbstore1007.eqiad.wmnet [cswiki]> EXPLAIN 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`,wl_user,wl_notificationtimestamp,we_expiry,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`,ores_damaging_cls.oresc_probability AS `ores_damaging_score`,ores_goodfaith_cls.oresc_probability AS `ores_goodfaith_score` FROM `recentchanges` STRAIGHT_JOIN `actor` `recentchanges_actor` ON ((actor_id=rc_actor)) STRAIGHT_JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) LEFT JOIN `watchlist` ON (wl_user = 275298 AND (wl_title=rc_title) AND (wl_namespace=rc_namespace)) LEFT JOIN `watchlist_expiry` ON ((wl_id = we_item)) LEFT JOIN `page` FORCE INDEX (PRIMARY) ON ((rc_cur_id=page_id)) LEFT JOIN `ores_classification` `ores_damaging_cls` FORCE INDEX (oresc_rev_model_class) ON (ores_damaging_cls.oresc_model = 12 AND (ores_damaging_cls.oresc_rev=rc_this_oldid) AND ores_damaging_cls.oresc_class = 1) LEFT JOIN `ores_classification` `ores_goodfaith_cls` FORCE INDEX (oresc_rev_model_class) ON (ores_goodfaith_cls.oresc_model = 13 AND (ores_goodfaith_cls.oresc_rev=rc_this_oldid) AND ores_goodfaith_cls.oresc_class = 1) WHERE rc_bot = 0 AND (rc_type != 6) AND (rc_source != 'wb') AND (recentchanges_actor.actor_user IN (184952,301205,351246,357559,426522,453028,460332,467450,468196,469154,479642,484990,485230,492154,503043,504173,513830,515030,543521,550081,553782,556699,558323,567145,569196,573994,583939,584120,587976,589568,590489,594245,600333,601217,601752,601989,605536,605581,605591,605620,605622,605702,605724,605758,605812,605844,605892,605897,605924,605944,605981,606012,606073,606224,606242,606258,606287,606288,606478,606708,606719,606748,606769,606859,606865,606979,606980,607005,607009,607069,607410,607584,607620,607661,607678,607701,607765,607965,607967,607981,607993,608015,608065,608075,608098,608118,608123,608139,608177,608214,608216,608361,608376,608383,608489,608566,608669,608744,608783,608916,609065,609112,609192,609235,609278,609341,609347,609352,609353,609441,609488,609496,609574,609580,609586,609628,609637,609702) ) AND (rc_timestamp >= '20230114181347') AND rc_new IN (0,1) ORDER BY rc_timestamp DESC LIMIT 250; +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+--------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+--------+-------------+ | 1 | PRIMARY | recentchanges | range | rc_timestamp,rc_actor,rc_new_name_timestamp | rc_timestamp | 14 | NULL | 239287 | Using where | | 1 | PRIMARY | recentchanges_actor | eq_ref | PRIMARY,actor_user | PRIMARY | 8 | cswiki.recentchanges.rc_actor | 1 | Using where | | 1 | PRIMARY | watchlist | ref | wl_user,wl_user_notificationtimestamp,wl_namespace_title | wl_namespace_title | 261 | cswiki.recentchanges.rc_namespace,cswiki.recentchanges.rc_title | 1 | Using where | | 1 | PRIMARY | watchlist_expiry | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.watchlist.wl_id | 1 | Using where | | 1 | PRIMARY | page | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.recentchanges.rc_cur_id | 1 | | | 1 | PRIMARY | ores_damaging_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 1 | PRIMARY | ores_goodfaith_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 1 | PRIMARY | comment_rc_comment | eq_ref | PRIMARY | PRIMARY | 8 | cswiki.recentchanges.rc_comment_id | 1 | | | 2 | DEPENDENT SUBQUERY | change_tag | ref | ct_rc_tag_id,ct_tag_id_id | ct_rc_tag_id | 5 | cswiki.recentchanges.rc_id | 1 | Using index | | 2 | DEPENDENT SUBQUERY | change_tag_def | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.change_tag.ct_tag_id | 1 | | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------+--------+-------------+
but I guess doing that in the RC hook is not an option...
Change 895891 had a related patch set uploaded (by Gergő Tisza; author: Gergő Tisza):
[mediawiki/extensions/GrowthExperiments@master] Mentor filters: Work around MariaDB query planner fail
With the patch:
wikiadmin2023@10.192.32.181(cswiki)> EXPLAIN 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`,wl_user,wl_notificationtimestamp,we_expiry,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`,ores_damaging_cls.oresc_probability AS `ores_damaging_score`,ores_goodfaith_cls.oresc_probability AS `ores_goodfaith_score` FROM `recentchanges` STRAIGHT_JOIN `actor` `recentchanges_actor` ON ((actor_id=rc_actor)) STRAIGHT_JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) LEFT JOIN `watchlist` ON (wl_user = 275298 AND (wl_title=rc_title) AND (wl_namespace=rc_namespace)) LEFT JOIN `watchlist_expiry` ON ((wl_id = we_item)) LEFT JOIN `page` FORCE INDEX (PRIMARY) ON ((rc_cur_id=page_id)) LEFT JOIN `ores_classification` `ores_damaging_cls` FORCE INDEX (oresc_rev_model_class) ON (ores_damaging_cls.oresc_model = 12 AND (ores_damaging_cls.oresc_rev=rc_this_oldid) AND ores_damaging_cls.oresc_class = 1) LEFT JOIN `ores_classification` `ores_goodfaith_cls` FORCE INDEX (oresc_rev_model_class) ON (ores_goodfaith_cls.oresc_model = 13 AND (ores_goodfaith_cls.oresc_rev=rc_this_oldid) AND ores_goodfaith_cls.oresc_class = 1) WHERE rc_bot = 0 AND (rc_type != 6) AND (rc_source != 'wb') AND (rc_actor IN (8066,75,11082,15,1707,892699,926812,956375,960148,964684,1015368,1040577,1041559,1073162,1120790,1126324,1180621,1187171,1294679,1312996,1323771,1332358,1337301,1361940,1368652,1382608,1411286,1411835,1421977,1426687,1429540,1440944,1460862,1463514,1465285,1466053,1476429,1476583,1476626,1476694,1476705,1476941,1477033,1477139,1477298,1477384,1477559,1477584,1477670,1477715,1477848,1477938,1478145,1478639,1478679,1478716,1478790,1478795,1479264,1479889,1479912,1480000,1480078,1480372,1480408,1480730,1480731,1480820,1480826,1481014,1481983,1482392,1482491,1482602,1482646,1482726,1482948,1483558,1483561,1483586,1483609,1483650,1483783,1483812,1483875,1483918,1483933,1483975,1484067,1484149,1484151,1484508,1484548,1484572,1484858,1485050,1485325,1485532,1485629,1486004,1486406,1486583,1486850,1486990,1487121,1487319,1487350,1487366,1487368,1487671,1487795,1487815,1488024,1488041,1488053,1488189,1488220,1488431) ) AND (rc_timestamp >= '20230114181347') AND rc_new IN (0,1) ORDER BY rc_timestamp DESC LIMIT 250; +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------------+------+----------------------------------------------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------------+------+----------------------------------------------------+ | 1 | PRIMARY | recentchanges | range | rc_timestamp,rc_actor,rc_new_name_timestamp | rc_actor | 22 | NULL | 3724 | Using index condition; Using where; Using filesort | | 1 | PRIMARY | recentchanges_actor | eq_ref | PRIMARY | PRIMARY | 8 | cswiki.recentchanges.rc_actor | 1 | | | 1 | PRIMARY | watchlist | eq_ref | wl_user,wl_user_notificationtimestamp,wl_namespace_title | wl_user | 265 | const,cswiki.recentchanges.rc_namespace,cswiki.recentchanges.rc_title | 1 | | | 1 | PRIMARY | watchlist_expiry | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.watchlist.wl_id | 1 | Using where | | 1 | PRIMARY | page | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.recentchanges.rc_cur_id | 1 | | | 1 | PRIMARY | ores_damaging_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 1 | PRIMARY | ores_goodfaith_cls | eq_ref | oresc_rev_model_class | oresc_rev_model_class | 7 | cswiki.recentchanges.rc_this_oldid,const,const | 1 | | | 1 | PRIMARY | comment_rc_comment | eq_ref | PRIMARY | PRIMARY | 8 | cswiki.recentchanges.rc_comment_id | 1 | | | 2 | DEPENDENT SUBQUERY | change_tag | ref | ct_rc_tag_id,ct_tag_id_id | ct_rc_tag_id | 5 | cswiki.recentchanges.rc_id | 1 | Using index | | 2 | DEPENDENT SUBQUERY | change_tag_def | eq_ref | PRIMARY | PRIMARY | 4 | cswiki.change_tag.ct_tag_id | 1 | | +------+--------------------+---------------------+--------+----------------------------------------------------------+-----------------------+---------+-----------------------------------------------------------------------+------+----------------------------------------------------+
takes <0.1s to run.
Change 895891 merged by jenkins-bot:
[mediawiki/extensions/GrowthExperiments@master] Mentor filters: Work around MariaDB query planner fail