Page MenuHomePhabricator

Fix Warning: According to a SiteLinkLookup Q-item is linked when actually is unlinked or non-existent
Closed, DeclinedPublicPRODUCTION ERROR

Description

I spotted the following in the logspam.

Warning: According to a SiteLinkLookup Q47013093 is linked to frwiki while it is not or it does not exist. [Called from Wikibase\Client\ParserOutput\ClientParserOutputDataUpdater::setBadgesProperty in /srv/mediawiki/php-1.31.0-wmf.12/extensions/Wikibase/client/includes/ParserOutput/ClientParserOutputDataUpdater.php at line 126] in /srv/mediawiki/php-1.31.0-wmf.12/includes/debug/MWDebug.php on line 309

After the patch altering the logging these exist as below:

https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-mediawiki-2020.01.13/mediawiki/?id=AW-hVDQFKWrIH1QR-VG_

According to SiteLinkLookup Q9896024 is linked to itwiki, but the link does not exist.

We should probably investigate this and figure out what ha happened, and if there is a fix that is needed.

Event Timeline

Addshore created this task.Jan 2 2018, 8:57 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJan 2 2018, 8:57 PM

It looks like https://www.wikidata.org/wiki/Special:Diff/615878263 (“‎Added [fr] label: Echelon II: Wind Warriors”) also removed the sitelink, at least according to the diff.

Mbch331 added a subscriber: Mbch331.Jan 3 2018, 5:55 PM

Wikidata item has no sitelinks (confirmed by wbgetentities), however the formerly linked page https://fr.wikipedia.org/wiki/Echelon_II:_Wind_Warriors still is linked to https://www.wikidata.org/wiki/Q47013093 according to pageprops.

I looked into this yesterday and the edits have been made in exact same second which means the second edit read from replica (which was lagged behind) and accidentally removed the sitelink. There are several ways to think about this issue:

  1. If such cases are rare and can easily be found in logstash, let's fix them as they arise
  2. If they are more than one case ( I checked and it seems it's two cases in the past 7 days) We need to make sure tools or Wikibase itself put some time between edits (I think this is made using Wikibase itself) We should ask user what they used that made this happen.
daniel closed this task as Declined.Feb 26 2018, 2:46 PM
daniel added a subscriber: daniel.

This can happen every now and then due to replag. We should not worry unless this happens a LOT.

This can happen every now and then due to replag. We should not worry unless this happens a LOT.

It happened 550 times over the past hour, which is a significant amount of log spam.

It happened 550 times over the past hour, which is a significant amount of log spam.

It's probably a symptom of another issue.

This can happen every now and then due to replag. We should not worry unless this happens a LOT.

If this isn't a problem with the code that needs an obvious/immediate fix, perhaps this shouldn't emit a PHP error. Might want to instead emit a message to a custom channel instead and have monitor that, or e.g. Icinga alert that queries Logstash/Graphite, or emit a Statsd increment and put a Grafana alert on it, or simply check the Logstash dashboard manually from time to time.

Raising the general MW exception/error levels with this and causing aborted deployments is presumably not the intent of this code :) - There is no actionable.

Krinkle reopened this task as Open.Jul 11 2019, 8:33 PM

Seen again in prod today:

  • Request ID: XSeYmwpAAD0AAFX9ZwwAAADG
  • Request URL: GET en.wikipedia.org /wiki/ (some page title)
message
PHP Warning: According to a SiteLinkLookup Q--- is linked to itwiki while it is not or it does not exist. [Called from Wikibase\Client\ParserOutput\ClientParserOutputDataUpdater::setBadgesProperty in /srv/mediawiki/php-1.34.0-wmf.13/extensions/Wikibase/client/includes/ParserOutput/ClientParserOutputDataUpdater.php at line 140]
trace
#0 /srv/mediawiki/php-1.34.0-wmf.13/includes/debug/MWDebug.php(309): MWExceptionHandler::handleError(integer, string, string, integer, array, array)
#1 /srv/mediawiki/php-1.34.0-wmf.13/includes/debug/MWDebug.php(164): MWDebug::sendMessage(string, array, string, integer)
#2 /srv/mediawiki/php-1.34.0-wmf.13/includes/GlobalFunctions.php(1078): MWDebug::warning(string, integer, integer, string)
#3 /srv/mediawiki/php-1.34.0-wmf.13/extensions/Wikibase/client/includes/ParserOutput/ClientParserOutputDataUpdater.php(140): wfLogWarning(string)
#4 /srv/mediawiki/php-1.34.0-wmf.13/extensions/Wikibase/client/includes/ParserOutput/ClientParserOutputDataUpdater.php(127): Wikibase\Client\ParserOutput\ClientParserOutputDataUpdater->setBadgesProperty(Wikibase\DataModel\Entity\ItemId, ParserOutput)
#5 /srv/mediawiki/php-1.34.0-wmf.13/extensions/Wikibase/client/includes/Hooks/ParserOutputUpdateHookHandlers.php(103): Wikibase\Client\ParserOutput\ClientParserOutputDataUpdater->updateBadgesProperty(Title, ParserOutput)
#6 /srv/mediawiki/php-1.34.0-wmf.13/extensions/Wikibase/client/includes/Hooks/ParserOutputUpdateHookHandlers.php(65): Wikibase\Client\Hooks\ParserOutputUpdateHookHandlers->doContentAlterParserOutput(Title, ParserOutput)
#7 /srv/mediawiki/php-1.34.0-wmf.13/includes/Hooks.php(174): Wikibase\Client\Hooks\ParserOutputUpdateHookHandlers::onContentAlterParserOutput(WikitextContent, Title, ParserOutput)
#8 /srv/mediawiki/php-1.34.0-wmf.13/includes/Hooks.php(202): Hooks::callHook(string, array, array, NULL)
#9 /srv/mediawiki/php-1.34.0-wmf.13/includes/content/AbstractContent.php(559): Hooks::run(string, array)
#10 /srv/mediawiki/php-1.34.0-wmf.13/includes/Revision/RenderedRevision.php(266): AbstractContent->getParserOutput(Title, integer, ParserOptions, boolean)
#11 /srv/mediawiki/php-1.34.0-wmf.13/includes/Revision/RenderedRevision.php(234): MediaWiki\Revision\RenderedRevision->getSlotParserOutputUncached(WikitextContent, boolean)
#12 /srv/mediawiki/php-1.34.0-wmf.13/includes/Revision/RevisionRenderer.php(199): MediaWiki\Revision\RenderedRevision->getSlotParserOutput(string)
#13 /srv/mediawiki/php-1.34.0-wmf.13/includes/Revision/RevisionRenderer.php(148): MediaWiki\Revision\RevisionRenderer->combineSlotOutput(MediaWiki\Revision\RenderedRevision, array)
#14 [internal function]: Closure$MediaWiki\Revision\RevisionRenderer::getRenderedRevision#2(MediaWiki\Revision\RenderedRevision, array)
#15 /srv/mediawiki/php-1.34.0-wmf.13/includes/Revision/RenderedRevision.php(197): call_user_func(Closure$MediaWiki\Revision\RevisionRenderer::getRenderedRevision#2;2946, MediaWiki\Revision\RenderedRevision, array)
#16 /srv/mediawiki/php-1.34.0-wmf.13/includes/poolcounter/PoolWorkArticleView.php(196): MediaWiki\Revision\RenderedRevision->getRevisionParserOutput()
#17 /srv/mediawiki/php-1.34.0-wmf.13/includes/poolcounter/PoolCounterWork.php(123): PoolWorkArticleView->doWork()
#18 /srv/mediawiki/php-1.34.0-wmf.13/includes/page/Article.php(774): PoolCounterWork->execute()
#19 /srv/mediawiki/php-1.34.0-wmf.13/includes/actions/ViewAction.php(63): Article->view()
#20 /srv/mediawiki/php-1.34.0-wmf.13/includes/MediaWiki.php(499): ViewAction->show()
#21 /srv/mediawiki/php-1.34.0-wmf.13/includes/MediaWiki.php(294): MediaWiki->performAction(Article, Title)
#22 /srv/mediawiki/php-1.34.0-wmf.13/includes/MediaWiki.php(884): MediaWiki->performRequest()
#23 /srv/mediawiki/php-1.34.0-wmf.13/includes/MediaWiki.php(515): MediaWiki->main()
#24 /srv/mediawiki/php-1.34.0-wmf.13/index.php(42): MediaWiki->run()
#25 /srv/mediawiki/w/index.php(3): include(string)
mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:09 PM

Change 542737 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/extensions/Wikibase@master] Make warning less noisy from ClientParserOutputDataUpdater

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

Change 542737 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Make warning less noisy from ClientParserOutputDataUpdater

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

It looks like these still occur. (Image of a 7 day period)

Addshore updated the task description. (Show Details)Jan 14 2020, 12:43 PM
Addshore triaged this task as Low priority.Jan 14 2020, 12:46 PM
Addshore added a subscriber: aaron.

If they are more than one case ( I checked and it seems it's two cases in the past 7 days) We need to make sure tools or Wikibase itself put some time between edits (I think this is made using Wikibase itself) We should ask user what they used that made this happen.

Shouldn't chronology protector help us here?

Addshore moved this task from Incoming to Needs Work on the Wikidata-Campsite board.
Restricted Application added a project: User-Addshore. · View Herald TranscriptJan 14 2020, 12:48 PM

If they are more than one case ( I checked and it seems it's two cases in the past 7 days) We need to make sure tools or Wikibase itself put some time between edits (I think this is made using Wikibase itself) We should ask user what they used that made this happen.

Shouldn't chronology protector help us here?

It probably is relevant, though without looking at the code or API request pattern in question, I can't say whether anything is wrong off hand. Does these errors occur to users who themsleves just made an edit or is it other users attempting to access something recently edited by someone else? Are there relevant uses of WANObjectCache that do not use getCacheSetOptions()?

Krinkle renamed this task from Investigate & Fix "According to a SiteLinkLookup Q47013093 is linked to frwiki while it is not or it does not exist" in logs to Fix Warning: According to a SiteLinkLookup Q-item is linked when actually is unlinked or non-existent.Jan 29 2020, 12:07 AM

Untagging as it's no longer a prod error. The issue has been ack'ed and turned into a debug log message. If a functional problem exists, the task will continue to track the work related to that but it no longer raises affected prod stability metrics and automated alerts/deploy aborts.

Addshore closed this task as Declined.Apr 28 2020, 2:46 PM

Re Declining with the same reasoning.
We have also recently rebuild this whole secondary table (its still rebuilding as I write this) so anything odd left over in the table should be cleaned up.