Page MenuHomePhabricator

MediaWiki->initializeArticle on FlaggedRevs wikis triggers deprecated "Unexpected clearActionName after getActionName"
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error

Seeing a bunch of these (12k and counting) after rolling back to group1; think I missed this as a separate error earlier:

Error
normalized_message
[{reqId}] {exception_url}   PHP Notice: Unexpected clearActionName after getActionName already called
exception.trace
from /srv/mediawiki/php-1.40.0-wmf.10/includes/context/RequestContext.php(311)
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.40.0-wmf.10/includes/context/RequestContext.php(311): trigger_error(string)
#2 /srv/mediawiki/php-1.40.0-wmf.10/includes/context/RequestContext.php(176): RequestContext->clearActionName()
#3 /srv/mediawiki/php-1.40.0-wmf.10/includes/MediaWiki.php(483): RequestContext->setTitle(Title)
#4 /srv/mediawiki/php-1.40.0-wmf.10/includes/MediaWiki.php(315): MediaWiki->initializeArticle()
#5 /srv/mediawiki/php-1.40.0-wmf.10/includes/MediaWiki.php(901): MediaWiki->performRequest()
#6 /srv/mediawiki/php-1.40.0-wmf.10/includes/MediaWiki.php(559): MediaWiki->main()
#7 /srv/mediawiki/php-1.40.0-wmf.10/index.php(50): MediaWiki->run()
#8 /srv/mediawiki/php-1.40.0-wmf.10/index.php(46): wfIndexMain()
#9 /srv/mediawiki/w/index.php(3): require(string)
#10 {main}

Searching logstash on the trace suggests that these are most of the notices.

I will likely roll back to group0 out of an abundance of caution before I go AFK for the day, just due to the volume, but I'm assuming these can also be trivially silenced.

Event Timeline

Krinkle triaged this task as Medium priority.Nov 17 2022, 9:14 AM
Krinkle created this task.

Seeing a bunch of these (12k and counting) after rolling back to group1; think I missed this as a separate error earlier:

