Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages Deadlock
Open, LowPublicPRODUCTION ERROR
Actions

Assigned To

None

Authored By

	thcipriani
	Jun 17 2020, 6:49 PM

Description

Error message

Function: Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages
Error: 1213 Deadlock found when trying to get lock; try restarting transaction

Stack Trace

	#0 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1663): Wikimedia\Rdbms\Database->getQueryException(string, integer, string, string)
#1 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1640): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#2 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1215): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#3 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(2319): Wikimedia\Rdbms\Database->query(string, string, integer)
#4 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(2281): Wikimedia\Rdbms\Database->doInsertNonConflicting(string, array, string)
#5 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Usage/Sql/EntityUsageTable.php(189): Wikimedia\Rdbms\Database->insert(string, array, string, array)
#6 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Usage/Sql/SqlUsageTracker.php(184): Wikibase\Client\Usage\Sql\EntityUsageTable->addUsages(integer, array)
#7 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Store/UsageUpdater.php(82): Wikibase\Client\Usage\Sql\SqlUsageTracker->addUsedEntities(integer, array)
#8 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Store/AddUsagesForPageJob.php(122): Wikibase\Client\Store\UsageUpdater->addUsagesForPage(integer, array)
#9 /srv/mediawiki/php-1.35.0-wmf.37/extensions/EventBus/includes/JobExecutor.php(79): Wikibase\Client\Store\AddUsagesForPageJob->run()
#10 /srv/mediawiki/rpc/RunSingleJob.php(76): MediaWiki\Extension\EventBus\JobExecutor->execute(array)
#11 {main}

Impact

1. Notes
Happening intermittently with low frequency.

Details

Request ID: a95f3d48-2165-4e0f-8060-013b24f55b47
Request URL: /rpc/RunSingleJob.php

Stack Trace

#0 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1663): Wikimedia\Rdbms\Database->getQueryException(string, integer, string, string)
#1 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1640): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#2 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1215): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#3 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(2319): Wikimedia\Rdbms\Database->query(string, string, integer)
#4 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(2281): Wikimedia\Rdbms\Database->doInsertNonConflicting(string, array, string)
#5 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Usage/Sql/EntityUsageTable.php(189): Wikimedia\Rdbms\Database->insert(string, array, string, array)
#6 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Usage/Sql/SqlUsageTracker.php(184): Wikibase\Client\Usage\Sql\EntityUsageTable->addUsages(integer, array)
#7 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Store/UsageUpdater.php(82): Wikibase\Client\Usage\Sql\SqlUsageTracker->addUsedEntities(integer, array)
#8 /srv/mediawiki/php-1.35.0-wmf.37/extensions/Wikibase/client/includes/Store/AddUsagesForPageJob.php(122): Wikibase\Client\Store\UsageUpdater->addUsagesForPage(integer, array)
#9 /srv/mediawiki/php-1.35.0-wmf.37/extensions/EventBus/includes/JobExecutor.php(79): Wikibase\Client\Store\AddUsagesForPageJob->run()
#10 /srv/mediawiki/rpc/RunSingleJob.php(76): MediaWiki\Extension\EventBus\JobExecutor->execute(array)
#11 {main}

Related Objects

Mentioned In: Blog Post: Production Excellence #39: December 2021
Blog Post: Production Excellence #22: June 2020
Mentioned Here: T253026: Introduce a centralized Dependency Tracking Service

Event Timeline

thcipriani created this task.Jun 17 2020, 6:49 PM

Restricted Application added a project: Platform Engineering. · View Herald TranscriptJun 17 2020, 6:49 PM

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

• Addshore added a project: Wikidata.Jun 17 2020, 7:06 PM

• Addshore added a subscriber: • Addshore.

• Michael added a subscriber: • Michael.Jun 18 2020, 3:52 PM

We think this is interesting for RDBMS reasons; @aaron might be interested to look at this while on Clinic Duty. @Addshore are you working on this directly?

• eprodromou moved this task from Inbox to Later on the Platform Team Workboards (Clinic Duty Team) board.Jun 18 2020, 7:08 PM

This is related to Rdbms in the same way that it relates to PHP and MediaWiki. It uses it, but it's not where the problem is.

