Unable to delete file pages on commons: MWException/LocalFileLockError: "Could not acquire lock"
Open, HighPublic
Actions

Assigned To

None

Authored By

	Steinsplitter
	Apr 18 2016, 3:14 PM

Description

Unable to delete pages on commons:

April 4:

https://commons.wikimedia.org/w/index.php?title=File:Cruz_guitarra.png
- [eb9591c9b973a89dfb23bc29] 2016-04-04 16:48:07: Fatal exception of type "MWException"

April 18:

https://commons.wikimedia.org/w/index.php?title=File:ASCEMCOL-FECOER.jpg
- [VxT5JgpAEEoAAGuO-XUAAABC] 2016-04-18 15:11:40: Fatal exception of type "MWException"

https://commons.wikimedia.org/w/index.php?title=File:Reconocimiento_Dr._Gomez.jpg
- [VxT5YwpAIDYAAHCdIAMAAABI] 2016-04-18 15:12:41: Fatal exception of type "MWException"

https://commons.wikimedia.org/w/index.php?title=File:Bodas_de_Plata_ASCEMCOL.jpg
- [VxT5igpAEK0AAHmhz7cAAAAA] 2016-04-18 15:13:20: Fatal exception of type "MWException"

https://commons.wikimedia.org/w/index.php?title=File:Nagarjuna_at_an_event.jpg
- [VxT6xQpAEFUAAHDo53wAAABE] 2016-04-18 15:18:36: Fatal exception of type "MWException"

May 7:

https://commons.wikimedia.org/wiki/File:(1)_Piano_Recital_at_12.jpg
- Exception encountered, of type "LocalFileLockError"
- [Vy45gApAMCEAAGZ5po8AAAAR] Exception Caught: Could not acquire lock for '(1)_Piano_Recital_at_12.jpg.'

Details

Subject	Repo	Branch	Lines +/-
Fixes to LocalFile::lock()	mediawiki/core	master	+91 -20
Increase redisLockManager read timeout from 1 to 2 seconds	operations/mediawiki-config	master	+1 -0
Use a log group for LocalFile lock errors	mediawiki/core	master	+10 -2
Use a log group for LocalFile lock errors	mediawiki/core	wmf/1.28.0-wmf.8	+10 -2
Make LocalFileLockError an error page exception	mediawiki/core	master	+13 -7
Increase LocalFile lock() timeout and improve error message	mediawiki/core	master	+5 -2
Remove upgradeRow() call from ?action=purge	mediawiki/core	master	+4 -4
Avoid lock error exceptions during upgradeRow() contention	mediawiki/core	master	+26 -11

Customize query in gerrit

Related Objects

Mentioned In: T45331: Do not refresh file metadata for huge files on purge, and especially do not do it well holding database locks
T275072: LocalFileLockError: Could not acquire lock for "mwstore: …" (via ApiUpload.php)
T141704: Unable to delete certain files due to "inconsistent state within the internal storage backends"
T147986: [BUG] rise in Could not acquire lock for "mwstore://local-multiwrite/local-public/NAME_OF_FILE
T32961: Run refreshImageMetadata.php --force
T139873: Can't delete en:File:Testing_protection_level_reset_on_delete_and_restore.png
T135117: Deletion error at Wikimedia Commons: LocalFileLockError
T129621: "internal_api_error_MWException: [dbf916b7] Exception Caught: Could not acquire lock for" for some uploads (during upload with Pywikibot OAuth)
T130359: API request failed (internal_api_error_MWException): [408e8b0f] Exception Caught: Could not acquire lock for 'Full_size_20150703094950ನಿಲ್ಲದ_ಬರವಣಿಗೆ.jpg.'
T131769: Cannot delete page
Mentioned Here: T141704: Unable to delete certain files due to "inconsistent state within the internal storage backends"
T135485: [Bug] File deletion problem on commons.wikimedia.org
T131769: Cannot delete page

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes

https://commons.wikimedia.org/w/index.php?title=File:2_Kenny_Oude_kleedkamerd.png&action=delete
Exception encountered, of type "LocalFileLockError"

