Page MenuHomePhabricator

[RefreshLinksJob] RevisionStore::constructSlotRecords: Main slot of revision not found in database
Open, Needs TriagePublic

Description

Filing a separate bug from T212428: includes/Revision/RevisionStore.php: Main slot of revision (number) not found in database! even though the error is the same:

Main slot of revision not found in database. See T212428

Full trace:

[2023-06-01T06:57:22.699757+00:00] exception.ERROR: [c47c4e5c2c3894512d7ac9d7] [no req]   MediaWiki\Revision\RevisionAccessException: Main slot of revision not found in database. See T212428. {"exception":"[o
bject] (MediaWiki\\Revision\\RevisionAccessException(code: 0): Main slot of revision not found in database. See T212428. at /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionStore.php:1522)
[stacktrace]
#0 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionStore.php(1417): MediaWiki\\Revision\\RevisionStore->constructSlotRecords()
#1 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionStore.php(1556): MediaWiki\\Revision\\RevisionStore->loadSlotRecords()
#2 [internal function]: MediaWiki\\Revision\\RevisionStore->MediaWiki\\Revision\\{closure}()
#3 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionSlots.php(170): call_user_func()
#4 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionSlots.php(129): MediaWiki\\Revision\\RevisionSlots->getSlots()
#5 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionRecord.php(217): MediaWiki\\Revision\\RevisionSlots->hasSlot()
#6 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3709): MediaWiki\\Revision\\RevisionRecord->hasSlot()
#7 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3583): Parser::statelessFetchTemplate()
#8 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3477): Parser->fetchTemplateAndTitle()
#9 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3218): Parser->getTemplateDom()
#10 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#11 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3293): PPFrame_Hash->expand()
#12 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#13 /srv/mediawiki/tags/2023-05-30_12:35:44/extensions/ParserFunctions/includes/ParserFunctions.php(105): PPFrame_Hash->expand()
#14 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3417): MediaWiki\\Extension\\ParserFunctions\\ParserFunctions::if()
#15 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3102): Parser->callParserFunction()
#16 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#17 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3293): PPFrame_Hash->expand()
#18 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#19 /srv/mediawiki/tags/2023-05-30_12:35:44/extensions/ParserFunctions/includes/ParserFunctions.php(130): PPFrame_Hash->expand()
#20 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3417): MediaWiki\\Extension\\ParserFunctions\\ParserFunctions::ifeq()
#21 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3102): Parser->callParserFunction()
#22 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#23 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3293): PPFrame_Hash->expand()
#24 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#25 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3293): PPFrame_Hash->expand()
#26 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#27 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(3293): PPFrame_Hash->expand()
#28 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/PPFrame_Hash.php(277): Parser->braceSubstitution()
#29 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(2935): PPFrame_Hash->expand()
#30 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(1588): Parser->replaceVariables()
#31 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/parser/Parser.php(700): Parser->internalParse()
#32 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/content/WikitextContentHandler.php(357): Parser->parse()
#33 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/content/ContentHandler.php(1752): WikitextContentHandler->fillParserOutput()
#34 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/content/Renderer/ContentRenderer.php(47): ContentHandler->getParserOutput()
#35 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RenderedRevision.php(260): MediaWiki\\Content\\Renderer\\ContentRenderer->getParserOutput()
#36 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RenderedRevision.php(232): MediaWiki\\Revision\\RenderedRevision->getSlotParserOutputUncached()
#37 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionRenderer.php(227): MediaWiki\\Revision\\RenderedRevision->getSlotParserOutput()
#38 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionRenderer.php(164): MediaWiki\\Revision\\RevisionRenderer->combineSlotOutput()
#39 [internal function]: MediaWiki\\Revision\\RevisionRenderer->MediaWiki\\Revision\\{closure}()
#40 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RenderedRevision.php(199): call_user_func()
#41 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/jobs/RefreshLinksJob.php(330): MediaWiki\\Revision\\RenderedRevision->getRevisionParserOutput()
#42 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/jobs/RefreshLinksJob.php(230): RefreshLinksJob->getParserOutput()
#43 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/jobs/RefreshLinksJob.php(153): RefreshLinksJob->runForTitle()
#44 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/JobRunner.php(363): RefreshLinksJob->run()
#45 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/JobRunner.php(324): JobRunner->doExecuteJob()
#46 /srv/mediawiki/tags/2023-05-30_12:35:44/includes/jobqueue/JobRunner.php(228): JobRunner->executeJob()
#47 /srv/mediawiki/tags/2023-05-30_12:35:44/maintenance/runJobs.php(99): JobRunner->run()
#48 /srv/mediawiki/tags/2023-05-30_12:35:44/maintenance/includes/MaintenanceRunner.php(681): RunJobs->execute()
#49 /srv/mediawiki/tags/2023-05-30_12:35:44/maintenance/run.php(51): MediaWiki\\Maintenance\\MaintenanceRunner->run()
#50 {main}
","exception_url":"[no req]","reqId":"c47c4e5c2c3894512d7ac9d7","caught_by":"other"} []

