Page MenuHomePhabricator
Create Task
Maniphest T412959

Logstash poolcounter warnings "Usage error: You may only aquire a single non-nowait lock" on wikis with post-processing cache enabled
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

While deploying Activate post-processing cache on some wikis today, we noticed the following logstash message on mwdebug:

Info
  • mwversion: 1.46.0-wmf.5
  • timestamp: 2025-12-17T14:50:46.561Z
  • phpversion: 8.3.26
  • reqId: ab251f54-2764-4aed-9464-5dc03d8ca706
  • Find reqId in Logstash
normalized_message
Pool key 'simplewiki:parsoid-pcache:129793:|#|:idhash:useParsoid=1:revid:10503646' (ArticleView): Usage error: You may only aquire a single non-nowait lock.
exception.trace

Subsequent investigation showed that this seems to be quite common outside of mwdebug, with a sharp uptick on 15 December, when Activate post-processing cache on idwiki was deployed:
https://logstash.wikimedia.org/goto/0c76f5bb63561e91410b391a570ebbe1

image.png (300×914 px, 35 KB)

There are some other occurrences of this usage error (including T412960: Pool key 'dewiki:SpecialContributions:a:127.0.0.1' (SpecialContributions): Usage error: You may only aquire a single non-nowait lock.), but they’re a lot less common.

Impact

Only logspam, as far as we’re aware. But quite a bit of it.

Details

Related Changes in Gerrit:
SubjectRepoBranchLines +/-
ParserOutputAccess: don't use PoolCounter recursivelymediawiki/corewmf/1.46.0-wmf.7+3 -1
ParserOutputAccess: don't use PoolCounter recursivelymediawiki/corewmf/1.46.0-wmf.5+3 -1
PoolCounter: fix typo in error message (aquire -> acquire)mediawiki/coremaster+1 -1
ParserOutputAccess: don't use PoolCounter recursivelymediawiki/coremaster+3 -1
Customize query in gerrit

Related Objects
Search...

Event Timeline

Lucas_Werkmeister_WMDE created this task.Dec 17 2025, 3:03 PM
Lucas_Werkmeister_WMDE triaged this task as High priority.
Restricted Application added a project: Wikimedia-production-error. · View Herald TranscriptDec 17 2025, 3:04 PM
cscott mentioned this in T412960: Pool key 'dewiki:SpecialContributions:a:127.0.0.1' (SpecialContributions): Usage error: You may only aquire a single non-nowait lock..Dec 17 2025, 3:04 PM
Lucas_Werkmeister_WMDE updated the task description. (Show Details)Dec 17 2025, 3:05 PM
cscott added a comment.Dec 17 2025, 3:10 PM

Presumably this is being triggered when we do a PoolCounter parse for a postprocessed ParserOutput, which then recursively triggers another PoolCounter parse of the canonical ParserOutput. I believe the entire thing is protected by the outer lock and so there is no practical impact other than logspam -- I triggered this during testing on simplewiki by doing a purge, and saw no reader-visible effects. But we should fix the logspam and the underlying usage before rolling out the postprocessing cache further.

gerritbot added a comment.Dec 17 2025, 6:26 PM

Change #1219197 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@master] ParserOutputAccess: don't use PoolCounter recursively

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

gerritbot added a project: Patch-For-Review.Dec 17 2025, 6:26 PM
gerritbot added a comment.Dec 17 2025, 6:33 PM

Change #1219194 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@master] PoolCounter: fix typo in error message (aquire -> acquire)

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

gerritbot added a comment.Dec 17 2025, 8:05 PM

Change #1219197 merged by jenkins-bot:

[mediawiki/core@master] ParserOutputAccess: don't use PoolCounter recursively

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

gerritbot added a comment.Dec 17 2025, 8:08 PM

Change #1219194 merged by jenkins-bot:

[mediawiki/core@master] PoolCounter: fix typo in error message (aquire -> acquire)

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

gerritbot added a comment.Dec 17 2025, 8:28 PM

Change #1219216 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@wmf/1.46.0-wmf.5] ParserOutputAccess: don't use PoolCounter recursively

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

gerritbot added a comment.Dec 17 2025, 8:29 PM

Change #1219217 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@wmf/1.46.0-wmf.7] ParserOutputAccess: don't use PoolCounter recursively

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

gerritbot added a comment.Dec 17 2025, 9:08 PM

Change #1219216 merged by jenkins-bot:

[mediawiki/core@wmf/1.46.0-wmf.5] ParserOutputAccess: don't use PoolCounter recursively

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

gerritbot added a comment.Dec 17 2025, 9:09 PM

Change #1219217 merged by jenkins-bot:

[mediawiki/core@wmf/1.46.0-wmf.7] ParserOutputAccess: don't use PoolCounter recursively

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

Stashbot added a comment.Dec 17 2025, 9:09 PM

Mentioned in SAL (#wikimedia-operations) [2025-12-17T21:09:38Z] <cscott@deploy2002> Started scap sync-world: Backport for [[gerrit:1219216|ParserOutputAccess: don't use PoolCounter recursively (T412959)]], [[gerrit:1219217|ParserOutputAccess: don't use PoolCounter recursively (T412959)]]

Stashbot added a comment.Dec 17 2025, 9:11 PM

Mentioned in SAL (#wikimedia-operations) [2025-12-17T21:11:50Z] <cscott@deploy2002> cscott: Backport for [[gerrit:1219216|ParserOutputAccess: don't use PoolCounter recursively (T412959)]], [[gerrit:1219217|ParserOutputAccess: don't use PoolCounter recursively (T412959)]] synced to the testservers (see https://wikitech.wikimedia.org/wiki/Mwdebug). Changes can now be verified there.

Stashbot added a comment.Dec 17 2025, 9:18 PM

Mentioned in SAL (#wikimedia-operations) [2025-12-17T21:18:28Z] <cscott@deploy2002> Finished scap sync-world: Backport for [[gerrit:1219216|ParserOutputAccess: don't use PoolCounter recursively (T412959)]], [[gerrit:1219217|ParserOutputAccess: don't use PoolCounter recursively (T412959)]] (duration: 08m 50s)

Maintenance_bot removed a project: Patch-For-Review.Dec 17 2025, 9:30 PM
cscott closed this task as Resolved.Dec 17 2025, 9:51 PM
cscott claimed this task.

I believe this is fixed in production now.

cscott added a comment.Dec 17 2025, 9:52 PM

image.png (549×643 px, 68 KB)

Lucas_Werkmeister_WMDE added a comment.Dec 18 2025, 1:22 PM

Alternative screenshot to make sure that the drop isn’t just due to the changed log message:

image.png (394×678 px, 43 KB)

(I acknowledge that you didn’t backport that change, but IMHO it still would’ve been a better idea to not do it at the same time :P)

Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits