ULS gets a lot of collateral for using the UserGetLanguageObject, where I think it should be safe to except that the User object's methods can be called.

The irony is that the hook doesn't do anything on WMF due to the configuration – other than exposing these bugs.

Please ping us (the Language team) if you need our assistance. Thank you!

In T267445#6610408, @Nikerabbit wrote:

ULS gets a lot of collateral for using the UserGetLanguageObject, where I think it should be safe to accept that the User object's methods can be called.

It is not safe today because MW supports auto creation, language unstubbing, and Block/Language doing date-formatting based on wgUser global state. So long as two of these three exist, these errors will continue. And I'd say based on that, using this hook in this way is thus not supported by MW today.

But, the use case seems fair to me. I'd recommend working with AHT and/or PET to explain the need so that support for this can be added.

In T267445#6643651, @Krinkle wrote:

And I'd say based on that, using this hook in this way is thus not supported by MW today.

So in a hook which allows to override the language of an user, one cannot access even the method to determine whether the user is logged in or not to determine whether to override the language. That sounds like a bug to me.

But, the use case seems fair to me. I'd recommend working with AHT and/or PET to explain the need so that support for this can be added.

ULS needs to know whether the user is logged in or not to determine whether to override the user's interface language. Depending on the configuration, it will override the interface language based on a cookie or the Accept-Language request header, but only for logged out users.

I'll ask @Rileych to help coordinate.

@ARamirez_WMF @Naike (cc @Rileych)

Ticket name/link: UserGetLanguageObjectHook is unsafe: "User::loadFromSession called before the end of Setup.php"
What problem is this causing: Main issue is log spam at a rate of almost 100 messages per hour. To our knowledge this does not cause user facing issues, but complicates train deployments by adding noise to the logs.
Which team we need help from: Anti-Harassment and Platform
What we need the other team to do: We need to figure out a solution together to stop the log spam. The solution is not obvious, because it arises from the interaction of multiple different parts of code in MediaWiki core and the Universal Language Selector (ULS). Our opinion is that ULS’s use of the “UserGetLanguageObject” hook should be supported.
How urgent is this/timeline: end of April.
Language team POC: Niklas (@Nikerabbit)

AHaT will be creating a spike to look into this. We'll drag the spike into our next sprint (which starts in 2 weeks).

An updated stack trace, since the line numbers have shifted since the one in the ticket:

from /srv/mediawiki/php-1.36.0-wmf.30/includes/user/User.php(365)
#0 /srv/mediawiki/php-1.36.0-wmf.30/includes/user/User.php(2063): User->load()
#1 /srv/mediawiki/php-1.36.0-wmf.30/includes/user/User.php(3042): User->getId()
#2 /srv/mediawiki/php-1.36.0-wmf.30/includes/user/User.php(3060): User->isRegistered()
#3 /srv/mediawiki/php-1.36.0-wmf.30/extensions/UniversalLanguageSelector/includes/UniversalLanguageSelectorHooks.php(320): User->isAnon()
#4 /srv/mediawiki/php-1.36.0-wmf.30/includes/HookContainer/HookContainer.php(333): UniversalLanguageSelectorHooks::getLanguage(User, string, RequestContext)
#5 /srv/mediawiki/php-1.36.0-wmf.30/includes/HookContainer/HookContainer.php(140): MediaWiki\HookContainer\HookContainer->callLegacyHook(string, array, array, array)
#6 /srv/mediawiki/php-1.36.0-wmf.30/includes/HookContainer/HookRunner.php(4276): MediaWiki\HookContainer\HookContainer->run(string, array)
#7 /srv/mediawiki/php-1.36.0-wmf.30/includes/context/RequestContext.php(392): MediaWiki\HookContainer\HookRunner->onUserGetLanguageObject(User, string, RequestContext)
#8 /srv/mediawiki/php-1.36.0-wmf.30/includes/StubUserLang.php(59): RequestContext->getLanguage()
#9 /srv/mediawiki/php-1.36.0-wmf.30/includes/StubObject.php(179): StubUserLang->_newObject()
#10 /srv/mediawiki/php-1.36.0-wmf.30/includes/StubObject.php(119): StubObject->_unstub(string, integer)
#11 /srv/mediawiki/php-1.36.0-wmf.30/includes/StubObject.php(149): StubObject->_call(string, array)
#12 /srv/mediawiki/php-1.36.0-wmf.30/includes/user/User.php(2844): StubObject->__call(string, array)
#13 /srv/mediawiki/php-1.36.0-wmf.30/languages/Language.php(2235): User->getDatePreference()
#14 /srv/mediawiki/php-1.36.0-wmf.30/languages/Language.php(2341): Language->dateFormat(boolean)
#15 /srv/mediawiki/php-1.36.0-wmf.30/languages/Language.php(4699): Language->timeanddate(string, boolean)
#16 /srv/mediawiki/php-1.36.0-wmf.30/includes/block/BlockErrorFormatter.php(111): Language->formatExpiry(string)
#17 /srv/mediawiki/php-1.36.0-wmf.30/includes/block/BlockErrorFormatter.php(204): MediaWiki\Block\BlockErrorFormatter->getFormattedBlockErrorInfo(MediaWiki\Block\DatabaseBlock, User, LanguageEn)
#18 /srv/mediawiki/php-1.36.0-wmf.30/includes/block/BlockErrorFormatter.php(65): MediaWiki\Block\BlockErrorFormatter->getBlockErrorMessageParams(MediaWiki\Block\DatabaseBlock, User, LanguageEn, string)
#19 /srv/mediawiki/php-1.36.0-wmf.30/includes/auth/CheckBlocksSecondaryAuthenticationProvider.php(92): MediaWiki\Block\BlockErrorFormatter->getMessage(MediaWiki\Block\DatabaseBlock, User, LanguageEn, string)
#20 /srv/mediawiki/php-1.36.0-wmf.30/includes/auth/AuthManager.php(1712): MediaWiki\Auth\CheckBlocksSecondaryAuthenticationProvider->testUserForCreation(User, string, array)
#21 /srv/mediawiki/php-1.36.0-wmf.30/includes/Setup.php(823): MediaWiki\Auth\AuthManager->autoCreateUser(User, string, boolean)
#22 /srv/mediawiki/php-1.36.0-wmf.30/includes/WebStart.php(89): require_once(string)
#23 /srv/mediawiki/php-1.36.0-wmf.30/api.php(43): require(string)
#24 /srv/mediawiki/w/api.php(3): require(string)
#25 {main}

Also, logstash link for the query to find this specific error path: https://logstash.wikimedia.org/goto/8fc2fed8fa16825c2e33762e978671db (just a search for normalized_message:"User::loadFromSession called before the end of Setup.php" AND exception.trace:UniversalLanguageSelectorHooks)

Change 665188 had a related patch set uploaded (by Umherirrender; owner: Umherirrender):
[mediawiki/core@master] Avoid unstubbing user in BlockErrorFormatter::getFormattedBlockErrorInfo

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

Change 665188 merged by jenkins-bot:
[mediawiki/core@master] Avoid unstubbing user in BlockErrorFormatter::getFormattedBlockErrorInfo

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

I haven't been able to recreate the circumstances to reproduce this (can anyone advise me how?), but the patch from @Umherirrender looks as though it should solve the problem.

As previous comments say, the problem appears to be that Language::formatExpiry tries to access the language preferences for the global user (via Language::dateFormat), rather than for the user passed to BlockErrorFormatter::getFormattedBlockErrorInfo, before the global user is initialised.

If I've understood that correctly, then the patch should solve the problem, since it allows the correct user to be passed into Language::formatExpiry.

Either way, we should go ahead with the patch, since it should be possible to pass the correct user to Language::formatExpiry, and one purpose of introducing the BlockErrorFormatter was to avoid accessing the global request context.

If this doesn't solve the issue we may need some advice from someone with a better knowledge of setup.

Yes, it is hard to trigger the error on local wiki. My fix is inspired by the stack trace where the use of global user is shown and that has make problems before when used too early.

The patch solves the problem or it gets a complet different stack trace. It is also possible that other places showing up due to use of the global user in early state.

Let's wait for the next train to get feedback from the logs

In T267445#6864955, @Umherirrender wrote:

Let's wait for the next train to get feedback from the logs

I'll keep this in the QA column for now, until we have some evidence the error is no longer happening.

I couldn't reproduce this bug either.

I did some regression testing of the modified BlockErrorFormatter::getFormattedBlockErrorInfo and Language::formatExpiry functions. The expiry messages look fine on pages like Special:ProtectedTitles, Special:BlockList and in the block message.

Test environments:

• https://en.wikipedia.beta.wmflabs.org MediaWiki 1.36.0-alpha (245bb62) 10:09, 1 March 2021
• https://en.wikisource.beta.wmflabs.org MediaWiki 1.36.0-alpha (245bb62) 10:09, 1 March 2021
• local vagrant MediaWiki 1.36.0-alpha (b235ee8)

I would assume a local ip block which blocks the account creation and a global user without a local account trying to autocreate an account on the first view of that wiki. It is also possible that its a direct link to the edit form with an autoblock/cookieblock for the global user without a local account on that wiki, which also trigger an autocreate.

But that is only a guess, not proved.

In T267445#6876150, @Umherirrender wrote:

I would assume a local ip block which blocks the account creation and a global user without a local account trying to autocreate an account on the first view of that wiki. It is also possible that its a direct link to the edit form with an autoblock/cookieblock for the global user without a local account on that wiki, which also trigger an autocreate.

I tried that when I was testing, but couldn't reproduce.