ContentTranslation\TranslationStorageManager::saveQuery: Deadlock found when trying to get lock; try restarting transaction
Open, MediumPublic
Actions

Assigned To

None

Authored By

	KartikMistry
	Jun 24 2020, 11:09 AM

Description

This error is frequently seen in ContentTranslation log at logstash/kibana:

Wiki: php-1.35.0-wmf.37
Referrer (for this example): https://es.wikipedia.org/w/index.php?title=Especial:Traducci%C3%B3n_de_contenidos&page=International+Science+Council&from=en&to=es&targettitle=Consejo+Cient%C3%ADfico+Internacional
Impact: Some parts of translation drafts are not getting saved (but retry mechanism should take care of that)

Log

ContentTranslation\TranslationStorageManager::save	10.64.32.11	1213	Deadlock found when trying to get lock; try restarting transaction (10.64.32.11)	SELECT  *  FROM `cx_corpora`    WHERE cxc_translation_id = 958734 AND cxc_section_id = '16' AND cxc_origin = 'user'  ORDER BY cxc_timestamp DESC LIMIT 1   FOR UPDATE

#0 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1640): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#1 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1215): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#2 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1879): Wikimedia\Rdbms\Database->query(string, string, integer)
#3 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(1975): Wikimedia\Rdbms\Database->select(string, string, array, string, array, array)
#4 /srv/mediawiki/php-1.35.0-wmf.37/extensions/ContentTranslation/includes/TranslationStorageManager.php(160): Wikimedia\Rdbms\Database->selectRow(string, string, array, string, array)
#5 /srv/mediawiki/php-1.35.0-wmf.37/extensions/ContentTranslation/includes/TranslationStorageManager.php(145): ContentTranslation\TranslationStorageManager::doFind(Wikimedia\Rdbms\DatabaseMysqli, array, array, string)
#6 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/Database.php(4264): ContentTranslation\TranslationStorageManager::ContentTranslation\{closure}(Wikimedia\Rdbms\DatabaseMysqli, string)
#7 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/DBConnRef.php(68): Wikimedia\Rdbms\Database->doAtomicSection(string, Closure)
#8 /srv/mediawiki/php-1.35.0-wmf.37/includes/libs/rdbms/database/DBConnRef.php(641): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#9 /srv/mediawiki/php-1.35.0-wmf.37/extensions/ContentTranslation/includes/TranslationStorageManager.php(153): Wikimedia\Rdbms\DBConnRef->doAtomicSection(string, Closure)
#10 /srv/mediawiki/php-1.35.0-wmf.37/extensions/ContentTranslation/api/ApiContentTranslationSave.php(225): ContentTranslation\TranslationStorageManager::save(ContentTranslation\TranslationUnit, boolean)
#11 /srv/mediawiki/php-1.35.0-wmf.37/extensions/ContentTranslation/api/ApiContentTranslationSave.php(72): ApiContentTranslationSave->saveTranslationUnits(array, ContentTranslation\Translation)
#12 /srv/mediawiki/php-1.35.0-wmf.37/includes/api/ApiMain.php(1585): ApiContentTranslationSave->execute()
#13 /srv/mediawiki/php-1.35.0-wmf.37/includes/api/ApiMain.php(525): ApiMain->executeAction()
#14 /srv/mediawiki/php-1.35.0-wmf.37/includes/api/ApiMain.php(496): ApiMain->executeActionWithErrorHandling()
#15 /srv/mediawiki/php-1.35.0-wmf.37/api.php(84): ApiMain->execute()
#16 /srv/mediawiki/w/api.php(3): require(string)
#17 {main}

Details

	Subject	Repo	Branch	Lines +/-
	TranslationCorporaStore: Avoid unnecessary lock when record does not exist	mediawiki/extensions/ContentTranslation	master	+37 -32

Customize query in gerrit

Related Objects

Mentioned In: T348235: Deadlock in SqlBagOStuff::modifyTableSpecificBlobsForSet
T312605: Duplicate entry for key 'cx_translation_ref' in ContentTranslation\Translation::createQuery
T306640: DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transaction ([db])Function: ContentTranslation\TranslationStorageManager::saveQuery
Mentioned Here: T321469: Wikimedia\Rdbms\DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transactionFunction: ContentTranslation\Store\TranslationCorporaStore::saveQuery: SELECT cxc_translation_id,cxc_section_id,cxc_

Event Timeline

KartikMistry created this task.Jun 24 2020, 11:09 AM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 24 2020, 11:09 AM

