Page MenuHomePhabricator

Wikibase\\TermSqlIndex::deleteTerms: Deadlock found when trying to get lock; try restarting transaction
Closed, ResolvedPublicPRODUCTION ERROR

Description

2019 Report
PHP Warning: [data-update-failed]: A data update callback triggered an exception (A database query error has occurred. Did you forget to run your application's database schema updater after upgrading? 
Query: DELETE FROM `wb_terms` WHERE term_language = 'ro' AND term_type = 'description' AND term_text = 'format Wikimedia' AND term_full_entity_id = 'Q14403615'
Function: Wikibase\Lib\Store\Sql\TermSqlIndex::deleteTerms
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.48.172)
) [Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.35.0-wmf.1/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 62]
2016 Report

Getting errors like:

Apr  8 09:02:17 mw1342:  #012Warning: [data-update-failed]: A data update callback triggered an exception (A database query error has occurred. Did you forget to run your application's database schema updater after upgrading? #012Query: DELETE FROM `wb_terms` WHERE term_language = 'en' AND term_type = 'label' AND term_text = 'Analyzing Cancer Disparities: A New Policy Landscape Calls for New Approaches to Research.' AND term_full_entity_id = 'Q35898854'#012Function: Wikibase\Lib\Store\Sql\TermSqlIndex::deleteTerms#012Error: 1213 Deadlock found when trying to get lock; try restarting transaction (10.64.48.26)#012) [Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.31.0-wmf.28/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 67] in /srv/mediawiki/php-1.31.0-wmf.28/includes/debug/MWDebug.php on line 309

This happens occasionally:

$ zgrep -cF 'Wikibase\\TermSqlIndex::deleteTerms\nError' archive/hhvm.log-201611*
archive/hhvm.log-20161101.gz:0
archive/hhvm.log-20161102.gz:0
archive/hhvm.log-20161103.gz:1
archive/hhvm.log-20161104.gz:1
archive/hhvm.log-20161105.gz:0
archive/hhvm.log-20161106.gz:1
archive/hhvm.log-20161107.gz:0
archive/hhvm.log-20161108.gz:2
archive/hhvm.log-20161109.gz:1
archive/hhvm.log-20161110.gz:0
archive/hhvm.log-20161111.gz:0
archive/hhvm.log-20161112.gz:0
archive/hhvm.log-20161113.gz:2
archive/hhvm.log-20161114.gz:0
archive/hhvm.log-20161115.gz:0
archive/hhvm.log-20161116.gz:1
archive/hhvm.log-20161117.gz:0
archive/hhvm.log-20161118.gz:2
archive/hhvm.log-20161119.gz:0
archive/hhvm.log-20161120.gz:1
archive/hhvm.log-20161121.gz:0
archive/hhvm.log-20161122.gz:3
archive/hhvm.log-20161123.gz:3
archive/hhvm.log-20161124.gz:0
archive/hhvm.log-20161125.gz:3
archive/hhvm.log-20161126.gz:1
archive/hhvm.log-20161127.gz:3

This could probably be solved or at least severely eased by collecting primary keys first (maybe even from a replica) and later on deleting by PK (in TermSqlIndex::deleteTerms and TermSqlIndex::deleteTermsOfEntity)

Details

Request ID
XaFW6QpAEMYAALXzYP0AAACN
Request URL
/w/api.php
Stack Trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.35.0-wmf.1/includes/debug/MWDebug.php(333): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.35.0-wmf.1/includes/debug/MWDebug.php(188): MWDebug::sendMessage(string, array, string, integer)
#3 /srv/mediawiki/php-1.35.0-wmf.1/includes/GlobalFunctions.php(1079): MWDebug::warning(string, integer, integer, string)
#4 /srv/mediawiki/php-1.35.0-wmf.1/extensions/Wikibase/lib/includes/Reporting/LogWarningExceptionHandler.php(28): wfLogWarning(string, integer)
#5 /srv/mediawiki/php-1.35.0-wmf.1/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php(62): Wikibase\Lib\Reporting\LogWarningExceptionHandler->handleException(Wikimedia\Rdbms\DBQueryError, string, string)
#6 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/DeferredUpdates.php(383): Wikibase\Repo\Content\DataUpdateAdapter->doUpdate()
#7 /srv/mediawiki/php-1.35.0-wmf.1/includes/Storage/DerivedPageDataUpdater.php(1630): DeferredUpdates::attemptUpdate(Wikibase\Repo\Content\DataUpdateAdapter, Wikimedia\Rdbms\LBFactoryMulti)
#8 /srv/mediawiki/php-1.35.0-wmf.1/includes/Storage/DerivedPageDataUpdater.php(1446): MediaWiki\Storage\DerivedPageDataUpdater->doSecondaryDataUpdates(array)
#9 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/MWCallableUpdate.php(38): MediaWiki\Storage\DerivedPageDataUpdater->MediaWiki\Storage\{closure}()
#10 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/DeferredUpdates.php(383): MWCallableUpdate->doUpdate()
#11 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/DeferredUpdates.php(281): DeferredUpdates::attemptUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#12 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/DeferredUpdates.php(226): DeferredUpdates::run(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti, Monolog\Logger, BufferingStatsdDataFactory, string)
#13 /srv/mediawiki/php-1.35.0-wmf.1/includes/deferred/DeferredUpdates.php(149): DeferredUpdates::handleUpdateQueue(array, string, integer)
#14 /srv/mediawiki/php-1.35.0-wmf.1/includes/MediaWiki.php(1053): DeferredUpdates::doUpdates(string)
#15 /srv/mediawiki/php-1.35.0-wmf.1/includes/MediaWiki.php(833): MediaWiki->restInPeace()
#16 /srv/mediawiki/php-1.35.0-wmf.1/includes/MediaWiki.php(842): MediaWiki->{closure}()
#17 /srv/mediawiki/php-1.35.0-wmf.1/api.php(118): MediaWiki->doPostOutputShutdown()
#18 /srv/mediawiki/w/api.php(3): require(string)
#19 {main}

Related Objects

Event Timeline

hoo created this task.Nov 28 2016, 7:19 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptNov 28 2016, 7:19 PM
hoo added a comment.Feb 11 2017, 1:52 PM

Probably the same thing, still happening fairly often:

$ zgrep -c TermSqlIndex::deleteTerms archive/DBQuery.log-201702*
archive/DBQuery.log-20170201.gz:11
archive/DBQuery.log-20170202.gz:0
archive/DBQuery.log-20170203.gz:6
archive/DBQuery.log-20170204.gz:5
archive/DBQuery.log-20170205.gz:4
archive/DBQuery.log-20170206.gz:5
archive/DBQuery.log-20170207.gz:4
archive/DBQuery.log-20170208.gz:8
archive/DBQuery.log-20170209.gz:1
archive/DBQuery.log-20170210.gz:8
archive/DBQuery.log-20170211:11
hoo added a comment.Oct 26 2017, 6:34 PM

Still seeing this, but the numbers don't seem very bad:

$ zgrep -c TermSqlIndex::deleteTerms archive/DBQuery.log-201710*
archive/DBQuery.log-20171001.gz:1
archive/DBQuery.log-20171002.gz:6
archive/DBQuery.log-20171003.gz:1
archive/DBQuery.log-20171004.gz:1
archive/DBQuery.log-20171005.gz:1
archive/DBQuery.log-20171006.gz:0
archive/DBQuery.log-20171007.gz:3
archive/DBQuery.log-20171008.gz:17
archive/DBQuery.log-20171009.gz:0
archive/DBQuery.log-20171010.gz:0
archive/DBQuery.log-20171011.gz:0
archive/DBQuery.log-20171012.gz:1
archive/DBQuery.log-20171013.gz:0
archive/DBQuery.log-20171014.gz:0
archive/DBQuery.log-20171015.gz:0
archive/DBQuery.log-20171016.gz:0
archive/DBQuery.log-20171017.gz:0
archive/DBQuery.log-20171018.gz:0
archive/DBQuery.log-20171019.gz:2
archive/DBQuery.log-20171020.gz:0
archive/DBQuery.log-20171021.gz:1
archive/DBQuery.log-20171022.gz:0
archive/DBQuery.log-20171023.gz:0
archive/DBQuery.log-20171024.gz:0
archive/DBQuery.log-20171025.gz:0
archive/DBQuery.log-20171026:0
hoo updated the task description. (Show Details)Oct 26 2017, 6:36 PM
thiemowmde triaged this task as Low priority.Oct 27 2017, 11:54 AM
thiemowmde added a project: patch-welcome.
thiemowmde moved this task from incoming to monitoring on the Wikidata board.
hoo raised the priority of this task from Low to Medium.Apr 12 2018, 12:55 PM

This has become more pressing since the switch to fully qualified entity ids in the table:

$ zgrep -cP 'TermSqlIndex::deleteTerms.*Deadlock' archive/hhvm.log-201804*
archive/hhvm.log-20180401.gz:6                                                                                                                                                                                                                                                 
archive/hhvm.log-20180402.gz:0                                                                                                                                                                                                                                                 
archive/hhvm.log-20180403.gz:2                                                                                                                                                                                                                                                 
archive/hhvm.log-20180404.gz:2                                                                                                                                                                                                                                                 
archive/hhvm.log-20180405.gz:4                                                                                                                                                                                                                                                 
archive/hhvm.log-20180406.gz:48                                                                                                                                                                                                                                                
archive/hhvm.log-20180407.gz:62                                                                                                                                                                                                                                                
archive/hhvm.log-20180408.gz:40                                                                                                                                                                                                                                                
archive/hhvm.log-20180409.gz:30                                                                                                                                                                                                                                                
archive/hhvm.log-20180410.gz:72                                                                                                                                                                                                                                                
archive/hhvm.log-20180411.gz:82                                                                                                                                                                                                                                                
archive/hhvm.log-20180412:102
hoo updated the task description. (Show Details)Apr 12 2018, 12:57 PM
Krinkle added a subscriber: Krinkle.

Still seen:

exception.message:
Wikimedia\Rdbms\DBTransactionStateError
Cannot execute query from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate while transaction status is ERROR.

exception.previous.message:
A database query error has occurred. 
Query: DELETE FROM `wb_terms` WHERE term_language = 'ru' AND term_type = 'label' AND term_text = 'Соловецкий (Архангельская область)' AND term_full_entity_id = 'Q3964446'
Function: Wikibase\Lib\Store\Sql\TermSqlIndex::deleteTerms
Error: 1213 Deadlock found when trying to get lock; try restarting transaction (10.64.48.26)

exception.previous.trace:
#0 /srv/mediawiki/php-1.32.0-wmf.20/includes/libs/rdbms/database/Database.php(1192): Wikimedia\Rdbms\Database->makeQueryException(string, integer, string, string)
#1 /srv/mediawiki/php-1.32.0-wmf.20/includes/libs/rdbms/database/Database.php(2907): Wikimedia\Rdbms\Database->query(string, string)
#2 /srv/mediawiki/php-1.32.0-wmf.20/extensions/Wikibase/lib/includes/Store/Sql/TermSqlIndex.php(390): Wikimedia\Rdbms\Database->delete(string, string, string)
#3 /srv/mediawiki/php-1.32.0-wmf.20/extensions/Wikibase/lib/includes/Store/Sql/TermSqlIndex.php(169): Wikibase\Lib\Store\Sql\TermSqlIndex->deleteTerms(Wikibase\DataModel\Entity\ItemId, array, Wikimedia\Rdbms\DatabaseMysqli)
#4 [internal function]: Wikibase\Lib\Store\Sql\TermSqlIndex->saveTermsOfEntity(Wikibase\DataModel\Entity\Item)
#5 /srv/mediawiki/php-1.32.0-wmf.20/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php(64): call_user_func_array(array, array)
#6 /srv/mediawiki/php-1.32.0-wmf.20/includes/deferred/DeferredUpdates.php(268): Wikibase\Repo\Content\DataUpdateAdapter->doUpdate()
#7 /srv/mediawiki/php-1.32.0-wmf.20/includes/deferred/DeferredUpdates.php(214): DeferredUpdates::runUpdate(Wikibase\Repo\Content\DataUpdateAdapter, Wikimedia\Rdbms\LBFactoryMulti, string, integer)
#8 /srv/mediawiki/php-1.32.0-wmf.20/includes/deferred/DeferredUpdates.php(134): DeferredUpdates::execute(array, string, integer)
#9 /srv/mediawiki/php-1.32.0-wmf.20/includes/MediaWiki.php(914): DeferredUpdates::doUpdates(string)
#10 /srv/mediawiki/php-1.32.0-wmf.20/includes/MediaWiki.php(734): MediaWiki->restInPeace(string, boolean)
#11 [internal function]: Closure$MediaWiki::doPostOutputShutdown()
#12 {main}

reqId: W5NWcgpAEMQAAD@Ex1wAAABP
wiki: www.wikidata.org
url: /w/api.php
Krinkle added a comment.EditedDec 21 2018, 5:25 AM

(Still seen on 1.33-wmf.8)

[XBoWRgpAIDQAAA4NtFoAAADI] /w/api.php   Wikimedia\Rdbms\DBTransactionError from line 1424 of /srv/mediawiki/php-1.33.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php: Wikibase\Repo\Content\DataUpdateAdapter::doUpdate: Commit failed on server(s) *: Cannot execute query from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate while transaction status is ERROR.

[XBGOngpAIDQAAEjKqpgAAABV] /w/api.php   Wikimedia\Rdbms\DBTransactionError from line 1424 of /srv/mediawiki/php-1.33.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php: Wikibase\Repo\Content\DataUpdateAdapter::doUpdate: Commit failed on server(s)  *: Cannot execute query from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate while transaction status is ERROR.

(Might be related to T147981)

Addshore added a subscriber: Addshore.EditedJan 14 2019, 5:33 PM

Has this stopped? Or has it moved? @hoo ?

addshore@mwlog1001:/srv/mw-log$ zgrep -cP 'TermSqlIndex::deleteTerms.*Deadlock' archive/hhvm.log-201901*
archive/hhvm.log-20190101.gz:0
archive/hhvm.log-20190102.gz:0
archive/hhvm.log-20190103.gz:0
archive/hhvm.log-20190104.gz:0
archive/hhvm.log-20190105.gz:0
archive/hhvm.log-20190106.gz:0
archive/hhvm.log-20190107.gz:0
archive/hhvm.log-20190108.gz:0
archive/hhvm.log-20190109.gz:0
archive/hhvm.log-20190110.gz:0
archive/hhvm.log-20190111.gz:0
archive/hhvm.log-20190112.gz:0
archive/hhvm.log-20190113.gz:0
archive/hhvm.log-20190114:0
addshore@mwlog1001:/srv/mw-log$ zgrep -cP 'TermSqlIndex::deleteTerms.*Deadlock' archive/hhvm.log-201812*
archive/hhvm.log-20181201.gz:0
archive/hhvm.log-20181202.gz:0
archive/hhvm.log-20181203.gz:0
archive/hhvm.log-20181204.gz:0
archive/hhvm.log-20181205.gz:0
archive/hhvm.log-20181206.gz:0
archive/hhvm.log-20181207.gz:0
archive/hhvm.log-20181208.gz:0
archive/hhvm.log-20181209.gz:0
archive/hhvm.log-20181210.gz:0
archive/hhvm.log-20181211.gz:0
archive/hhvm.log-20181212.gz:0
archive/hhvm.log-20181213.gz:0
archive/hhvm.log-20181214.gz:0
archive/hhvm.log-20181215.gz:0
archive/hhvm.log-20181216.gz:0
archive/hhvm.log-20181217.gz:0
archive/hhvm.log-20181218.gz:0
archive/hhvm.log-20181219.gz:0
archive/hhvm.log-20181220.gz:0
archive/hhvm.log-20181221.gz:0
archive/hhvm.log-20181222.gz:0
archive/hhvm.log-20181223.gz:0
archive/hhvm.log-20181224.gz:0
archive/hhvm.log-20181225.gz:0
archive/hhvm.log-20181226.gz:0
archive/hhvm.log-20181227.gz:0
archive/hhvm.log-20181228.gz:0
archive/hhvm.log-20181229.gz:0
archive/hhvm.log-20181230.gz:0
archive/hhvm.log-20181231.gz:0
hoo added a comment.Jan 14 2019, 7:08 PM

