Maniphest T203283

Special:CreateAccount causes ApiValidatePassword to log a DBPerformance warning from CentralAuth
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Assigned To

None

Authored By

	Krinkle
	Aug 31 2018, 9:21 PM

Description

Error

At 120,00 log entries in 7 days (~20 to 100x per minute) with this description, this is one of the most frequent and noisiest logs in the system right now.

https://logstash.wikimedia.org/goto/84ab7b3f6e1019171a0e10ebcd6edad4

stack trace

Expectation (masterConns <= 0) by ApiMain::setRequestExpectations not met (actual: 1):
[connect to 10.64.48.15 (centralauth)]
#0 /srv/mediawiki/php-1.32.0-wmf.19/includes/libs/rdbms/TransactionProfiler.php(165): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.32.0-wmf.19/includes/libs/rdbms/loadbalancer/LoadBalancer.php(776): Wikimedia\Rdbms\TransactionProfiler->recordConnection()
#2 /srv/mediawiki/php-1.32.0-wmf.19/includes/libs/rdbms/loadbalancer/LoadBalancer.php(850): Wikimedia\Rdbms\LoadBalancer->getConnection()
#3 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthUtils.php(57): Wikimedia\Rdbms\LoadBalancer->getConnectionRef()
#4 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthUser.php(224): CentralAuthUtils::getCentralDB()
#5 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthUser.php(433): CentralAuthUser->getSafeReadDB()
#6 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthUser.php(376): CentralAuthUser->loadFromDatabase()
#7 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthUser.php(597): CentralAuthUser->loadState()
#8 /srv/mediawiki/php-1.32.0-wmf.19/extensions/CentralAuth/includes/CentralAuthHooks.php(813): CentralAuthUser->isAttached()
#9 /srv/mediawiki/php-1.32.0-wmf.19/includes/Hooks.php(174): CentralAuthHooks::onUserSetEmail()
#10 /srv/mediawiki/php-1.32.0-wmf.19/includes/Hooks.php(202): Hooks::callHook()
#11 /srv/mediawiki/php-1.32.0-wmf.19/includes/user/User.php(3059): Hooks::run()
#12 /srv/mediawiki/php-1.32.0-wmf.19/includes/api/ApiValidatePassword.php(30): User->setEmail()
#13 /srv/mediawiki/php-1.32.0-wmf.19/includes/api/ApiMain.php(1587): ApiValidatePassword->execute()
#14 /srv/mediawiki/php-1.32.0-wmf.19/includes/api/ApiMain.php(531): ApiMain->executeAction()
#15 /srv/mediawiki/php-1.32.0-wmf.19/includes/api/ApiMain.php(502): ApiMain->executeActionWithErrorHandling()
#16 /srv/mediawiki/php-1.32.0-wmf.19/api.php(87): ApiMain->execute()
#17 /srv/mediawiki/w/api.php(3): include()
#18 {main}

Notes

The above sample:

exception_id: W4mv6QpAMEYAAGx8920AAACG
POST request to /w/api.php
Domain: en.wikibooks.org
HTTP referer: https://en.wikibooks.org/w/index.php?title=Special:CreateAccount&returnto=Main+Page

It seems to be like this warning is a false negative, given that a master connection during a POST request would normally be acceptable.

Also, it seems this error was previously reported in June 2017 and seemingly fixed:

In T92357#3334646, @gerritbot wrote:

Change 348658 merged by jenkins-bot:
[mediawiki/extensions/CentralAuth@master] Avoid triggering master queries in ApiValidatePassword

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

Related Objects

Mentioned Here: rECAU0416f276fd67: Avoid triggering master queries in ApiValidatePassword
T92357: Fix database master queries from HTTP GET/HEAD before active-active multi-dc

Event Timeline

Krinkle created this task.Aug 31 2018, 9:21 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptAug 31 2018, 9:21 PM

Krinkle updated the task description. (Show Details)Aug 31 2018, 9:24 PM

Krinkle added a project: Core-Platform-Team-Old.

Krinkle updated the task description. (Show Details)

Krinkle moved this task from Untriaged to Dec2019/1.35.wmf.10+ on the Wikimedia-production-error board.Sep 1 2018, 1:25 AM

Anomie moved this task from Unsorted to Non-core-API stuff on the MediaWiki-Action-API board.Sep 4 2018, 1:12 PM

It looks like CentralAuthHooks::onUserSetEmail() may need the same treatment that was given to CentralAuthHooks::onUserSetEmailAuthenticationTimestamp() in rECAU0416f276fd67: Avoid triggering master queries in ApiValidatePassword.

I don't see any stack traces in that patch or in the linked task, so I'm not sure why 0416f27 did onUserSetEmailAuthenticationTimestamp rather than onUserSetEmail in the first place.

CCicalese_WMF moved this task from Inbox to CPT TEC1 Backlog on the Core-Platform-Team-Old board.Sep 5 2018, 1:20 AM

Krinkle moved this task from Dec2019/1.35.wmf.10+ to Older on the Wikimedia-production-error board.Sep 5 2018, 2:42 AM

CCicalese_WMF added a project: Platform Team Legacy (Next).Oct 1 2018, 11:23 PM

CCicalese_WMF edited projects, added Core Platform Team Goals (Security, stability, performance and scalability (TEC1)); removed Core-Platform-Team-Old.Oct 2 2018, 12:06 AM

CCicalese_WMF edited projects, added Platform Engineering (Needs Cleaning - Security, stability, performance, and scalability (TEC1)); removed Core Platform Team Goals (Security, stability, performance and scalability (TEC1)).Oct 2 2018, 2:24 AM

WDoranWMF removed a project: Platform Team Legacy (Next).Jul 26 2019, 5:45 PM

• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:08 PM

Tagging performance team to look at this.

Restricted Application added a project: Platform Engineering. · View Herald TranscriptSep 3 2019, 6:48 PM

Krinkle updated the task description. (Show Details)Sep 3 2019, 8:07 PM

No longer seen in the past 30 days. Presumed resolved.

Aklapper removed a subscriber: Anomie.Oct 16 2020, 5:38 PM

Special:CreateAccount causes ApiValidatePassword to log a DBPerformance warning from CentralAuthClosed, ResolvedPublicPRODUCTION ERRORActions