Last modified: 2014-08-27 01:27:55 UTC

Wikimedia Bugzilla is closed!

Wikimedia migrated from Bugzilla to Phabricator. Bug reports are handled in Wikimedia Phabricator.
This static website is read-only and for historical purposes. It is not possible to log in and except for displaying bug reports and their history, links might be broken. See T72038, the corresponding Phabricator task for complete and up-to-date bug report information.
Bug 70038 - User::loadPasswords 400% spike on wmf db masters
User::loadPasswords 400% spike on wmf db masters
Status: RESOLVED FIXED
Product: MediaWiki
Classification: Unclassified
Database (Other open bugs)
1.24rc
All All
: High major (vote)
: ---
Assigned To: Nobody - You can work on this!
:
Depends on: 69381
Blocks:
  Show dependency treegraph
 
Reported: 2014-08-26 13:56 UTC by Sean Pringle
Modified: 2014-08-27 01:27 UTC (History)
10 users (show)

See Also:
Web browser: ---
Mobile Platform: ---
Assignee Huggle Beta Tester: ---


Attachments

Description Sean Pringle 2014-08-26 13:56:11 UTC
Around 2014-08-21 20:00:00 all WMF master database servers experienced a permanent increase in read traffic, between 50% and 400%. Write-load has not changed significantly.

1.24wmf17 rolled out to wikipedias around 2014-08-21 19:55:00.

There is an obvious outlier in query logs SELECT /* User::loadPasswords ... */, which, on masters with many wikis/users, is now executing more frequently than all other queries combined. Last week it hardly registered.

Possible culprit is https://gerrit.wikimedia.org/r/#/c/151649/ , the bug 69102 fix. Can we use a slave for such non-trivial read traffic?
Comment 1 Sean Pringle 2014-08-26 14:09:59 UTC
Worth noting that SELECT /* User::loadFromDatabase ... */ has been in the top 10 queries on masters for a while, but it is barely 1/10th the volume of SELECT /* User::loadPasswords ... */.

Passwords being reloaded multiple times per request, perhaps?
Comment 2 Jesús Martínez Novo (Ciencia Al Poder) 2014-08-26 14:37:47 UTC
I doubt Gerrit change #151649 is the cause, since it added $this->loadPasswords(); in setPassword and setNewpasswords, which should be called only when a user resets or sets a new password, unless we have many paranoid users resetting their passwords every hour or so :P

Adding Parent5446 as cc since that was his changeset
Comment 3 Sean Pringle 2014-08-26 14:53:32 UTC
Yeah, I see, that does sound odd.

Possibly https://gerrit.wikimedia.org/r/#/c/151569/
Comment 4 Kunal Mehta (Legoktm) 2014-08-26 14:55:40 UTC
(In reply to Sean Pringle from comment #3)

> Possibly https://gerrit.wikimedia.org/r/#/c/151569/

Ugh, I wonder if this is due to bug 69381. That might explain it...
Comment 5 Jesús Martínez Novo (Ciencia Al Poder) 2014-08-26 15:13:00 UTC
Gerrit change #149658 can be related: Changed password default to PBKDF2. Bug 28419

From release notes: The default password type for MediaWiki has been changed from MD5 to PBKDF2. Password hashes will automatically be updated as users log in.

But on the other hand, it has been disabled on WMF by Gerrit change #153850, by making MD5 the current hash, so it shouldn't be affected, unless:

A) the change to use MD5 on WMF isn't being applied somehow.

B) the code is loading the password anyway to check if it's an old MD5 hash, even if it then realizes it shouldn't be changed.
Comment 6 Florian 2014-08-26 15:22:39 UTC
> the code is loading the password anyway to check if it's an old MD5 hash, even if it then realizes it shouldn't be changed.

Hmm, but LocalSettings (CommonSettings) overrides DefaultSettings settings completly, so for the code nothing has changed and if there wasn't a change in this routine we don't had this problem just now :/

I think like legoktm that this comes from the problem described in bug 69381 :/
Comment 7 Sam Reed (reedy) 2014-08-26 16:01:31 UTC
(In reply to Jesús Martínez Novo (Ciencia Al Poder) from comment #5)
> A) the change to use MD5 on WMF isn't being applied somehow.

reedy@tin:~$ mwscript eval.php mediawikiwiki
> var_dump( $wgPasswordDefault );
string(1) "B"

> reedy@tin:~$ mwscript eval.php enwiki
> var_dump( $wgPasswordDefault );
string(1) "B"
Comment 8 Chris Steipp 2014-08-26 16:14:13 UTC
Any users with type :A: passwords will get their hash updated to type :B:, but that should be a pretty small segment of users. I can confirm normal users with type :B: passwords aren't getting reset on login.

Oh wow, I missed that MassMessage was doing that in the UserGetRights hook. That hook can be called something like 10 times in a single page view, if you hit the wrong page.

If Sean can confirm that the user being querried is always the same username ($wgMassMessageAccountUsername), then that will confirm it. If it's the logged in user's name, then we have another problem.
Comment 9 Sean Pringle 2014-08-26 16:57:37 UTC
Yep, confirmed.

Looking only at enwiki sampled traffic, user 20181147 'MediaWiki message delivery' accounts for 98.6% of the User::loadPasswords queries.
Comment 10 Kunal Mehta (Legoktm) 2014-08-26 17:06:13 UTC
The fix for bug 69381 will go out in today afternoon's SWAT window.
Comment 11 Kunal Mehta (Legoktm) 2014-08-26 23:05:48 UTC
It actually went out around 11 UTC. Sean, could you check if there are less queries now?
Comment 12 Sean Pringle 2014-08-27 01:27:55 UTC
Load returned to normal immediately when Reedy did: 

18:53 logmsgbot: reedy Synchronized php-1.24wmf18/extensions/MassMessage: (no message) (duration: 00m 14s)

Not 11 UTC, but presumably included the relevant fix.

Thanks everyone, for such a prompt response on this bug!

Note You need to log in before you can comment on or make changes to this bug.


Navigation
Links