Still happening (very occasionally):

$ zgrep -c 'TermSqlIndex::deleteTerms' archive/exception.log-201901*
archive/exception.log-20190101.gz:0
archive/exception.log-20190102.gz:0
archive/exception.log-20190103.gz:2
archive/exception.log-20190104.gz:0
archive/exception.log-20190105.gz:0
archive/exception.log-20190106.gz:4
archive/exception.log-20190107.gz:1
archive/exception.log-20190108.gz:0
archive/exception.log-20190109.gz:2
archive/exception.log-20190110.gz:1
archive/exception.log-20190111.gz:0
archive/exception.log-20190112.gz:0
archive/exception.log-20190113.gz:0
archive/exception.log-20190114:0

Feb 2019, still happening occasionally:

addshore@mwlog1001:/srv/mw-log$ zgrep -c 'TermSqlIndex::deleteTerms' archive/exception.log-201902*
archive/exception.log-20190201.gz:0
archive/exception.log-20190202.gz:0
archive/exception.log-20190203.gz:6
archive/exception.log-20190204.gz:0
archive/exception.log-20190205.gz:0
archive/exception.log-20190206.gz:0
archive/exception.log-20190207.gz:1
archive/exception.log-20190208.gz:0
archive/exception.log-20190209.gz:0
archive/exception.log-20190210.gz:0
archive/exception.log-20190211.gz:1
archive/exception.log-20190212.gz:0
archive/exception.log-20190213.gz:0
archive/exception.log-20190214.gz:0
archive/exception.log-20190215.gz:0
archive/exception.log-20190216.gz:0
archive/exception.log-20190217.gz:1
archive/exception.log-20190218.gz:1
archive/exception.log-20190219.gz:2
archive/exception.log-20190220.gz:0
archive/exception.log-20190221.gz:0
archive/exception.log-20190222.gz:0
archive/exception.log-20190223.gz:0
archive/exception.log-20190224.gz:0
archive/exception.log-20190225.gz:0
archive/exception.log-20190226.gz:5
archive/exception.log-20190227.gz:2
archive/exception.log-20190228.gz:1

Very occasionally happening in June still:

addshore@mwlog1001:/srv/mw-log$ zgrep -c 'TermSqlIndex::deleteTerms' archive/exception.log-201906*
archive/exception.log-20190601.gz:0
archive/exception.log-20190602.gz:1
archive/exception.log-20190603.gz:0
archive/exception.log-20190604.gz:1
archive/exception.log-20190605.gz:0
archive/exception.log-20190606.gz:0
archive/exception.log-20190607.gz:0
archive/exception.log-20190608.gz:0
archive/exception.log-20190609.gz:0
archive/exception.log-20190610.gz:0
archive/exception.log-20190611.gz:0
archive/exception.log-20190612.gz:0
archive/exception.log-20190613.gz:0
archive/exception.log-20190614.gz:0
archive/exception.log-20190615.gz:0
archive/exception.log-20190616.gz:0
archive/exception.log-20190617.gz:1
archive/exception.log-20190618.gz:0
archive/exception.log-20190619.gz:0
archive/exception.log-20190620.gz:0
archive/exception.log-20190621.gz:0
archive/exception.log-20190622:0

Very soon we won't be using the wb_terms table any more

Addshore changed the task status from Open to Stalled.Jun 22 2019, 10:19 PM
mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:11 PM
Krinkle changed the task status from Stalled to Open.Oct 12 2019, 5:01 AM
Krinkle raised the priority of this task from Medium to Needs Triage.
Krinkle set Request URL to /w/api.php.
Krinkle set Request ID to XaFW6QpAEMYAALXzYP0AAACN.
Krinkle updated the task description. (Show Details)
Krinkle edited Stack Trace. (Show Details)
Krinkle added a project: Wikidata-Campsite.
Krinkle added subscribers: mmodell, Michael, alaa_wmde.
Krinkle moved this task from Old to Oct2019/1.35.wmf.1+ on the Wikimedia-production-error board.EditedOct 12 2019, 5:03 AM