I wanted to discard data drift between servers (an issue I found before), I think I did:

$ mysql -BN -A -h db1040 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -
$ mysql -BN -A -h db1042 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -
$ mysql -BN -A -h db1056 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -
$ mysql -BN -A -h db1059 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -
$ mysql -BN -A -h db1064 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -
$ mysql -BN -A -h db1068 commonswiki -e "SELECT * FROM page where page_namespace=6 AND page_title='(1)_Piano_Recital_at_12.jpg';SELECT * FROM revision WHERE rev_page=48412604;SELECT * FROM image WHERE img_name='(1)_Piano_Recital_at_12.jpg'" | md5sum
ae9297a9b9c1ca94733ccdb1a90ecd06  -

From the infrastructure point of view, it looks as if the file was actually successful deleted, but the database wasn't updated to reflect this. I will leave the why to the mediawiki people, and offer help when/if database needs to be updated to reflect this fact.

https://commons.wikimedia.org/wiki/File:Jfdg_hfhu_pprsdrsd_gegjg.webm Exception encountered, of type "LocalFileLockError"

Upping priority, we need to be able to delete copyright violations.

Restricted Application added subscribers: Luke081515, Urbanecm. · View Herald TranscriptMay 9 2016, 8:42 AM

Poyekhali awarded a token.May 9 2016, 8:43 AM

Sjoerddebruin subscribed.May 9 2016, 8:58 AM

In T132921#2274679, @Riley_Huntley wrote:

https://commons.wikimedia.org/wiki/File:Jfdg_hfhu_pprsdrsd_gegjg.webm Exception encountered, of type "LocalFileLockError"

Upping priority, we need to be able to delete copyright violations.

You still should be able, if I understand correctly. (The file you linked seems to be gone.)

In T132921#2274551, @jcrespo wrote:

From the infrastructure point of view, it looks as if the file was actually successful deleted, but the database wasn't updated to reflect this. I will leave the why to the mediawiki people, and offer help when/if database needs to be updated to reflect this fact.

All those files seem to have been deleted now, also on the database.

A database query error has occurred. This may indicate a bug in the software.

Function: WikiPage::lockAndGetLatest
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.16.31)

While deleting

@Riley_Huntley Were you shown an exception identifier like 'VxT6xQpAEFUAAHDo53wAAABE'? It allows developers to view error details in the logs, which is often very helpful. Judging by just the message you pasted, that looks like a different issue, but it's hard to tell.

ReleaseTaggerBot added projects: MW-1.28-release (WMF-deploy-2016-05-10_(1.28.0-wmf.1)), MW-1.28-release-notes.May 10 2016, 1:11 PM

I had the same issue with https://commons.wikimedia.org/wiki/File:Chinese_women_volleyball.jpg
but now deleted.

Change 288535 had a related patch set uploaded (by Aaron Schulz):
Increase LocalFile lock() timeout and improve error message

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

gerritbot added a project: Patch-For-Review.May 12 2016, 10:53 PM

Aklapper merged a task: T135117: Deletion error at Wikimedia Commons: LocalFileLockError.May 15 2016, 12:20 PM

Aklapper mentioned this in T135117: Deletion error at Wikimedia Commons: LocalFileLockError.

Aklapper added a subscriber: AFBorchert.

I got this error (that is, white page with black Courier text: Exception encountered, of type "LocalFileLockError") repeatedly with https://commons.wikimedia.org/wiki/File:Amateur_Gardening_July_2015_(20138255285)_(2).jpg
I attempted to delete it several times but when it finally went through, I had attempted to delete it manually (via the delete tab) rather than through the trashcan icon provided by the DelReqHandler gadget. Not sure if what made a difference was either time or the different technique.

Change 288535 merged by jenkins-bot:
Increase LocalFile lock() timeout and improve error message

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

ReleaseTaggerBot added a project: MW-1.28-release (WMF-deploy-2016-05-17_(1.28.0-wmf.2)).May 17 2016, 10:00 AM

