Maniphest T204669

Slow access to Special:Contributions on mediawiki.org (due to enabling actor table WRITE_BOTH mode)
Closed, ResolvedPublic
Actions

Description

Today at least, accessing Special:Contributions for any user (even if it has less than 5 contributions) takes a long time to load (in the order of 25 - 30 seconds), while other pages load near-instantly. example

I suspect there's a problem with today's deploy: https://www.mediawiki.org/wiki/MediaWiki_1.32/wmf.22

curl https://www.mediawiki.org/wiki/Special:Contributions/Andrew0005?forceprofile=1


<!--
100.00% 10800.014      1 - main()
100.00% 10799.744      1 - {internal}
100.00% 10799.541      1 - run_init::/srv/mediawiki/php-1.32.0-wmf.20/index.php
 99.34% 10729.084      1 - MediaWiki::run
 98.95% 10686.479      1 - MediaWiki::main
 97.57% 10537.861      1 - MediaWiki::performRequest
 97.50% 10529.659      1 - MediaWiki\Special\SpecialPageFactory::executePath
 97.49% 10529.381      1 - SpecialPage::run
 97.45% 10524.883      1 - SpecialContributions::execute
 93.27% 10072.893     39 - Wikimedia\Rdbms\Database::select
 93.24% 10069.615     58 - Wikimedia\Rdbms\Database::query
 93.18% 10063.914     64 - Wikimedia\Rdbms\Database::doProfiledQuery
 93.15% 10059.856     84 - Wikimedia\Rdbms\DatabaseMysqli::doQuery
 92.46% 9985.890      2 - IndexPager::doQuery
 92.41% 9979.937      3 - IndexPager::getNumRows
 92.41% 9979.896      1 - section.IndexPager::doQuery (ContribsPager)
 92.41% 9979.756      1 - ContribsPager::reallyDoQuery
  3.99% 430.981    871 - Hooks::callHook

Details

Related Changes in Gerrit:

Subject	Repo	Branch	Lines +/-
Adjust for core change I4764c1c78	mediawiki/extensions/Renameuser	master	+44 -17
Improve some queries ordering by rev_timestamp with actor migration READ_NEW	mediawiki/core	master	+111 -42
Adjust for core change I4764c1c78	mediawiki/extensions/UserMerge	master	+56 -28
ActorMigration: Remove possibility of read-both	mediawiki/core	master	+564 -724
Adjust for core change I4764c1c78	mediawiki/extensions/ORES	master	+4 -4
Adjust for core change I4764c1c78	mediawiki/extensions/WikimediaMaintenance	master	+3 -3
Set ActorTableSchemaMigrationStage => OLD on test wikis, mw.org	operations/mediawiki-config	master	+0 -4

Customize query in gerrit

Related Objects
Search...

Status	Assigned	Task
Resolved	daniel	T161671 Compacting the revision table
Resolved	None	T227047 Complete actor table and comment table migration
Resolved	Anomie	T188327 Deploy refactored actor storage
Resolved	Anomie	T204669 Slow access to Special:Contributions on mediawiki.org (due to enabling actor table WRITE_BOTH mode)

Event Timeline

Ciencia_Al_Poder created this task.Sep 18 2018, 9:40 AM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptSep 18 2018, 9:40 AM

Ciencia_Al_Poder added a parent task: T191068: 1.32.0-wmf.22 deployment blockers.Sep 18 2018, 9:40 AM

Ciencia_Al_Poder added a project: MediaWiki-Special-pages.Sep 18 2018, 10:04 AM

I'm confused. Deployment of wmf.22 is supposed to happen today https://www.mediawiki.org/wiki/MediaWiki_1.32/Roadmap but it hasn't happened yet on mediawiki.org, which is on .20, but the problem seems to happen since today.

I'll leave the parent task as it is until someone can clarify that

Peachey88 added a project: Regression.Sep 18 2018, 10:31 AM

Confirming. Source code of https://www.mediawiki.org/wiki/Special:Contributions/Andrew0005?debug=true says:

<script>(window.RLQ=window.RLQ||[]).push(function(){mw.config.set( {
    "wgBackendResponseTime": 24761,
    "wgHostname": "mw2184"
} );});</script>

hashar updated the task description. (Show Details)Sep 18 2018, 12:41 PM

From profiling (with https://www.mediawiki.org/wiki/Special:Contributions/Andrew0005?forceprofile=1 ) that comes from ContribsPager::reallyDoQuery . HHVM reports a slow sql query:

That is for mediawikiwiki database:

SELECT /* IndexPager::buildQueryInfo (contributions page unfiltered) xxx */
   rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,
  COALESCE( comment_rev_comment.comment_text, rev_comment ) AS `rev_comment_text`,
  comment_rev_comment.comment_data AS `rev_comment_data`,
  comment_rev_comment.comment_id AS `rev_comment_cid`,
  COALESCE( actor_rev_user.actor_user, rev_user ) AS `rev_user`,
  COALESCE( actor_rev_user.actor_name, rev_user_text ) AS `rev_user_text`,
  temp_rev_user.revactor_actor AS `rev_actor`,
  rev_text_id,rev_content_format,rev_content_model,
  page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name,page_is_new,
  (SELECT  GROUP_CONCAT(ct_tag SEPARATOR ',')
   FROM `change_tag`    WHERE ct_rev_id=rev_id  ) AS `ts_tags`
FROM `revision`
LEFT JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id))
LEFT JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id))
LEFT JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id))
LEFT JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor))
INNER JOIN `page` ON ((page_id = rev_page))
LEFT JOIN `user` ON (
    (COALESCE( actor_rev_user.actor_user, rev_user ) != 0)
    AND (user_id = COALESCE( actor_rev_user.actor_user, rev_user ))
 )

WHERE (
  ( (temp_rev_user.revactor_actor IS NOT NULL)
    AND temp_rev_user.revactor_actor = 'YYYYYYY'
  )
    OR
  (
     temp_rev_user.revactor_actor IS NULL AND rev_user = 'XXXXXXXX')
  )
  AND ((rev_deleted & 4) = 0)

ORDER BY rev_timestamp DESC LIMIT 51

I have obfuscated revactor_actor and rev_user

The query plan shows it is using a temporary and filesort against the page table which is a big NO/NO:

           id: 1
  select_type: PRIMARY
        table: page
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 682929
        Extra: Using temporary; Using filesort

• Marostegui moved this task from Triage to Blocked external/Not db team on the DBA board.Sep 18 2018, 1:01 PM

I have quickly poked the DBA to check whether something was going on, and the servers looks all fine.

From our Logstash, a query for ""contributions page unfiltered"" shows it had some occurrences for the last 30 days. There is slightly more since 09/17 ~ 16:00 UTC.

For those having access: https://logstash.wikimedia.org/goto/d9085504b0f3a18e89685a739473812e

hashar mentioned this in T191068: 1.32.0-wmf.22 deployment blockers.Sep 18 2018, 1:20 PM

The specific query in T204669#4593536 is due to the enabling of actor table WRITE_BOTH mode on mediawiki.org (07a6db7), so we can hopefully find slow queries like this and fix them before they go out to big content wikis and cause more trouble. Currently that config change is also enabled on testwiki, test2wiki, and testwikidatawiki.

In the somewhat-long term any slow queries like this would go away once we're done with the actor migration and no longer have to check both the 'actor' and 'user' fields. In the short term, I'll have to add code to do a union of the "old" and "new" queries instead of combining the different conditions with an OR.

• Marostegui removed a project: DBA.Sep 18 2018, 1:44 PM

• Marostegui added subscribers: jcrespo, • Banyek, • Marostegui.

Aklapper renamed this task from Slow access to Special:Contributions on mediawiki.org to Slow access to Special:Contributions on mediawiki.org (due to enabling actor table WRITE_BOTH mode).Sep 18 2018, 1:46 PM

Paladox subscribed.Sep 18 2018, 1:48 PM

I may decide to instead revert the config change and rewrite the migration process to use "write-both-read-old"→"write-both-read-new" instead of "write-both-read-both"→"write-new-read-both"; particularly when the revision table and special pages are involved, "read both" quickly gets complicated.

hashar mentioned this in T204764: DB error in PageTriage: Unknown column 'actor_rev_user.actor_user' in 'on clause'.Sep 18 2018, 8:22 PM

hashar mentioned this in T204767: Special:ActiveUsers fails with "Error: 1054 Unknown column 'rc_actor' in 'on clause' (10.192.32.110)".Sep 18 2018, 8:30 PM

Change 461209 had a related patch set uploaded (by Anomie; owner: Anomie):
[operations/mediawiki-config@master] Set ActorTableSchemaMigrationStage => OLD on test wikis, mw.org

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

gerritbot added a project: Patch-For-Review.Sep 18 2018, 8:50 PM

Change 461209 merged by jenkins-bot:
[operations/mediawiki-config@master] Set ActorTableSchemaMigrationStage => OLD on test wikis, mw.org

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

Mentioned in SAL (#wikimedia-operations) [2018-09-18T20:58:52Z] <catrope@deploy1001> Synchronized wmf-config/InitialiseSettings.php: Set ActorTableSchemaMigrationStage back to OLD on test wikis, mediawikiwiki (T188327, T204669) (duration: 00m 57s)

• CCicalese_WMF moved this task from Inbox to CPT-Q1-Jul-Sep-2018 on the Core-Platform-Team-Old board.Sep 19 2018, 1:29 AM

• CCicalese_WMF edited projects, added Core-Platform-Team-Old (CPT-Q1-Jul-Sep-2018); removed Core-Platform-Team-Old.

hashar added a parent task: T188327: Deploy refactored actor storage.Sep 19 2018, 7:28 AM

hashar removed a parent task: T191068: 1.32.0-wmf.22 deployment blockers.

Change 461440 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/core@master] ActorMigration: Remove possibility of read-both

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

Change 461441 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/extensions/ORES@master] Adjust for core change I4764c1c78

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

Change 461442 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/extensions/Renameuser@master] Adjust for core change I4764c1c78

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