I had configured log channel for RevisionStore so I was able to debug further:

[2023-06-01T06:57:22.698017+00:00] RevisionStore.INFO: MediaWiki\Revision\RevisionStore::loadSlotRecordsFromDb falling back to READ_LATEST. {"revid":11628063,"exception":"[object] (RuntimeException(code: 0):  at /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionStore.php:1443)"} []
[2023-06-01T06:57:22.698682+00:00] RevisionStore.ERROR: MediaWiki\Revision\RevisionStore::constructSlotRecords: Main slot of revision not found in database. See T212428. {"revid":11628063,"queryFlags":0,"exception":"[object] (RuntimeException(code: 0):  at /srv/mediawiki/tags/2023-05-30_12:35:44/includes/Revision/RevisionStore.php:1518)"} []

However it cannot be fixed:

$ php maintenance/run.php findBadBlobs --revisions 11628063
Scanning 1 ids
        - Scanned a batch of 1 revisions
Found 0 bad revisions.

Investigating:

MariaDB [translatewiki_net]> select * from bw_revision where rev_id = '11628063'\G
*************************** 1. row ***************************
        rev_id: 11628063
      rev_page: 7782606
rev_comment_id: 0
     rev_actor: 1116
 rev_timestamp: 20230601065722
rev_minor_edit: 0
   rev_deleted: 0
       rev_len: 19434
 rev_parent_id: 11627752
      rev_sha1: h2xlj57z955ne9dojb7djhk8ko4zckr
1 row in set (0.001 sec)
MariaDB [translatewiki_net]> select * from bw_page where page_id = '7782606'\G
*************************** 1. row ***************************
           page_id: 7782606
    page_namespace: 10
        page_title: Languagename/t
  page_is_redirect: 0
       page_is_new: 0
       page_random: 0.475838959229
      page_touched: 20230601065722
       page_latest: 11628063
          page_len: 19434
page_content_model: wikitext
page_links_updated: 20230601065710
         page_lang: NULL
1 row in set (0.001 sec)

This seems to indicate a race condition since revision works fine afterwards.

Some more info from history of log recent log entries:

MariaDB [translatewiki_net]> select page_namespace,page_title,rev_timestamp,rev_actor from bw_revision JOIN bw_page on (rev_page = page_id) where rev_id in (11620249,11620652,11620980,116
+----------------+-------------------------+----------------+-----------+
| page_namespace | page_title              | rev_timestamp  | rev_actor |
+----------------+-------------------------+----------------+-----------+
|              8 | Revdelete-radio-same/sn | 20230528163318 |   4336779 |
|             10 | Scriptfonts             | 20230529022330 |      1116 |
|             10 | Languagename/a          | 20230529125048 |      1116 |
|             10 | Languagename/a          | 20230529164919 |      1116 |
|             10 | Languagename/a          | 20230530092239 |      1116 |
|             10 | Languagename/a          | 20230530100230 |      1116 |
|             10 | Languagename/m          | 20230530134055 |      1116 |
|             10 | Languagename/f          | 20230601065443 |      1116 |
|             10 | Languagename/t          | 20230601065722 |      1116 |
+----------------+-------------------------+----------------+-----------+

Looking at Logstash, this seems to affect WMF production too.