API request failed (internal_api_error_LocalFileLockError): [VzrtXgpAID8AACKElzUAAAAH] Exception Caught: Could not acquire lock for 'Assad_Khan_3.jpg.'
API request failed (internal_api_error_LocalFileLockError): [VzrtXQpAMCMAACPeIVAAAABP] Exception Caught: Could not acquire lock for 'Assad_Khan.jpg.'
API request failed (internal_api_error_LocalFileLockError): [VzrtXQpAMCQAACe8kCIAAAAH] Exception Caught: Could not acquire lock for 'Assad_Khan_work.jpg.'
API request failed (internal_api_error_LocalFileLockError): [VzrtWApAEHEAAA6cY5wAAAAN] Exception Caught: Could not acquire lock for 'Assad_Khan_2.jpg.'

TerraCodes removed projects: MW-1.28-release (WMF-deploy-2016-05-17_(1.28.0-wmf.2)), Patch-For-Review.May 17 2016, 4:02 PM

TerraCodes added a project: MW-1.28-release (WMF-deploy-2016-05-17_(1.28.0-wmf.2)).

New error when deleting (related to this?):

API request failed (backend-fail-internal): An unknown error occurred in storage backend "local-multiwrite".

See also https://commons.wikimedia.org/wiki/Category:Deletion_bug and more complains on commons admin noticeboard by a number of admins.

Well thats a record.. 32 images in a row that I could not delete.

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1ApAMEEAAFnDRjEAAAAT] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:16 GMT served by mw1230

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1ApAEHQAACKc3hQAAACV] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:16 GMT served by mw1136

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1ApAANEAAAYvSyYAAADA] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:16 GMT served by mw1206

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1ApAEHcAAHlQ4xAAAAAF] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:17 GMT served by mw1139

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1ApAIEEAABnEJSIAAAAV] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:16 GMT served by mw1195

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAMEUAAFykz9YAAADA] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:17 GMT served by mw1234

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAMDsAAKhiu3YAAACV] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:17 GMT served by mw1224

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAMEUAAFykz9kAAADU] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1234

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAANAAAGov1S0AAAAC] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:17 GMT served by mw1205

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAIEEAABnEJYAAAAAY] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1195

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAEGMAABLuPmYAAAAI] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:17 GMT served by mw1119

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAEG8AAB9hgo0AAAAG] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1131

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1QpAIEAAAGLHi-8AAABQ] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1194

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAEGQAABOAL3YAAAAL] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1120

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAEF4AAAv7McsAAAAQ] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1114

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAEHgAAF6tlSQAAAAV] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1140

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAEF4AAAv7MdIAAAAV] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1114

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAEHkAADYKumUAAAAD] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1141

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAMD0AALnTKoAAAAAD] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1226

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAMEQAAAJXDVcAAACT] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1233

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAAM8AADKQVHIAAACR] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1204

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAID8AACY0pOgAAAAA] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1193

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAMCEAAE-7T3wAAACW] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:18 GMT served by mw1201

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1gpAMEAAAAaUlusAAAAE] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1229

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAMEMAAEsnRzkAAABW] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1232

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAANAAAGov1gkAAAAE] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1205

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAANIAADZpB2kAAACK] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1207

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAMEYAALDLiHIAAAAH] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1235

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAMCEAAE-7T@kAAACM] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1201

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAIEEAABnEJkUAAAAS] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1195

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAEHYAAG5ovIcAAACA] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:20 GMT served by mw1138

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAIEAAAGLHjNoAAABR] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:20 GMT served by mw1194

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAMCQAAGY8n1EAAAAW] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1208

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAIEAAAGLHjOgAAABK] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:20 GMT served by mw1194

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAEHEAACGaE1MAAACE] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:19 GMT served by mw1133

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL1wpAIDsAAENBGLIAAAAR] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:20 GMT served by mw1189

API request failed (internal_api_error_Wikibase\Client\Usage\UsageTrackerException): [V0IL2ApAEGIAAEDx1hgAAAAK] Exception Caught: Got explicit BEGIN from Wikibase\Client\Usage\Sql\EntityUsageTable::removeUsages while atomic section(s) FileDeleteForm::doDelete are open. at Sun, 22 May 2016 19:43:20 GMT served by mw1118

@Riley_Huntley That sounds like a separate bug, Wikidata-related. Looks like it's filed as T135485.

Also happened four or five times on:

API request failed (internal_api_error_LocalFileLockError): [V0QTqwpAID8AAGdG7ocAAACU] Exception Caught: Could not acquire lock for 'AMARU-Patricia.jpg' (10.959584951401 sec)

before it just worked. Image preview wouldn't load on file description page, either.

Change 293268 had a related patch set uploaded (by Aaron Schulz):
Make LocalFileLockError and error page exception

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

gerritbot added a project: Patch-For-Review.Jun 8 2016, 8:28 AM

Change 293268 merged by jenkins-bot:
Make LocalFileLockError an error page exception

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

ReleaseTaggerBot added a project: MW-1.28-release (WMF-deploy-2016-06-14_(1.28.0-wmf.6)).Jun 11 2016, 4:00 AM

The error message should be less terse now.

How often does this occur when another user is not currently deleting the file? The only way that could happen would be if the lock failed to release (maybe due to some transient redis error).

Change 296676 had a related patch set uploaded (by Aaron Schulz):
Increase redisLockManager read timeout from 1 to 2 seconds

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

Change 296678 had a related patch set uploaded (by Aaron Schulz):
Use a log group for LocalFile lock errors

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

Change 296815 had a related patch set uploaded (by Aaron Schulz):
Use a log group for LocalFile lock errors

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

Change 296678 merged by jenkins-bot:
Use a log group for LocalFile lock errors

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

Change 296815 merged by jenkins-bot:
Use a log group for LocalFile lock errors

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

ReleaseTaggerBot added projects: MW-1.28-release (WMF-deploy-2016-06-28_(1.28.0-wmf.8)), MW-1.28-release (WMF-deploy-2016-07-05_(1.28.0-wmf.9)).Jun 30 2016, 8:00 PM

This is still happening. I don't believe it's due to multiple people trying to delete the files, since the files remain after failure. Possibly relevant: the files where deletion fails universally take a _long_ time to generate the thumbnails, or simply don't generate thumbnails on the File: pages.

Trying again and again sometimes works, sometimes doesn't.

Recent examples:
[[:File:BREAKFAST (held by) NORDDEUTSCHER LLOYD BREMEN (at) EN ROUTE ABOARD DAMPFER BARBAROSSA (SS;) (NYPL Hades-276248-4000013535).jpg]]
Could not acquire lock for "mwstore://local-multiwrite/local-public/8/85/BREAKFAST_(held_by)_NORDDEUTSCHER_LLOYD_BREMEN_(at)_EN_ROUTE_ABOARD_DAMPFER_BARBAROSSA_(SS;)_(NYPL_Hades-276248-4000013535).jpg".

[[:File:FRUHSTUCK_(held_by)_NORDDEUTSCHER_LLOYD_BREMEN_(at)_DAMPFER;_H.H._MEIER_(SS;)_(NYPL_Hades-276205-4000013489).tiff]]
Could not acquire lock for "mwstore://local-multiwrite/local-public/d/d8/FRUHSTUCK_(held_by)_NORDDEUTSCHER_LLOYD_BREMEN_(at)_DAMPFER;_H.H._MEIER_(SS;)_(NYPL_Hades-276205-4000013489).tiff".

Example of it working after two failed attempts:
[[:File:LUNCH_(held_by)_NORDDEUTSCHER_LLOYD_BREMEN_(at)_"SCHNELLDAMPFER_"HOHENZOLLERN"_(SS;)_(NYPL_Hades-276088-4000013324).tiff]]

Logging indicates that the following happens:
a) many similarly named files are deleted at once, causing deadlocks in GlobalUsage::copyLocalImagelinks
b) this causes DB rollback and the unlockFiles() call in onTransactionIdle() never happens
c) RedisLockManager::destruct() *should* clear the locks at request end, but does not seem to trigger (it might be too late and the redis connection pool may be destroyed)
d) A bunch of locks are stuck for the 5 minute timeout for those files

Change 297284 had a related patch set uploaded (by Aaron Schulz):
Fixes to LocalFile::lock()

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

