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

Assigned To

Authored By

	Addshore
	Jan 2 2018, 8:57 PM

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.

Details

	Subject	Repo	Branch	Lines +/-
	Make warning less noisy from ClientParserOutputDataUpdater	mediawiki/extensions/Wikibase	master	+37 -18

Customize query in gerrit

Related Objects

Mentioned In: T265376: Merging item with sitelinks seems to sometimes(?) cause the "According to SiteLinkLookup {item} is linked to {site}, but the link does not exist." error

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

WMDE-leszek subscribed.Jan 3 2018, 4:28 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.

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:

If such cases are rare and can easily be found in logstash, let's fix them as they arise
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.

Ladsgroup moved this task from incoming to consider for next sprint on the Wikidata board.Jan 16 2018, 10:34 AM

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

In T183993#4001382, @daniel wrote:

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.

In T183993#4703835, @Catrope wrote:

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

It's probably a symptom of another issue.

In T183993#4001382, @daniel wrote:

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.

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)

Ladsgroup added a project: Wikidata-Campsite.Jul 11 2019, 8:35 PM

Krinkle moved this task from Untriaged to Jul2019/1.34.wmf.13+ on the Wikimedia-production-error board.Jul 16 2019, 2:55 PM

• 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

gerritbot added a project: Patch-For-Review.Oct 13 2019, 1:07 AM

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

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

Maintenance_bot removed a project: Patch-For-Review.Oct 21 2019, 12:11 PM

ReleaseTaggerBot added a project: MW-1.35-notes (1.35.0-wmf.3; 2019-10-22).Oct 21 2019, 7:00 PM

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

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 claimed this task.Jan 14 2020, 12:48 PM

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

Addshore moved this task from consider for next sprint to needs discussion or investigation on the Wikidata board.Jan 14 2020, 12:48 PM

In T183993#5801637, @Addshore wrote:

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()?

Addshore moved this task from Unsorted 💣 to Back Burner 🏛️ on the User-Addshore board.Jan 16 2020, 11:40 PM

Addshore moved this task from Needs Work to Needs Tech Work on the Wikidata-Campsite board.Jan 27 2020, 3:50 PM

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.

Krinkle removed projects: MW-1.35-notes (1.35.0-wmf.3; 2019-10-22), Wikimedia-production-error.Jan 29 2020, 12:10 AM

Krinkle unsubscribed.

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.

Michael subscribed.Jun 19 2020, 8:09 AM

Michael mentioned this in T265376: Merging item with sitelinks seems to sometimes(?) cause the "According to SiteLinkLookup {item} is linked to {site}, but the link does not exist." error.Oct 13 2020, 4:32 PM

Fix Warning: According to a SiteLinkLookup Q-item is linked when actually is unlinked or non-existentClosed, DeclinedPublicPRODUCTION ERRORActions

Description

Details

Related Objects

Event Timeline

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