Can confirm locally. I think it happens when the action is initialized (via RequestContext::getAction or RequestContext::getActionName) in the InitializeArticleMaybeRedirect hook, but then the article is not a redirect (so the // Article may have been changed by hook branch is followed in MediaWiki::initializeArticle).
Specifically, FlaggedRevs does that via FlaggedRevsUIHooks::overrideRedirect -> FlaggablePageView::showingStable -> FlaggablePageView::isDefaultPageView as the stable version is only supposed to be shown on view and similar actions.

None of the four implementers of that hook change the article, and it doesn't seem like a reasonable thing to do, so I think that branch can just be dropped. Although that wouldn't prevent this error when FlaggedRevs is present and the page is a redirect.

Change 858109 had a related patch set uploaded (by Krinkle; author: Gergő Tisza):

[mediawiki/core@master] InitializeArticleMaybeRedirect hook: Improve docs & restrict

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

Change 858226 had a related patch set uploaded (by Krinkle; author: Gergő Tisza):

[mediawiki/core@wmf/1.40.0-wmf.10] InitializeArticleMaybeRedirect hook: Improve docs & restrict

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

Change 858226 merged by jenkins-bot:

[mediawiki/core@wmf/1.40.0-wmf.10] InitializeArticleMaybeRedirect hook: Improve docs & restrict

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

Mentioned in SAL (#wikimedia-operations) [2022-11-17T17:53:53Z] <brennen@deploy1002> Started scap: Backport for [[gerrit:858226|InitializeArticleMaybeRedirect hook: Improve docs & restrict (T323254)]]

Mentioned in SAL (#wikimedia-operations) [2022-11-17T17:54:17Z] <brennen@deploy1002> brennen and krinkle: Backport for [[gerrit:858226|InitializeArticleMaybeRedirect hook: Improve docs & restrict (T323254)]] synced to the testservers: mwdebug2001.codfw.wmnet, mwdebug1002.eqiad.wmnet, mwdebug1001.eqiad.wmnet, mwdebug2002.codfw.wmnet

Mentioned in SAL (#wikimedia-operations) [2022-11-17T17:59:48Z] <brennen@deploy1002> Finished scap: Backport for [[gerrit:858226|InitializeArticleMaybeRedirect hook: Improve docs & restrict (T323254)]] (duration: 05m 55s)

Change 858109 merged by jenkins-bot:

[mediawiki/core@master] InitializeArticleMaybeRedirect hook: Improve docs & restrict

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

[…] Although that wouldn't prevent this error when FlaggedRevs is present and the page is a redirect.

Ack, this is a genuine bug imho and exactly the sort of thing we want to find. I.e. code passed around or otherwise inspected the determined action, but then later changes the title and thus the content model and associated action overriddes. Either it needs to opt-out from the title change, or needs to do so without needing to vary by action as that's recursive/paradoxal.

Conceptually, I don't think there's anything wrong here (beyond MediaWiki::initializeArticle modifying the context in the first place). FlaggedRevs checks the title and depending on what it finds redirects to a different title. Since it's the same code doing the checking and instructing the replacement of Title, it knows the old Title is temporary and there is no risk.

The fundamental problem is MediaWiki::initializeArticle modifying the context object, which is fragile as something somewhere might have cached it. (The current error triggering is somewhat arbitrary: it happens when a cached action is reset, but not when the same happens for title, user, request etc, although those all expose the same kind of risk.) I think the nice solution would be if the RequestContext was initialized in the MediaWiki class, not Setup.php, and that initialization wouldn't happen until it has determined redirects, so InitializeArticleMaybeRedirect would be passed a temporary context object. Probably not really feasible though.

The easiest way to get rid of the warning would be to change the FlaggedRevs code to use $actionFactory->getActionName( RequestContext::getMain() ) instead of RequestContext::getMain()->getActionName(), but that does feel like a hack.

Now seeing these at a much lower level on group1 than yesterday - a few hundred in 15 minutes. Manageable from an alert volume perspective, at least here. Should this block rolling to all wikis?

Change 858416 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/core@master] MediaWiki: Temp silence FR-induced clearActionName warnings

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

Change 858317 had a related patch set uploaded (by Brennen Bearnes; author: Krinkle):

[mediawiki/core@wmf/1.40.0-wmf.10] MediaWiki: Temp silence FR-induced clearActionName warnings

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

Change 858416 merged by jenkins-bot:

[mediawiki/core@master] MediaWiki: Temp silence FR-induced clearActionName warnings

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

Change 858317 merged by jenkins-bot:

[mediawiki/core@wmf/1.40.0-wmf.10] MediaWiki: Temp silence FR-induced clearActionName warnings

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

Mentioned in SAL (#wikimedia-operations) [2022-11-17T22:34:31Z] <brennen@deploy1002> Started scap: Backport for [[gerrit:858317|MediaWiki: Temp silence FR-induced clearActionName warnings (T323254)]]

Mentioned in SAL (#wikimedia-operations) [2022-11-17T22:34:55Z] <brennen@deploy1002> brennen and brennen: Backport for [[gerrit:858317|MediaWiki: Temp silence FR-induced clearActionName warnings (T323254)]] synced to the testservers: mwdebug2002.codfw.wmnet, mwdebug1001.eqiad.wmnet, mwdebug1002.eqiad.wmnet, mwdebug2001.codfw.wmnet

Mentioned in SAL (#wikimedia-operations) [2022-11-17T22:41:48Z] <brennen@deploy1002> Finished scap: Backport for [[gerrit:858317|MediaWiki: Temp silence FR-induced clearActionName warnings (T323254)]] (duration: 07m 16s)

These errors are still trickling in at a low but noticeable rate (~15/hour).

Change 888050 had a related patch set uploaded (by Ahmon Dancy; author: Ahmon Dancy):

[operations/puppet@production] logspam.pl: Filter out some persistent noise

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

Change 888050 merged by Dzahn:

[operations/puppet@production] logspam.pl: Filter out some persistent noise

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

Change 945792 had a related patch set uploaded (by Bartosz Dziewoński; author: Bartosz Dziewoński):

[operations/puppet@production] Revert "logspam.pl: Filter out some persistent noise"

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

Change 947418 had a related patch set uploaded (by Krinkle; author: Bartosz Dziewoński):

[mediawiki/extensions/FlaggedRevs@master] action=purge is not a page view

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

Change 947418 merged by jenkins-bot:

[mediawiki/extensions/FlaggedRevs@master] action=purge is not a page view

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

Change 947426 had a related patch set uploaded (by Bartosz Dziewoński; author: Bartosz Dziewoński):

[mediawiki/extensions/FlaggedRevs@master] FlaggablePageView: Move isPageView() check outside of showingStable()

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

Change 947427 had a related patch set uploaded (by Bartosz Dziewoński; author: Bartosz Dziewoński):

[mediawiki/core@master] Revert "MediaWiki: Temp silence FR-induced clearActionName warnings"

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

Change 947424 had a related patch set uploaded (by Krinkle; author: Bartosz Dziewoński):

[mediawiki/extensions/FlaggedRevs@master] FlaggablePageView: Clean up redundant conditions in showingStable()

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

Change 945792 merged by RLazarus:

[operations/puppet@production] Revert "logspam.pl: Filter out some persistent noise"

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

Change 947424 merged by jenkins-bot:

[mediawiki/extensions/FlaggedRevs@master] FlaggablePageView: Clean up redundant conditions in showingStable()

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

Change 947426 merged by jenkins-bot:

[mediawiki/extensions/FlaggedRevs@master] FlaggablePageView: Move isPageView() check outside of showingStable()

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

Change 947427 merged by jenkins-bot:

[mediawiki/core@master] Revert "MediaWiki: Temp silence FR-induced clearActionName warnings"

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

matmarex claimed this task.
matmarex added a subscriber: Tgr.