This has approximately 10 occurrences in last 7 days.

• mmodell moved this task from Untriaged to Jul 2020 on the Wikimedia-production-error board.Jul 1 2020, 6:49 PM

• mmodell merged a task: T256899: Error 1213: Deadlock found when trying to get lock; Function: ContentTranslation\TranslationStorageManager::createQuery.

• mmodell subscribed.

Arrbee moved this task from Needs Triage to Check & Move on the ContentTranslation board.Aug 17 2020, 12:13 PM

Nikerabbit triaged this task as Medium priority.Sep 28 2020, 2:51 PM

Nikerabbit updated the task description. (Show Details)

Krinkle moved this task from Jul 2020 to Older on the Wikimedia-production-error board.Mar 7 2022, 8:14 PM

Nikerabbit renamed this task from ContentTranslation: Deadlock found when trying to get lock; try restarting transaction (10.64.32.11) to ContentTranslation\TranslationStorageManager::saveQuery: Deadlock found when trying to get lock; try restarting transaction.May 11 2022, 2:03 PM

Nikerabbit mentioned this in T306640: DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transaction ([db])Function: ContentTranslation\TranslationStorageManager::saveQuery.

Nikerabbit merged a task: T306640: DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transaction ([db])Function: ContentTranslation\TranslationStorageManager::saveQuery.

Nikerabbit moved this task from Check & Move to Bugs on the ContentTranslation board.

Nikerabbit added subscribers: brennen, ngkountas.

Krinkle mentioned this in T312605: Duplicate entry for key 'cx_translation_ref' in ContentTranslation\Translation::createQuery.Jul 7 2022, 11:01 PM

This has been going up a lot recently and it seems it's a logical issue (a bug in the code). There are two competing threads holding locks for the blocks the other from moving. I looked at x1 master to get more details and here we are:

2022-08-09 *redacted* *redacted*
*** (1) TRANSACTION:
TRANSACTION *redacted*, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id *redacted*, OS thread handle *redacted*, query id *redacted* 10.64.0.158 wikiuser202206 Sending data
SELECT /* ContentTranslation\Store\TranslationCorporaStore::save  */  *  FROM `cx_corpora`    WHERE cxc_translation_id = 1534421 AND cxc_section_id = '3' AND cxc_origin = 'user'  ORDER BY cxc_timestamp >
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id *redacted* page no *redacted* n bits 440 index cx_corpora_unique of table `wikishared`.`cx_corpora` trx id *redacted* lock_mode X waiting
Record lock, heap no 40 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
*redacted*
*** (2) TRANSACTION:
TRANSACTION *redacted*, ACTIVE 0 sec updating or deleting
mysql tables in use 1, locked 1
5 lock struct(s), heap size 1128, 4 row lock(s), undo log entries 1
MySQL thread id *redacted*, OS thread handle *redacted*, query id *redacted* 10.64.48.204 wikiuser202206 Updating
UPDATE /* ContentTranslation\Store\TranslationCorporaStore::updateTranslationUnit  */  `cx_corpora` SET cxc_sequence_id = NULL,cxc_timestamp = '20220809140101',cxc_content = '<section rel=\"cx:Section\">
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id *redacted* page no *redacted* n bits 440 index cx_corpora_unique of table `wikishared`.`cx_corpora` trx id *redacted* lock_mode X
Record lock, heap no 40 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
 *redacted*

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id *redacted* page no *redacted* n bits 440 index cx_corpora_unique of table `wikishared`.`cx_corpora` trx id *redacted* lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 41 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
*redacted*
*** WE ROLL BACK TRANSACTION (1)

HTH debugging it.

Error

mwversion: 1.39.0-wmf.26
reqId: e966db00-3b7e-4a62-ad6d-2a0961db8968
Find reqId in Logstash

normalized_message

[{reqId}] {exception_url}   Wikimedia\Rdbms\DBQueryError: Error 1213: Deadlock found when trying to get lock; try restarting transaction
Function: ContentTranslation\Store\TranslationCorporaStore::save
Query: SELECT  *  FROM `cx_corpora`    WHERE cxc_tran

exception.trace