Change 461443 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/extensions/UserMerge@master] Adjust for core change I4764c1c78

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

Change 461444 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/extensions/WikimediaMaintenance@master] Adjust for core change I4764c1c78

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

• CCicalese_WMF moved this task from Backlog to In Progress on the Core-Platform-Team-Old (CPT-Q1-Jul-Sep-2018) board.Oct 1 2018, 12:40 PM

• CCicalese_WMF edited projects, added Platform Team Legacy (Designing); removed Core-Platform-Team-Old (CPT-Q1-Jul-Sep-2018).Oct 1 2018, 1:27 PM

• CCicalese_WMF moved this task from Inbox to Doing on the Platform Team Legacy (Designing) board.Oct 1 2018, 1:33 PM

• CCicalese_WMF added a project: Platform Engineering.Oct 2 2018, 2:14 PM

• CCicalese_WMF moved this task from Inbox to MCR on the Platform Engineering board.Oct 2 2018, 6:49 PM

• CCicalese_WMF edited projects, added Platform Engineering (MCR); removed Platform Engineering.

• CCicalese_WMF moved this task from MCR to Needs Cleaning - Code Health (TEC13) on the Platform Engineering board.

• CCicalese_WMF edited projects, added Platform Engineering (Needs Cleaning - Code Health (TEC13)); removed Platform Engineering (MCR).

• CCicalese_WMF moved this task from Needs Cleaning - Code Health (TEC13) to Needs Cleaning - Security, stability, performance, and scalability (TEC1) on the Platform Engineering board.Oct 3 2018, 2:20 PM

• CCicalese_WMF edited projects, added Platform Engineering (Needs Cleaning - Security, stability, performance, and scalability (TEC1)); removed Platform Engineering (Needs Cleaning - Code Health (TEC13)).

I don't know if this is late to the game, but from the perspective of one who uses the http API: in the past 2 weeks or so, on en.wikipedia.org, a multi-user "usercontribs" query went from always returning immediately (sub-second) to always timing out. Is this change intended to fix that?

Redacted test case that times out on en.wikipedia.org:
GET /w/api.php?action=query&format=xml&list=usercontribs&ucuser=fakeuser1%7Cfakeuser2&uclimit=20&ucnamespace=0&ucprop=title%7Ctimestamp%7Ccomment%7Cflags&continue= HTTP/1.1

Remove the "%7Cfakeuser2" and it returns immeidately.

Change 461441 merged by jenkins-bot:
[mediawiki/extensions/ORES@master] Adjust for core change I4764c1c78

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

Change 461444 merged by jenkins-bot:
[mediawiki/extensions/WikimediaMaintenance@master] Adjust for core change I4764c1c78

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

Change 461440 merged by jenkins-bot:
[mediawiki/core@master] ActorMigration: Remove possibility of read-both

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

Change 461443 merged by jenkins-bot:
[mediawiki/extensions/UserMerge@master] Adjust for core change I4764c1c78

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

ReleaseTaggerBot added a project: MW-1.32-notes (WMF-deploy-2018-10-16 (1.32.0-wmf.26)).Oct 11 2018, 2:00 AM

Change 466720 had a related patch set uploaded (by Anomie; owner: Anomie):
[mediawiki/core@master] Improve some queries ordering by rev_timestamp with actor migration READ_NEW

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

• CCicalese_WMF edited projects, added Platform Team Workboards (Doing); removed Platform Team Legacy (Designing).Oct 14 2018, 3:55 PM

Change 466720 merged by jenkins-bot:
[mediawiki/core@master] Improve some queries ordering by rev_timestamp with actor migration READ_NEW

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

ReleaseTaggerBot added a project: MW-1.33-notes (1.33.0-wmf.3; 2018-11-06).Nov 1 2018, 7:00 AM

Anomie closed this task as Resolved.Nov 1 2018, 4:05 PM

• CCicalese_WMF moved this task from Doing to Done with CPT on the Platform Team Workboards board.Nov 5 2018, 9:48 PM

• CCicalese_WMF edited projects, added Platform Team Workboards (Done with CPT); removed Platform Team Workboards (Doing).

Should we backport the fix (and others) to REL1_31 / REL1_32?

I don't know. rMW993baa3493f1: ActorMigration: Remove possibility of read-both is a bit of a large change, the default is MIGRATION_OLD, and if a wiki goes straight to MIGRATION_NEW they wouldn't run into this either.

Change 461442 merged by Umherirrender:
[mediawiki/extensions/Renameuser@master] Adjust for core change I4764c1c78

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

ReleaseTaggerBot edited projects, added MW-1.33-notes (1.33.0-wmf.8; 2018-12-11); removed MW-1.33-notes (1.33.0-wmf.3; 2018-11-06).Dec 8 2018, 2:00 PM

Aklapper removed subscribers: • Banyek, Anomie.Oct 16 2020, 5:40 PM

Umherirrender mentioned this in T88084: Using both rvuser and rvcontinue with prop=revisions causes database error on pages with a lot of revisions.Sep 5 2022, 7:44 PM