Seems to have come back, now happening a few hundred times a day as of 1.34.0-wmf.24.

Ladsgroup added a subscriber: Ladsgroup.

Seems to have come back, now happening a few hundred times a day as of 1.34.0-wmf.24.

No, this ticket is about the old term store. The errors you have been seeing is about the new term store which is tracked in T234948: New Wikibase deadlocks on Wikidata wiki since 2019-10-08T00:00:02: Wikibase\Lib\Store\Sql\Terms\{closure} Deadlock found when trying to get lock; try restarting transaction

Seen 3,500 times (evenly spread out throughout the month).

Logstash: https://logstash.wikimedia.org/goto/f12480d76fe5fa011e52110a94927d3e.

@Ladsgroup I don't know if is the same issue or not. It does have the same stack trace from DataUpdateAdapter::doUpdate line 62, same as in this task's description with a similar error message afaik.

message
PHP Warning: [data-update-failed]: A data update callback triggered an exception (Fail-safe exception. Number of ids to be restored is not equal to the number of records that are about to be inserted into master. This should never happen, except for an edge-case that was not detected during development or due to a race-condition that is not covered by this implementation.)
[Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 62]
exception.trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.35.0-wmf.10/includes/debug/MWDebug.php(333): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.35.0-wmf.10/includes/debug/MWDebug.php(188): MWDebug::sendMessage(string, array, string, integer)
#3 /srv/mediawiki/php-1.35.0-wmf.10/includes/GlobalFunctions.php(1079): MWDebug::warning(string, integer, integer, string)
#4 /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/lib/includes/Reporting/LogWarningExceptionHandler.php(28): wfLogWarning(string, integer)
#5 /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php(62): Wikibase\Lib\Reporting\LogWarningExceptionHandler->handleException(Exception, string, string)
#6 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(416): Wikibase\Repo\Content\DataUpdateAdapter->doUpdate()
#7 /srv/mediawiki/php-1.35.0-wmf.10/includes/Storage/DerivedPageDataUpdater.php(1634): DeferredUpdates::attemptUpdate(Wikibase\Repo\Content\DataUpdateAdapter, Wikimedia\Rdbms\LBFactoryMulti)
#8 /srv/mediawiki/php-1.35.0-wmf.10/includes/Storage/DerivedPageDataUpdater.php(1446): MediaWiki\Storage\DerivedPageDataUpdater->doSecondaryDataUpdates(array)
#9 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/MWCallableUpdate.php(38): MediaWiki\Storage\DerivedPageDataUpdater->MediaWiki\Storage\{closure}()
#10 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(416): MWCallableUpdate->doUpdate()
#11 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(296): DeferredUpdates::attemptUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#12 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(233): DeferredUpdates::run(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti, Monolog\Logger, BufferingStatsdDataFactory, string)
#13 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(150): DeferredUpdates::handleUpdateQueue(array, string, integer)
#14 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(1053): DeferredUpdates::doUpdates(string)
#15 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(833): MediaWiki->restInPeace()
#16 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(842): MediaWiki->{closure}()
#17 /srv/mediawiki/php-1.35.0-wmf.10/api.php(113): MediaWiki->doPostOutputShutdown()
#18 /srv/mediawiki/w/api.php

If this is separate, feel free to create a new task :)

Seen 3,500 times (evenly spread out throughout the month).

Yup, we are still writing to the old store (and we will for probably long time still...)

Logstash: https://logstash.wikimedia.org/goto/f12480d76fe5fa011e52110a94927d3e.

@Ladsgroup I don't know if is the same issue or not. It does have the same stack trace from DataUpdateAdapter::doUpdate line 62, same as in this task's description with a similar error message afaik.