Still seen in current production.

Krinkle mentioned this in Blog Post: Production Excellence #22: June 2020.Jul 23 2020, 3:25 AM

• Addshore merged a task: T260277: UsageTrackerException: Sql/SqlUsageTracker.php: Error 1213: Function: Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages Deadlock found when trying to get lock; try restarting transaction.Aug 12 2020, 9:43 PM

T253026: Introduce a centralized Dependency Tracking Service would help here

Ladsgroup added a subscriber: Ladsgroup.Feb 8 2021, 10:44 AM

Restricted Application added a project: wdwb-tech. · View Herald TranscriptFeb 8 2021, 10:44 AM

It it using batches for the insert and doing INSERT IGNORE, after that it waits for replica with domain to the local wiki id.

The current wmf config seems wmgWikibaseClientAddEntityUsagesBatchSize with 100, the hard coded default is 500 in case the config is not passed deep enough.

Not sure what the best way is to fix this. Using replace instead? It is running as part of a job

• Addshore moved this task from Inbox to Legacy Inbox on the wdwb-tech board.Mar 17 2021, 5:19 PM

• Addshore moved this task from Legacy Inbox to Research on the wdwb-tech board.Apr 20 2021, 7:18 AM

• Addshore removed a project: Wikidata-Campsite.Apr 22 2021, 4:04 PM

Still seen on various wikipedias, in the past week, such as:

reqId: 25a14a4b-aa85-460a-9aa2-3ddb686f1fda
wiki: zhwiki

[{reqId}] {exception_url} Wikimedia\Rdbms\DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transaction (db2107) Function: Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages Query: INSERT IGNORE INTO `wbc_entity_usage`

• Addshore moved this task from Research to Investigate & Discuss on the wdwb-tech board.Jul 16 2021, 8:38 AM

Krinkle removed a project: MediaWiki-libs-Rdbms.Oct 16 2021, 1:36 AM

Umherirrender removed a subscriber: Umherirrender.Nov 24 2021, 8:04 PM

Krinkle mentioned this in Blog Post: Production Excellence #39: December 2021.Jan 17 2022, 10:16 PM

Krinkle moved this task from Jun 2020 to Older on the Wikimedia-production-error board.Feb 4 2022, 1:07 AM

From what I'm seeing, it seems it tries to do the exact same insert back to back. Maybe it needs de-duplication logic:

2022-08-08 14:15:01 *redacted*
*** (1) TRANSACTION:
TRANSACTION *redacted*, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1
MySQL thread id *redacted*, OS thread handle *redacted*, query id *redacted* 10.64.0.169 wikiuser202206 Update
INSERT /* Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages  */ IGNORE INTO `wbc_entity_usage` (eu_page_id,eu_aspect,eu_entity_id) VALUES (783633,'C.P227','Q760690'),(783633,'C.P244','Q760690'),(783>
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id *redacted* page no *redacted* n bits *redacted* index eu_entity_id of table `eowiki`.`wbc_entity_usage` trx id *redacted* lock mode S waiting
Record lock, heap no 495 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
*redacted*

*** (2) TRANSACTION:
TRANSACTION 160726462551, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 3
MySQL thread id 1736043481, OS thread handle *redacted*, query id *redacted* 10.64.32.38 wikiuser202206 Update
INSERT /* Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages  */ IGNORE INTO `wbc_entity_usage` (eu_page_id,eu_aspect,eu_entity_id) VALUES (783633,'C.P227','Q760690'),(783633,'C.P244','Q760690'),(783>
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id *redacted* page no *redacted* n bits *redacted* index eu_entity_id of table `eowiki`.`wbc_entity_usage` trx id *redacted* lock_mode X locks rec but not gap
Record lock, heap no 495 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
*redacted*

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id *redacted* page no *redacted* n bits *redacted* index eu_entity_id of table `eowiki`.`wbc_entity_usage` trx id *redacted* lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 495 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
*redacted*

*** WE ROLL BACK TRANSACTION (1)

Wikibase\Client\Usage\Sql\EntityUsageTable::addUsages DeadlockOpen, LowPublicPRODUCTION ERRORActions