Change 296676 merged by jenkins-bot:
Increase redisLockManager read timeout from 1 to 2 seconds

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

Change 297284 merged by jenkins-bot:
Fixes to LocalFile::lock()

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

ReleaseTaggerBot added a project: MW-1.28-release (WMF-deploy-2016-07-12_(1.28.0-wmf.10)).Jul 5 2016, 9:00 PM

It's also affecting INeverCry: https://commons.wikimedia.org/wiki/Commons:Administrators%27_noticeboard#Deletion_fails

I don't think it's caused by similarity of names... The following just failed twice:

[[:File:B5c2309350800d06dc1efe7414da0fbc.jpg.jpg]]:
Could not acquire lock for "mwstore://local-multiwrite/local-public/f/f2/B5c2309350800d06dc1efe7414da0fbc.jpg.jpg".

[[:File:599full-genevieve-padalecki_.jpg]]:
Could not acquire lock for "mwstore://local-multiwrite/local-public/8/82/599full-genevieve-padalecki_.jpg".

These were the only two failures in a batch of ~70 deletions, and they failed again after a minute or so, before working on the third try just now as I'm typing.

Poyekhali merged a task: T139873: Can't delete en:File:Testing_protection_level_reset_on_delete_and_restore.png.Jul 10 2016, 7:58 AM

Poyekhali mentioned this in T139873: Can't delete en:File:Testing_protection_level_reset_on_delete_and_restore.png.

Poyekhali added subscribers: Matanya, MrStradivarius.

According to kibana, these seem to be relatively rare now.

I ~~can't~~ couldn't delete https://commons.wikimedia.org/wiki/File:%D8%B3%DB%8C%D9%86%D8%A7.PNG

Could not acquire lock for "mwstore://local-multiwrite/local-public/4/40/سینا.PNG".

It was a dupe of another file (https://commons.wikimedia.org/w/index.php?title=File:Sina0.PNG&action=edit&redlink=1) which I successfully deleted a second before trying this one. Does not seem to be a fixed issue, so marking it as resolved because it is "rare" is misleading...

(Successfully deleted minutes after)

When does "because it is rare" became a reason to close tasks as resolved...

For random "can't lock", "lock wait timeout", and "deadlock" errors, it is normal to close bugs if they are rare, as long as nothing ends up corrupted.

Is there any other reason for reopening this? Is there excess or phantom contention?

matmarex unsubscribed.Jul 24 2016, 6:07 PM

aaron closed this task as Resolved.Jul 26 2016, 12:23 AM

See https://commons.wikimedia.org/wiki/Commons:Administrators%27_noticeboard#Deletion_fails, INC cannot delete files again.

Unfortunately, they seems back. Cite "I get at least 20 per week closing the daily DRs.".

Can be mass delete a cause?

(@aaron hope it is okay if i am going to re-open this, especially to gave a track - otherwise users will open new task and stuff is getting spitted :-) - otherwise feel free to re-close again.)

T141704 is something else?

aaron removed aaron as the assignee of this task.Aug 7 2016, 7:14 AM

czar awarded a token.Aug 8 2016, 6:27 PM

czar unsubscribed.

matmarex mentioned this in T32961: Run refreshImageMetadata.php --force.Oct 10 2016, 9:25 PM

fgiunchedi mentioned this in T147986: [BUG] rise in Could not acquire lock for "mwstore://local-multiwrite/local-public/NAME_OF_FILE.Oct 14 2016, 9:18 AM

thcipriani merged a task: T147986: [BUG] rise in Could not acquire lock for "mwstore://local-multiwrite/local-public/NAME_OF_FILE.Oct 27 2016, 2:13 PM

thcipriani added subscribers: thcipriani, • Gilles, fgiunchedi, Jay8g.

zhuyifei1999 moved this task from Backlog to File storage issues on the Commons board.Jul 25 2017, 10:27 AM