message
PHP Warning: [data-update-failed]: A data update callback triggered an exception (Fail-safe exception. Number of ids to be restored is not equal to the number of records that are about to be inserted into master. This should never happen, except for an edge-case that was not detected during development or due to a race-condition that is not covered by this implementation.)
[Called from Wikibase\Repo\Content\DataUpdateAdapter::doUpdate in /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php at line 62]
exception.trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.35.0-wmf.10/includes/debug/MWDebug.php(333): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.35.0-wmf.10/includes/debug/MWDebug.php(188): MWDebug::sendMessage(string, array, string, integer)
#3 /srv/mediawiki/php-1.35.0-wmf.10/includes/GlobalFunctions.php(1079): MWDebug::warning(string, integer, integer, string)
#4 /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/lib/includes/Reporting/LogWarningExceptionHandler.php(28): wfLogWarning(string, integer)
#5 /srv/mediawiki/php-1.35.0-wmf.10/extensions/Wikibase/repo/includes/Content/DataUpdateAdapter.php(62): Wikibase\Lib\Reporting\LogWarningExceptionHandler->handleException(Exception, string, string)
#6 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(416): Wikibase\Repo\Content\DataUpdateAdapter->doUpdate()
#7 /srv/mediawiki/php-1.35.0-wmf.10/includes/Storage/DerivedPageDataUpdater.php(1634): DeferredUpdates::attemptUpdate(Wikibase\Repo\Content\DataUpdateAdapter, Wikimedia\Rdbms\LBFactoryMulti)
#8 /srv/mediawiki/php-1.35.0-wmf.10/includes/Storage/DerivedPageDataUpdater.php(1446): MediaWiki\Storage\DerivedPageDataUpdater->doSecondaryDataUpdates(array)
#9 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/MWCallableUpdate.php(38): MediaWiki\Storage\DerivedPageDataUpdater->MediaWiki\Storage\{closure}()
#10 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(416): MWCallableUpdate->doUpdate()
#11 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(296): DeferredUpdates::attemptUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#12 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(233): DeferredUpdates::run(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti, Monolog\Logger, BufferingStatsdDataFactory, string)
#13 /srv/mediawiki/php-1.35.0-wmf.10/includes/deferred/DeferredUpdates.php(150): DeferredUpdates::handleUpdateQueue(array, string, integer)
#14 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(1053): DeferredUpdates::doUpdates(string)
#15 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(833): MediaWiki->restInPeace()
#16 /srv/mediawiki/php-1.35.0-wmf.10/includes/MediaWiki.php(842): MediaWiki->{closure}()
#17 /srv/mediawiki/php-1.35.0-wmf.10/api.php(113): MediaWiki->doPostOutputShutdown()
#18 /srv/mediawiki/w/api.php

If this is separate, feel free to create a new task :)

This is T233414: Merge triggered warning about unequal numbers of ids to be restored and records to be inserted into master. We are on it:

Macro catbowtie:

This will likely end up being helped greatly by T244115: Investigate & Fix holes for aliases in new term tables (take 3), the bulk of which will be going out with .21

When the transaction splitting and job gets deployed we will likely and should see a drop in deadlock issues.

We should be able to observe this @ https://logstash.wikimedia.org/goto/956ac31f9e47b1a4a579e4f39c300b2f

This will likely end up being helped greatly by T244115: Investigate & Fix holes for aliases in new term tables (take 3), the bulk of which will be going out with .21

When the transaction splitting and job gets deployed we will likely and should see a drop in deadlock issues.

We should be able to observe this @ https://logstash.wikimedia.org/goto/956ac31f9e47b1a4a579e4f39c300b2f

yeah but OTOH, this is going to go away (the ticket is about the old term store)

Removing from the campsite, and we will close this ticket when the old term store is gone!

Krinkle removed a subscriber: Krinkle.Mar 9 2020, 9:58 PM
Addshore closed this task as Resolved.Mar 23 2020, 9:18 AM
Addshore claimed this task.

We are no longer writing to this table

Restricted Application added a project: User-Addshore. · View Herald TranscriptMar 23 2020, 9:18 AM