[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Page MenuHomePhabricator
Create Task
Maniphest T249045

PHP Warning: Recursion detected in RequestContext::getLanguage
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error

MediaWiki version: 1.35.0-wmf.26

message
PHP Warning: Recursion detected in RequestContext::getLanguage

Impact

Significant error rate increase following testwiki deployment. No production impact beyond testwiki and log spam.

Notes

Details

Request ID
XoOknQpAAL8AA4@boCkAAAAP
Request URL
https://test.wikipedia.org/w/index.php?title=User:SR5/test3.js&action=raw&ctype=text/javascript
Stack Trace
exception.trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.35.0-wmf.26/includes/context/RequestContext.php(334): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.35.0-wmf.26/includes/language/Message.php(721): RequestContext->getLanguage()
#3 /srv/mediawiki/php-1.35.0-wmf.26/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
#4 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
#5 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/UserNameUtils.php(280): MediaWiki\User\UserNameUtils->isUsable(string)
#6 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(1147): MediaWiki\User\UserNameUtils->getCanonical(string, string)
#7 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(539): User::getCanonicalName(string, string)
#8 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/UserInfo.php(104): User::newFromName(string, string)
#9 /srv/mediawiki/php-1.35.0-wmf.26/extensions/CentralAuth/includes/session/CentralAuthSessionProvider.php(203): MediaWiki\Session\UserInfo::newFromName(string, boolean)
#10 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/SessionManager.php(466): CentralAuthSessionProvider->provideSessionInfo(WebRequest)
#11 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/SessionManager.php(191): MediaWiki\Session\SessionManager->getSessionInfoForRequest(WebRequest)
#12 /srv/mediawiki/php-1.35.0-wmf.26/includes/WebRequest.php(810): MediaWiki\Session\SessionManager->getSessionForRequest(WebRequest)
#13 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(1169): WebRequest->getSession()
#14 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(341): User->loadDefaults()
#15 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(5066): User->load()
#16 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(2889): User->loadOptions()
#17 /srv/mediawiki/php-1.35.0-wmf.26/includes/context/RequestContext.php(351): User->getOption(string)
#18 /srv/mediawiki/php-1.35.0-wmf.26/includes/language/Message.php(721): RequestContext->getLanguage()
#19 /srv/mediawiki/php-1.35.0-wmf.26/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
#20 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
#21 /srv/mediawiki/php-1.35.0-wmf.26/includes/user/User.php(993): MediaWiki\User\UserNameUtils->isUsable(string)
#22 /srv/mediawiki/php-1.35.0-wmf.26/extensions/CentralAuth/includes/session/CentralAuthSessionProvider.php(166): User::isUsableName(string)
#23 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/SessionManager.php(466): CentralAuthSessionProvider->provideSessionInfo(WebRequest)
#24 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/SessionManager.php(191): MediaWiki\Session\SessionManager->getSessionInfoForRequest(WebRequest)
#25 /srv/mediawiki/php-1.35.0-wmf.26/includes/WebRequest.php(810): MediaWiki\Session\SessionManager->getSessionForRequest(WebRequest)
#26 /srv/mediawiki/php-1.35.0-wmf.26/includes/session/SessionManager.php(129): WebRequest->getSession()
#27 /srv/mediawiki/php-1.35.0-wmf.26/includes/Setup.php(720): MediaWiki\Session\SessionManager::getGlobalSession()
#28 /srv/mediawiki/php-1.35.0-wmf.26/includes/WebStart.php(89): require_once(string)
#29 /srv/mediawiki/php-1.35.0-wmf.26/index.php(44): require(string)
#30 /srv/mediawiki/w/index.php(3): require(string)
#31 {main}
SubjectRepoBranchLines +/-
Add a MessageFactory service to inject a message localizermediawiki/coremaster+130 -1
UserNameUtils: use ITextFormatter instead of MessageLocalizermediawiki/coremaster+109 -40
Revert "Add a new UserNameUtils service"mediawiki/coremaster+129 -802
Use wfMessage in UserNameUtils::isUsable for nowmediawiki/corewmf/1.35.0-wmf.26+2 -2
Use wfMessage in UserNameUtils::isUsable for nowmediawiki/coremaster+2 -2
Customize query in gerrit

Related Objects
Search...

Event Timeline

dduvall created this task.Mar 31 2020, 8:16 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMar 31 2020, 8:16 PM
dduvall added a parent task: T247773: 1.35.0-wmf.26 deployment blockers.Mar 31 2020, 8:16 PM
DannyS712 claimed this task.Mar 31 2020, 8:19 PM
DannyS712 triaged this task as High priority.
DannyS712 subscribed.

Likely caused by T245231: Factor username logic out of the User class

Restricted Application added a project: User-DannyS712. · View Herald TranscriptMar 31 2020, 8:19 PM
Jdforrester-WMF raised the priority of this task from High to Unbreak Now!.Mar 31 2020, 8:28 PM
Restricted Application added a subscriber: Liuxinyu970226. · View Herald TranscriptMar 31 2020, 8:28 PM
gerritbot added a comment.Mar 31 2020, 8:29 PM

Change 577687 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/core@master] Add a MessageFactory service to inject a message localizer

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

gerritbot added a project: Patch-For-Review.Mar 31 2020, 8:29 PM
DannyS712 moved this task from Unsorted to In progress on the User-DannyS712 board.Mar 31 2020, 8:31 PM
Jdforrester-WMF subscribed.Mar 31 2020, 8:49 PM

The normal approach would be to revert the patch, but reverting rMW23242d04d1dc: Add a new UserNameUtils service looks moderately painful; however, merging MessageFactory and rushing it out feels not ideal.

gerritbot added a comment.Mar 31 2020, 8:52 PM

Change 585033 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/core@master] Use wfMessage in UserNameUtils::isUsable for now

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

daniel subscribed.Mar 31 2020, 8:53 PM
In T249045#6016579, @Jdforrester-WMF wrote:

The normal approach would be to revert the patch, but reverting rMW23242d04d1dc: Add a new UserNameUtils service looks moderately painful; however, merging MessageFactory and rushing it out feels not ideal.

Considering that the new service class is < 10 actual lines of code, it may still be the best option. If it's known to actually fix the issue.

daniel added a comment.EditedMar 31 2020, 8:54 PM

I'm wondering how we could test for this kind of problem. Why does this not show up in API integration tests or Selenium tests or some such?

daniel added a project: Platform Team Workboards (Clinic Duty Team).Mar 31 2020, 8:55 PM
gerritbot added a comment.Mar 31 2020, 9:02 PM

Change 585036 had a related patch set uploaded (by Jforrester; owner: Jforrester):
[mediawiki/core@master] Revert "Add a new UserNameUtils service"

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

Anomie subscribed.Mar 31 2020, 9:08 PM
In T249045#6016609, @daniel wrote:

Why does this not show up in API integration tests or Selenium tests or some such?

Note this isn't actually a thrown exception, it's just a log that uses an unthrown exception to produce a trace. Looks like it gets written as warning-level to the 'error' channel and info-level to the 'recursion-guard' channel. Do those tests check those log channels?

Locally I also see a lot of info-level messages to GlobalTitleFail that begin like

2020-03-31 17:03:26 [eb484a2c5485f265aca87719] GlobalTitleFail INFO: RequestContext::getTitle called with no title set.
[Exception Exception] (/usr/local/src/MediaWiki/core/includes/context/RequestContext.php:175)
  #0 /usr/local/src/MediaWiki/core/includes/language/Message.php(722): RequestContext->getTitle()
  #1 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
  #2 /usr/local/src/MediaWiki/core/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
  #3 /usr/local/src/MediaWiki/core/includes/user/User.php(993): MediaWiki\User\UserNameUtils->isUsable(string)
  ...

and an info-level to 'session' like

2020-03-31 17:03:26 [eb484a2c5485f265aca87719] session WARNING: User::loadFromSession called before the end of Setup.php
[Exception Exception] (/usr/local/src/MediaWiki/core/includes/user/User.php:339) User::loadFromSession called before the end of Setup.php
  #0 /usr/local/src/MediaWiki/core/includes/user/User.php(5066): User->load()
  #1 /usr/local/src/MediaWiki/core/includes/user/User.php(2889): User->loadOptions()
  #2 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(351): User->getOption(string)
  #3 /usr/local/src/MediaWiki/core/includes/language/Message.php(721): RequestContext->getLanguage()
  #4 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
  #5 /usr/local/src/MediaWiki/core/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
  #6 /usr/local/src/MediaWiki/core/includes/user/User.php(993): MediaWiki\User\UserNameUtils->isUsable(string)
  ...
DannyS712 added a comment.Mar 31 2020, 9:10 PM
In T249045#6016670, @Anomie wrote:
In T249045#6016609, @daniel wrote:

Why does this not show up in API integration tests or Selenium tests or some such?

Note this isn't actually a thrown exception, it's just a log that uses an unthrown exception to produce a trace. Looks like it gets written as warning-level to the 'error' channel and info-level to the 'recursion-guard' channel. Do those tests check those log channels?

Locally I also see a lot of info-level messages to GlobalTitleFail that begin like

2020-03-31 17:03:26 [eb484a2c5485f265aca87719] GlobalTitleFail INFO: RequestContext::getTitle called with no title set.
[Exception Exception] (/usr/local/src/MediaWiki/core/includes/context/RequestContext.php:175)
  #0 /usr/local/src/MediaWiki/core/includes/language/Message.php(722): RequestContext->getTitle()
  #1 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
  #2 /usr/local/src/MediaWiki/core/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
  #3 /usr/local/src/MediaWiki/core/includes/user/User.php(993): MediaWiki\User\UserNameUtils->isUsable(string)
  ...

and an info-level to 'session' like

2020-03-31 17:03:26 [eb484a2c5485f265aca87719] session WARNING: User::loadFromSession called before the end of Setup.php
[Exception Exception] (/usr/local/src/MediaWiki/core/includes/user/User.php:339) User::loadFromSession called before the end of Setup.php
  #0 /usr/local/src/MediaWiki/core/includes/user/User.php(5066): User->load()
  #1 /usr/local/src/MediaWiki/core/includes/user/User.php(2889): User->loadOptions()
  #2 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(351): User->getOption(string)
  #3 /usr/local/src/MediaWiki/core/includes/language/Message.php(721): RequestContext->getLanguage()
  #4 /usr/local/src/MediaWiki/core/includes/context/RequestContext.php(443): Message->setContext(RequestContext)
  #5 /usr/local/src/MediaWiki/core/includes/user/UserNameUtils.php(178): RequestContext->msg(string)
  #6 /usr/local/src/MediaWiki/core/includes/user/User.php(993): MediaWiki\User\UserNameUtils->isUsable(string)
  ...

Both of the patches I submitted (just using wfMessage, and adding a proxy service) should fix those by removing the use of RequestContext completely

gerritbot added a comment.Mar 31 2020, 9:28 PM

Change 585033 merged by jenkins-bot:
[mediawiki/core@master] Use wfMessage in UserNameUtils::isUsable for now

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

gerritbot added a comment.Mar 31 2020, 9:29 PM

Change 585040 had a related patch set uploaded (by Jforrester; owner: DannyS712):
[mediawiki/core@wmf/1.35.0-wmf.26] Use wfMessage in UserNameUtils::isUsable for now

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

Agusbou2015 subscribed.Mar 31 2020, 9:39 PM
gerritbot added a comment.Mar 31 2020, 9:44 PM

Change 585040 merged by jenkins-bot:
[mediawiki/core@wmf/1.35.0-wmf.26] Use wfMessage in UserNameUtils::isUsable for now

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

Stashbot added a comment.Mar 31 2020, 9:46 PM

Mentioned in SAL (#wikimedia-operations) [2020-03-31T21:46:26Z] <jforrester@deploy1001> Synchronized php-1.35.0-wmf.26/includes/user/UserNameUtils.php: T249045 Use wfMessage in UserNameUtils::isUsable for now (duration: 00m 58s)

ReleaseTaggerBot added a project: MW-1.35-notes (1.35.0-wmf.26; 2020-03-31).Mar 31 2020, 10:00 PM
• Jrbranaa subscribed.Mar 31 2020, 10:01 PM
• Catrope closed this task as Resolved.Mar 31 2020, 10:45 PM
gerritbot added a comment.Mar 31 2020, 11:30 PM

Change 585053 had a related patch set uploaded (by Ppchelko; owner: Ppchelko):
[mediawiki/core@master] UserNameUtils: use ITextFormatter instead of MessageLocalizer

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

daniel added a comment.Apr 1 2020, 2:34 PM

From looking at the stack trace, this is another instance of lazy-instantiation leading to unpredictable behavior during the initialization phase: For creating a session, we need to validate a user name. Name validation depends on system messages (in the content language) which we get from MessageLocalizer - this is the bit that the patches above are fixing, but it's not problematic by itself. MessageLocalizer however defaults to the user's interface language and tries to determine it first. However, determining the user language causes the so-far-uninitialiezd User object to be initialized, which again leads to session initialization (we have already gone full circle at this point, but this has not yet detected), which again wants to check for user name validity, which uses MessageLocalizer.

To reproduce this, a test would have to attempt session initialization with GlobalAuth enabled and the User object still uninitialized. It's unlikely that we would catch such a case with a unit test - in fact, unit tests are generally designed to bypass any such setup.

The only way I see to catch this kind of this is to run end-to-end tests against a production-like environment. I don't see a way to do this before we merge, but it could be done before we deploy, see T248683: Create and run a suite of end-to-end tests for the Wikimedia environment.

gerritbot added a comment.Apr 1 2020, 4:47 PM

Change 585036 abandoned by Ppchelko:
Revert "Add a new UserNameUtils service"

Reason:
A different mitigation was deployed

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

• Jrbranaa mentioned this in T249645: Train Blocker UBN - T249045 - Retrospective.Apr 7 2020, 6:03 PM
• Pchelolo moved this task from Inbox to Waiting for Review on the Platform Team Workboards (Clinic Duty Team) board.Apr 10 2020, 5:16 PM
gerritbot added a comment.Apr 20 2020, 5:27 PM

Change 585053 merged by jenkins-bot:
[mediawiki/core@master] UserNameUtils: use ITextFormatter instead of MessageLocalizer

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

ReleaseTaggerBot edited projects, added MW-1.35-notes (1.35.0-wmf.30; 2020-04-28); removed MW-1.35-notes (1.35.0-wmf.26; 2020-03-31).Apr 20 2020, 7:00 PM
DannyS712 moved this task from In progress to Merged on the User-DannyS712 board.May 27 2020, 8:36 AM
gerritbot added a comment.Aug 29 2020, 12:51 AM

Change 577687 abandoned by DannyS712:
[mediawiki/core@master] Add a MessageFactory service to inject a message localizer

Reason:

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

Aklapper removed a subscriber: Anomie.Oct 16 2020, 5:38 PM
• Jrbranaa closed subtask T249645: Train Blocker UBN - T249045 - Retrospective as Resolved.Jun 4 2021, 6:44 PM
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