Krinkle removed projects: MW-1.28-release (WMF-deploy-2016-07-12_(1.28.0-wmf.10)), MW-1.28-release (WMF-deploy-2016-07-05_(1.28.0-wmf.9)), MW-1.28-release (WMF-deploy-2016-06-28_(1.28.0-wmf.8)), MW-1.28-release (WMF-deploy-2016-06-14_(1.28.0-wmf.6)), Patch-For-Review, MW-1.28-release (WMF-deploy-2016-05-17_(1.28.0-wmf.2)), MW-1.28-release-notes, MW-1.28-release (WMF-deploy-2016-05-10_(1.28.0-wmf.1)), MW-1.27-release-notes, MW-1.27-release (WMF-deploy-2016-05-03_(1.27.0-wmf.23)), SRE-swift-storage, SRE.Aug 8 2017, 2:15 AM

Krinkle added a project: Multimedia.

@aaron can you check if this is still an issue, or if the related bug's solution also solved this problem? We're wondering whether the Multimedia team needs to pay attention to this or if it got fixed already.

• Ramsey-WMF moved this task from Untriaged to Tracking on the Multimedia board.Oct 9 2017, 4:43 PM

• demon merged a task: T129621: "internal_api_error_MWException: [dbf916b7] Exception Caught: Could not acquire lock for" for some uploads (during upload with Pywikibot OAuth).Dec 1 2017, 6:20 PM

• demon added subscribers: Rillke, Sporti.

2017-12-08 22:16:19 [WisPIwpAADoAAHf0y50AAADA] mw1263 commonswiki 1.31.0-wmf.11 exception ERROR: [WisPIwpAADoAAHf0y50AAADA] /w/index.php?title=File:Test.svg&action=delete   Wikimedia\Rdbms\DBQueryError from line 1179 of /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/database/Database.php: A database query error has occurred. Did you forget to run your application's database schema updater after upgrading?
Query: SELECT  page_latest  FROM `page`    WHERE page_id = '50159152' AND page_namespace = '6' AND page_title = 'Test.svg'  LIMIT 1   FOR UPDATE
Function: WikiPage::lockAndGetLatest
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.48.23)
 {"exception_id":"WisPIwpAADoAAHf0y50AAADA","exception_url":"/w/index.php?title=File:Test.svg&action=delete","caught_by":"mwe_handler"}
[Exception Wikimedia\Rdbms\DBQueryError] (/srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/database/Database.php:1179) A database query error has occurred. Did you forget to run your application's database schema updater after upgrading?
Query: SELECT  page_latest  FROM `page`    WHERE page_id = '50159152' AND page_namespace = '6' AND page_title = 'Test.svg'  LIMIT 1   FOR UPDATE
Function: WikiPage::lockAndGetLatest
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.48.23)

  #0 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/database/Database.php(991): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
  #1 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/database/Database.php(1374): Wikimedia\Rdbms\Database->query(string, string)
  #2 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/database/Database.php(1200): Wikimedia\Rdbms\Database->select(string, string, array, string, array, array)
  #3 /srv/mediawiki/php-1.31.0-wmf.11/includes/page/WikiPage.php(2994): Wikimedia\Rdbms\Database->selectField(string, string, array, string, array)
  #4 /srv/mediawiki/php-1.31.0-wmf.11/includes/page/WikiPage.php(2815): WikiPage->lockAndGetLatest()
  #5 /srv/mediawiki/php-1.31.0-wmf.11/includes/FileDeleteForm.php(197): WikiPage->doDeleteArticleReal(string, boolean, integer, boolean, string, User, array)
  #6 /srv/mediawiki/php-1.31.0-wmf.11/includes/FileDeleteForm.php(119): FileDeleteForm::doDelete(Title, LocalFile, string, string, boolean, User)
  #7 /srv/mediawiki/php-1.31.0-wmf.11/includes/page/ImagePage.php(992): FileDeleteForm->execute()
  #8 /srv/mediawiki/php-1.31.0-wmf.11/includes/actions/DeleteAction.php(46): ImagePage->delete()
  #9 /srv/mediawiki/php-1.31.0-wmf.11/includes/MediaWiki.php(499): DeleteAction->show()
--
2017-12-08 22:16:19 [WisPIwpAADoAAHf0y50AAADA] mw1263 commonswiki 1.31.0-wmf.11 exception ERROR: [WisPIwpAADoAAHf0y50AAADA] /w/index.php?title=File:Test.svg&action=delete   Wikimedia\Rdbms\DBTransactionError from line 1213 of /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/loadbalancer/LoadBalancer.php: Explicit transaction still active. A caller may have caught an error. {"exception_id":"WisPIwpAADoAAHf0y50AAADA","exception_url":"/w/index.php?title=File:Test.svg&action=delete","caught_by":"mwe_handler"}
[Exception Wikimedia\Rdbms\DBTransactionError] (/srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/loadbalancer/LoadBalancer.php:1213) Explicit transaction still active. A caller may have caught an error.
  #0 [internal function]: Closure$Wikimedia\Rdbms\LoadBalancer::approveMasterChanges(Wikimedia\Rdbms\DatabaseMysqli)
  #1 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1556): call_user_func_array(Closure$Wikimedia\Rdbms\LoadBalancer::approveMasterChanges;352, array)
  #2 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1233): Wikimedia\Rdbms\LoadBalancer->forEachOpenMasterConnection(Closure$Wikimedia\Rdbms\LoadBalancer::approveMasterChanges;352)
  #3 [internal function]: Wikimedia\Rdbms\LoadBalancer->approveMasterChanges(array)
  #4 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/lbfactory/LBFactory.php(184): call_user_func_array(array, array)
  #5 [internal function]: Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod(Wikimedia\Rdbms\LoadBalancer, string, array)
  #6 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/lbfactory/LBFactoryMulti.php(425): call_user_func_array(Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod;244, array)
  #7 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/lbfactory/LBFactory.php(187): Wikimedia\Rdbms\LBFactoryMulti->forEachLB(Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod;244, array)
  #8 /srv/mediawiki/php-1.31.0-wmf.11/includes/libs/rdbms/lbfactory/LBFactory.php(224): Wikimedia\Rdbms\LBFactory->forEachLBCallMethod(string, array)
  #9 /srv/mediawiki/php-1.31.0-wmf.11/includes/MediaWiki.php(881): Wikimedia\Rdbms\LBFactory->commitMasterChanges(string)
  #10 /srv/mediawiki/php-1.31.0-wmf.11/includes/MediaWiki.php(719): MediaWiki->restInPeace(string, boolean)
  #11 [internal function]: Closure$MediaWiki::doPostOutputShutdown()
  #12 {main}

Perhelion subscribed.Dec 8 2017, 10:33 PM

I guess Test.svg is a really problem (limit) indicator, as this has the ongoing growing longest file history ever (+ already deletions).

jcrespo mentioned this in T141704: Unable to delete certain files due to "inconsistent state within the internal storage backends".Apr 2 2018, 9:52 AM

The previous comments don't explain what/who exactly this task is stalled on ("If a report is waiting for further input (e.g. from its reporter or a third party) and can currently not be acted on"). Hence resetting task status.

(Smallprint, as general orientation for task management: If you wanted to express that nobody is currently working on this task, then the assignee should be removed and/or priority could be lowered instead. If work on this task is blocked by another task, then that other task should be added via Edit Related Tasks... → Edit Subtasks. If this task is stalled on an upstream project, then the Upstream tag should be added. If this task requires info from the task reporter, then there should be instructions which info is needed. If this task is out of scope and nobody should ever work on this, then task status should have the "Declined" status.)

Krinkle mentioned this in T275072: LocalFileLockError: Could not acquire lock for "mwstore: …" (via ApiUpload.php).Feb 17 2021, 7:42 PM

Umherirrender mentioned this in T45331: Do not refresh file metadata for huge files on purge, and especially do not do it well holding database locks.Nov 27 2021, 5:27 PM

Addshore unsubscribed.Jun 27 2023, 12:39 PM

Unable to delete file pages on commons: MWException/LocalFileLockError: "Could not acquire lock"Open, HighPublicActions

Description

Details

Related Objects

Event Timeline

Unable to delete file pages on commons: MWException/LocalFileLockError: "Could not acquire lock"
Open, HighPublic
Actions