from /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1742)
#0 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1726): Wikimedia\Rdbms\Database->getQueryException(string, integer, string, string)
#1 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1700): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#2 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1076): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#3 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1832): Wikimedia\Rdbms\Database->query(string, string, integer)
#4 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(1841): Wikimedia\Rdbms\Database->select(string, string, array, string, array, array)
#5 /srv/mediawiki/php-1.39.0-wmf.26/extensions/ContentTranslation/includes/Store/TranslationCorporaStore.php(210): Wikimedia\Rdbms\Database->selectRow(string, string, array, string, array)
#6 /srv/mediawiki/php-1.39.0-wmf.26/extensions/ContentTranslation/includes/Store/TranslationCorporaStore.php(163): ContentTranslation\Store\TranslationCorporaStore->doFind(Wikimedia\Rdbms\DatabaseMysqli, array, array, string)
#7 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/Database.php(2874): ContentTranslation\Store\TranslationCorporaStore->ContentTranslation\Store\{closure}(Wikimedia\Rdbms\DatabaseMysqli, string)
#8 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/DBConnRef.php(103): Wikimedia\Rdbms\Database->doAtomicSection(string, Closure)
#9 /srv/mediawiki/php-1.39.0-wmf.26/includes/libs/rdbms/database/DBConnRef.php(663): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#10 /srv/mediawiki/php-1.39.0-wmf.26/extensions/ContentTranslation/includes/Store/TranslationCorporaStore.php(171): Wikimedia\Rdbms\DBConnRef->doAtomicSection(string, Closure)
#11 /srv/mediawiki/php-1.39.0-wmf.26/extensions/ContentTranslation/includes/ActionApi/ApiContentTranslationSave.php(188): ContentTranslation\Store\TranslationCorporaStore->save(ContentTranslation\TranslationUnit, boolean)
#12 /srv/mediawiki/php-1.39.0-wmf.26/extensions/ContentTranslation/includes/ActionApi/ApiContentTranslationSave.php(116): ContentTranslation\ActionApi\ApiContentTranslationSave->saveTranslationUnits(array, ContentTranslation\Translation)
#13 /srv/mediawiki/php-1.39.0-wmf.26/includes/api/ApiMain.php(1900): ContentTranslation\ActionApi\ApiContentTranslationSave->execute()
#14 /srv/mediawiki/php-1.39.0-wmf.26/includes/api/ApiMain.php(875): ApiMain->executeAction()
#15 /srv/mediawiki/php-1.39.0-wmf.26/includes/api/ApiMain.php(846): ApiMain->executeActionWithErrorHandling()
#16 /srv/mediawiki/php-1.39.0-wmf.26/api.php(90): ApiMain->execute()
#17 /srv/mediawiki/php-1.39.0-wmf.26/api.php(45): wfApiMain()
#18 /srv/mediawiki/w/api.php(3): require(string)
#19 {main}

Notes

Unrelated, but I do note that it is suspicious to have a wildcard SELECT query in production code. That is unlikely to be the cause of the deadlock, but it is certainly making it harder to pin down and find potential fields that can cause locks or more generally know what is being used.

This issue was supposed to be fixed in 2016 when Aaron Schulz debugged and fixed in https://gerrit.wikimedia.org/r/c/mediawiki/extensions/ContentTranslation/+/305004. Curious to see it resurface again.
The relevant code is at https://github.com/wikimedia/mediawiki-extensions-ContentTranslation/blob/master/includes/Store/TranslationCorporaStore.php#L134 which is basically a insert or update logic block. The doFind method in that class is doing a SELECT * .. FOR UPDATE for finding if a translation unit exist or not.
@Ladsgroup Do you see any wrong patterns there? As per Timo's observation, I just submitted a patch to avoid wildcard select.

I think it's gap locking, it shows in the deadlock record as well. My suggestion to avoid such cases is to first try replica then try master with "for update", that at least drastically reduces the chance of it from happening. I generally suggest not grabbing a lock for existence because if it doesn't, it locks the whole gap, not the record. You can probably use insert ignore (or upsert depending on your usecase) instead.

Change 833331 had a related patch set uploaded (by Santhosh; author: Santhosh):

[mediawiki/extensions/ContentTranslation@master] TranslationCorporaStore: Avoid unnecessary lock when record does not exist

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

gerritbot added a project: Patch-For-Review.Sep 20 2022, 10:05 AM

Change 833331 merged by jenkins-bot:

[mediawiki/extensions/ContentTranslation@master] TranslationCorporaStore: Avoid unnecessary lock when record does not exist

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

Maintenance_bot removed a project: Patch-For-Review.Sep 27 2022, 11:30 AM

ReleaseTaggerBot added a project: MW-1.40-notes (1.40.0-wmf.4; 2022-10-03).Sep 27 2022, 12:00 PM

I had duplicate T321469 filed cause the class got renamed at some point. It had: