PHP Warning: [data-update-failed]: A data update callback triggered an exception (Fail-safe exception. Avoiding infinite loop due to possibily undetectable existing records in master. It may be due to encoding incompatibility between database values and values passed in $neededRecords parameter.) [Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 62]
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error

MediaWiki version: 1.35.0-wmf.37

message
PHP Warning: [data-update-failed]: A data update callback triggered an exception (Fail-safe exception. Avoiding infinite loop due to possibily undetectable existing records in master.
 It may be due to encoding incompatibility between database values and values passed in $neededRecords parameter.) [Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 62]

Impact

  • Seems to have started today at around 8:20 UTC. Looks like 100 events per 30 minutes.

Notes

Details

Request ID
140f3eda-6e6f-4223-bcc6-d7786bb293f4
Request URL
https://www.wikidata.org/w/api.php
Stack Trace
exception.trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.35.0-wmf.37/includes/debug/MWDebug.php(393): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.35.0-wmf.37/includes/debug/MWDebug.php(196): MWDebug::sendMessage(string, string, integer)
#3 /srv/mediawiki/php-1.35.0-wmf.37/includes/GlobalFunctions.php(1064): MWDebug::warning(string, integer, integer, string)
#4 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/lib/includes/Reporting/LogWarningExceptionHandler.php(28): wfLogWarning(string, integer)
#5 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php(62): Wikibase\Lib\Reporting\LogWarningExceptionHandler->handleException(Exception, string, string)
#6 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/DeferredUpdates.php(466): Wikibase\Repo\Content\DataUpdateAdapter->doUpdate()
#7 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/RefreshSecondaryDataUpdate.php(101): DeferredUpdates::attemptUpdate(Wikibase\Repo\Content\DataUpdateAdapter, Wikimedia\Rdbms\LBFactoryMulti)
#8 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/DeferredUpdates.php(466): RefreshSecondaryDataUpdate->doUpdate()
#9 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/DeferredUpdates.php(343): DeferredUpdates::attemptUpdate(RefreshSecondaryDataUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#10 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/DeferredUpdates.php(278): DeferredUpdates::run(RefreshSecondaryDataUpdate, Wikimedia\Rdbms\LBFactoryMulti, Monolog\Logger, BufferingStatsdDataFactory, string)
#11 /srv/mediawiki/php-1.35.0-wmf.37/includes/deferred/DeferredUpdates.php(194): DeferredUpdates::handleUpdateQueue(array, string, integer)
#12 /srv/mediawiki/php-1.35.0-wmf.37/includes/MediaWiki.php(1072): DeferredUpdates::doUpdates(string)
#13 /srv/mediawiki/php-1.35.0-wmf.37/includes/MediaWiki.php(849): MediaWiki->restInPeace()
#14 /srv/mediawiki/php-1.35.0-wmf.37/includes/MediaWiki.php(861): MediaWiki->{closure}()
#15 /srv/mediawiki/php-1.35.0-wmf.37/api.php(119): MediaWiki->doPostOutputShutdown()
#16 /srv/mediawiki/w/api.php(3): require(string)
#17 {main}

Event Timeline

Michael triaged this task as Unbreak Now! priority.Jun 19 2020, 10:41 AM

Change 606691 had a related patch set uploaded (by Addshore; owner: Addshore):
[mediawiki/extensions/Wikibase@master] AdHocLogging for ReplicaMasterAwareRecordIdsAcquirer

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

Change 606692 had a related patch set uploaded (by Addshore; owner: Addshore):
[mediawiki/extensions/Wikibase@wmf/1.35.0-wmf.37] AdHocLogging for ReplicaMasterAwareRecordIdsAcquirer

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

Michael lowered the priority of this task from Unbreak Now! to High.Jun 19 2020, 1:40 PM

After debugging together with @Addshore, I'm lowering the priority for now as it doesn't seem to do permanent damage. It seems to go wrong somewhere in ReplicaMasterAwareRecordIdsAcquirer::insertNonExistingRecords, but we don't know where/how exactly.

We have a patch that adds more debugging output (see above), but we decided against deploying it on a Friday.

Just noting here that this didn't stop yet.

image.png (314×1 px, 37 KB)

We are currently speculating that these errors might be triggered by a batch of quickstatement edits adding labels to Chinese villages.

Two candidates are:

The errors reduced their frequency abruptly over the weekend, but are occasionally still happening:

image.png (189×1 px, 23 KB)

Change 606692 abandoned by Addshore:
AdHocLogging for ReplicaMasterAwareRecordIdsAcquirer

Reason:
No longer needed to backport

https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Wikibase/ /606692

Change 606691 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] More logging for ReplicaMasterAwareRecordIdsAcquirer error case

https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Wikibase/ /606691

Marking as resolved as the issue and spike went away, and we added more logging