Page MenuHomePhabricator

Unable to view some articles due to fatal LogicException: Cannot roll back missing named ref "" (from ReferenceStack.php)
Closed, ResolvedPublic3 Estimate Story Points

Details

Request ID
XhiXwApAIDoAAIDJg1cAAABR
Stack Trace
2020-01-10 15:26:56 [XhiXwApAIDoAAIDJg1cAAABR] mw1346 enwiki 1.35.0-wmf.14 exception ERROR: [XhiXwApAIDoAAIDJg1cAAABR] /w/api.php   LogicException from line 329 of /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/ReferenceStack.php: Cannot roll back missing named ref "". {"exception_id":"XhiXwApAIDoAAIDJg1cAAABR","exception_url":"/w/api.php","caught_by":"mwe_handler"} 
[Exception LogicException] (/srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/ReferenceStack.php:329) Cannot roll back missing named ref "".
  #0 /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/ReferenceStack.php(264): Cite\ReferenceStack->rollbackRef(string, integer, string, string, NULL, string, array)
  #1 /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/Cite.php(450): Cite\ReferenceStack->rollbackRefs(integer)
  #2 /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/Cite.php(413): Cite\Cite->guardedReferences(string, array, Parser)
  #3 /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/Hooks/CiteParserTagHooks.php(63): Cite\Cite->references(string, array, Parser)
  #4 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(4046): Cite\Hooks\CiteParserTagHooks::references(string, array, Parser, PPTemplateFrame_Hash)
  #5 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/CoreParserFunctions.php(1111): Parser->extensionSubstitution(array, PPTemplateFrame_Hash)
  #6 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(3569): CoreParserFunctions::tagObj(Parser, PPTemplateFrame_Hash, array)
  #7 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(3273): Parser->callParserFunction(PPTemplateFrame_Hash, string, array)
  #8 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
  #9 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(3451): PPFrame_Hash->expand(PPNode_Hash_Tree)
  #10 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPFrame_Hash)
  #11 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(3115): PPFrame_Hash->expand(PPNode_Hash_Tree, integer)
  #12 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(1478): Parser->replaceVariables(string)
  #13 /srv/mediawiki/php-1.35.0-wmf.14/includes/parser/Parser.php(586): Parser->internalParse(string)
  #14 /srv/mediawiki/php-1.35.0-wmf.14/includes/content/WikitextContent.php(368): Parser->parse(string, Title, ParserOptions, boolean, boolean, NULL)
  #15 /srv/mediawiki/php-1.35.0-wmf.14/includes/content/AbstractContent.php(555): WikitextContent->fillParserOutput(Title, NULL, ParserOptions, boolean, ParserOutput)
  #16 /srv/mediawiki/php-1.35.0-wmf.14/includes/Revision/RenderedRevision.php(267): AbstractContent->getParserOutput(Title, NULL, ParserOptions, boolean)
  #17 /srv/mediawiki/php-1.35.0-wmf.14/includes/Revision/RenderedRevision.php(236): MediaWiki\Revision\RenderedRevision->getSlotParserOutputUncached(WikitextContent, boolean)
  #18 /srv/mediawiki/php-1.35.0-wmf.14/includes/Revision/RevisionRenderer.php(215): MediaWiki\Revision\RenderedRevision->getSlotParserOutput(string)
  #19 /srv/mediawiki/php-1.35.0-wmf.14/includes/Revision/RevisionRenderer.php(152): MediaWiki\Revision\RevisionRenderer->combineSlotOutput(MediaWiki\Revision\RenderedRevision, array)
  #20 [internal function]: MediaWiki\Revision\RevisionRenderer->MediaWiki\Revision\{closure}(MediaWiki\Revision\RenderedRevision, array)
  #21 /srv/mediawiki/php-1.35.0-wmf.14/includes/Revision/RenderedRevision.php(198): call_user_func(Closure, MediaWiki\Revision\RenderedRevision, array)
  #22 /srv/mediawiki/php-1.35.0-wmf.14/includes/Storage/DerivedPageDataUpdater.php(1290): MediaWiki\Revision\RenderedRevision->getRevisionParserOutput()
  #23 [internal function]: MediaWiki\Storage\DerivedPageDataUpdater->getCanonicalParserOutput()
  #24 /srv/mediawiki/php-1.35.0-wmf.14/includes/edit/PreparedEdit.php(104): call_user_func(array)
  #25 /srv/mediawiki/php-1.35.0-wmf.14/includes/edit/PreparedEdit.php(119): MediaWiki\Edit\PreparedEdit->getOutput()
  #26 /srv/mediawiki/php-1.35.0-wmf.14/includes/Storage/DerivedPageDataUpdater.php(1268): MediaWiki\Edit\PreparedEdit->__get(string)
  #27 /srv/mediawiki/php-1.35.0-wmf.14/includes/page/WikiPage.php(2029): MediaWiki\Storage\DerivedPageDataUpdater->getPreparedEdit()
  #28 /srv/mediawiki/php-1.35.0-wmf.14/includes/Storage/PageEditStash.php(130): WikiPage->prepareContentForEdit(WikitextContent, NULL, User, string, boolean)
  #29 /srv/mediawiki/php-1.35.0-wmf.14/includes/api/ApiStashEdit.php(137): MediaWiki\Storage\PageEditStash->parseAndCache(WikiPage, WikitextContent, User, string)
  #30 /srv/mediawiki/php-1.35.0-wmf.14/includes/api/ApiMain.php(1603): ApiStashEdit->execute()
  #31 /srv/mediawiki/php-1.35.0-wmf.14/includes/api/ApiMain.php(539): ApiMain->executeAction()
  #32 /srv/mediawiki/php-1.35.0-wmf.14/includes/api/ApiMain.php(510): ApiMain->executeActionWithErrorHandling()
  #33 /srv/mediawiki/php-1.35.0-wmf.14/api.php(78): ApiMain->execute()
  #34 /srv/mediawiki/w/api.php(3): require(string)
  #35 {main}
Related Gerrit Patches:
mediawiki/services/parsoid : masterSync parserTests with Cite, including new blacklist entries
mediawiki/extensions/Cite : masterRelax empty-string name validation
mediawiki/extensions/Cite : masterFix for blank-named ref in #tag
mediawiki/extensions/Cite : wmf/1.35.0-wmf.15[Backport] Fix for nested #tag:references and empty name
mediawiki/extensions/Cite : masterFix for nested #tag:references

Event Timeline

Reedy created this task.Jan 10 2020, 3:27 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJan 10 2020, 3:27 PM
Reedy changed the subtype of this task from "Task" to "Production Error".Jan 10 2020, 3:27 PM
Reedy set Request ID to XhiXwApAIDoAAIDJg1cAAABR.
Reedy edited Stack Trace. (Show Details)

Looking at the currently deployed branch it seems @awight last touched that area (but since cutting the branch there have been further changes in that file).

This is causing some more exceptions starting the 13th at 20:00 UTC
https://logstash.wikimedia.org/goto/f89dbf583c75b464f941a73e51f35fc5

How exciting! This is a page which causes a render exception every time it's viewed: https://fr.wikipedia.org/wiki/Nachi_(navire)

It's caused by nested References templates,

== Notes et références ==

; Notes
{{Références|groupe="Note"|références=

<ref name="Note1">Le commandant du ''Nachi'' depuis le 15 novembre 1942, est le [[Kaigun-daisa|capitaine de vaisseau]] Akira Soji, qui commandait le {{navire|Mogami|croiseur}}, à la [[bataille de Midway]]. </ref>

; Références
{{Références|colonnes=3}}
}}

Impressive edge case :-) Moving the final }} solves the problem. I'll write a regression test case to reproduce.

Change 564558 had a related patch set uploaded (by Awight; owner: Awight):
[mediawiki/extensions/Cite@master] [WIP] Regression test for nested, #tag references

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

Um, just noticing that the error I'm chasing is different than the one reported in this task.

LogicException from line 309 of /srv/mediawiki/php-1.35.0-wmf.14/extensions/Cite/src/ReferenceStack.php: Cannot roll back ref with unknown group "".

Not sure which one you fixed, but it definitely made the one I reported stop :-)
https://logstash.wikimedia.org/goto/f89dbf583c75b464f941a73e51f35fc5

Thanks!

See also T182929 / https://gerrit.wikimedia.org/r/423342 which seems to have dealt with a similar issue. May've gotten lost in the refactor (I should have added a test back then..).

WMDE-Fisch moved this task from Sprint Backlog to Doing on the WMDE-QWERTY-Sprint-2020-01-08 board.

See also T182929 / https://gerrit.wikimedia.org/r/423342 which seems to have dealt with a similar issue.

Thanks for the link. If you ask me, these are unrelated. While T182929 was about the group, this here is about the name.

Overall, I'm super happy with how the current refactoring turned out. It could have been sooo much worse, but didn't. We had really good test coverage before we started. However, there are sooo many edge cases now (for example, the follow feature is nuts, as is the ability to section-preview incomplete references), there was no way we could predict everything. The real issue is that a most of the later features have been added without a single test.

WMDE-Fisch set the point value for this task to 3.Jan 16 2020, 10:48 AM
Krinkle triaged this task as Unbreak Now! priority.EditedJan 16 2020, 6:39 PM

This is currently the most frequently observed error in production (Logstash).

The fatals come in waves from readers viewing articles that have become inaccessible due to this bug.

The one spiking most frequently right now is https://uk.wikipedia.org/wiki/Tinder. And interesting is that it has not been edited in several months (last edit in September 2019). Raising priority because it is consistently affecting production GET traffic, in particular pre-existing articles that have not been broken by users recently stopped being accessible as a result, with a risk of cascading failures.

This is expected to become more frequent over time as more CDN and parser caches expire.

Restricted Application added a subscriber: Liuxinyu970226. · View Herald TranscriptJan 16 2020, 6:39 PM
Krinkle renamed this task from ReferenceStack.php: Cannot roll back missing named ref "" to Unable to view some articles due to fatal LogicException: Cannot roll back missing named ref "" (from ReferenceStack.php).Jan 16 2020, 6:39 PM
Krinkle added subscribers: AS, Base.

Change 564558 merged by jenkins-bot:
[mediawiki/extensions/Cite@master] Fix for nested #tag:references

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

Change 565517 had a related patch set uploaded (by Awight; owner: Awight):
[mediawiki/extensions/Cite@master] [WIP] Regression test for blank-named ref in #tag

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

Hopefully the second patch addresses the remaining exceptions. There was an interesting edge case where name="" in a template-generated reflist causes a crash. The patch does additional validation to catch these.

Since today is Friday, my suggestion is that I workaround the most popular pages which are crashing, by manually fixing their bad refs. For example, this edit. We can SWAT-deploy the code fix on Monday.

Change 565517 merged by jenkins-bot:
[mediawiki/extensions/Cite@master] Fix for blank-named ref in #tag

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

I've already hit the wall with my editing approach. https://zh.wikipedia.org/w/index.php?title=User:Atana_goodwin/Work14&oldid=49425248 cannot be edited because it's under the user namespace, but seems to be breaking the RefreshLinksJob.

Starting to look like this is a Friday deployment.

@awight are there enough errors from that person's user page to warrant drastic action or might it be OK to suffer the consequences of ignoring it over the weekend?

Change 565562 had a related patch set uploaded (by Awight; owner: Awight):
[mediawiki/extensions/Cite@wmf/1.35.0-wmf.15] [Backport] Fix for nested #tag:references and empty name

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

Change 565562 merged by jenkins-bot:
[mediawiki/extensions/Cite@wmf/1.35.0-wmf.15] [Backport] Fix for nested #tag:references and empty name

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

Mentioned in SAL (#wikimedia-operations) [2020-01-17T14:03:09Z] <awight> beginning Friday deployment for UBN, T242437

Mentioned in SAL (#wikimedia-operations) [2020-01-17T14:09:12Z] <awight@deploy1001> Synchronized php-1.35.0-wmf.15/extensions/Cite: UBN backport: [[gerrit:565562|Fix for nested #tag:references and empty name (T242437)]] (duration: 00m 57s)

More examples of fixing the error (thanks, @Reedy!):
https://zh.wikipedia.org/w/index.php?title=User%3AAtana_goodwin%2FWork14&type=revision&diff=57736642&oldid=49425248

The code fix is deployed, and logs are quiet.

awight lowered the priority of this task from Unbreak Now! to High.Jan 20 2020, 9:18 AM
awight moved this task from Review to Doing on the WMDE-QWERTY-Sprint-2020-01-08 board.

The "unbreak now" issue is fixed in production, but during code review we found that the fix needs to be rolled back and reimplemented. As currently deployed, the code will show inline errors for any refs with name="" or a name with pure whitespace. Although this is a degenerate case, it wasn't erroring in the past, and our guideline for the rewrite has been to not introduce any new errors for existing wikitext.

Change 565990 had a related patch set uploaded (by Awight; owner: Awight):
[mediawiki/extensions/Cite@master] Relax empty-string name validation

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

Change 565990 merged by jenkins-bot:
[mediawiki/extensions/Cite@master] Relax empty-string name validation

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

WMDE-Fisch closed this task as Resolved.Jan 21 2020, 2:45 PM

Should be fixed.

Change 566352 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/services/parsoid@master] Sync parserTests with Cite, including new blacklist entries

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

Change 566352 merged by jenkins-bot:
[mediawiki/services/parsoid@master] Sync parserTests with Cite, including new blacklist entries

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