Page MenuHomePhabricator
Create Task
Maniphest T140156

CentralAuth 'Invalid key type: NULL'
Closed, ResolvedPublic
Actions

Description

2016-07-12 19:49:17 [V4VJugpAIDEAAGRzeuoAAABN] mw1306 mediawikiwiki 1.28.0-wmf.8 Echo DEBUG: Exception when fetching CentralAuth token: wiki: mediawikiwiki, userName: Jtnayem147, userId: 684
7810, centralId: 47182055, exception: exception 'InvalidArgumentException' with message 'Invalid key type: NULL' in /srv/mediawiki/php-1.28.0-wmf.8/includes/utils/MWCryptHash.php:110
Stack trace:
#0 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CentralAuthUser.php(607): MWCryptHash::hmac()
#1 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/api/ApiCentralAuthToken.php(62): CentralAuthUser->getAuthToken()
#2 /srv/mediawiki/php-1.28.0-wmf.8/includes/api/ApiMain.php(1373): ApiCentralAuthToken->execute()
#3 /srv/mediawiki/php-1.28.0-wmf.8/includes/api/ApiMain.php(438): ApiMain->executeAction()
#4 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(57): ApiMain->execute()
#5 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(112): EchoForeignWikiRequest->getCentralAuthToken()
#6 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(92): EchoForeignWikiRequest->getQueryParams()
#7 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(29): EchoForeignWikiRequest->getRequestParams()
#8 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(709): EchoForeignWikiRequest->execute()
#9 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(770): MWEchoNotifUser->getForeignData()
#10 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(496): MWEchoNotifUser->getForeignTimestamp()
#11 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/Hooks.php(1150): MWEchoNotifUser->resetNotificationCount()
#12 /srv/mediawiki/php-1.28.0-wmf.8/includes/Hooks.php(195): EchoHooks::onUserSaveSettings()
#13 /srv/mediawiki/php-1.28.0-wmf.8/includes/user/User.php(3952): Hooks::run()
#14 /srv/mediawiki/php-1.28.0-wmf.8/includes/auth/AuthManager.php(1678): User->saveSettings()
#15 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CentralAuthUtils.php(141): MediaWiki\Auth\AuthManager->autoCreateUser()
#16 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CreateLocalAccountJob.php(56): CentralAuthUtils::autoCreateUser()
#17 /srv/mediawiki/php-1.28.0-wmf.8/includes/jobqueue/JobRunner.php(265): CentralAuthCreateLocalAccountJob->run()
#18 /srv/mediawiki/php-1.28.0-wmf.8/includes/jobqueue/JobRunner.php(179): JobRunner->executeJob()
#19 /srv/mediawiki/rpc/RunJobs.php(47): JobRunner->run()
#20 {main} {"wiki":"mediawikiwiki","userName":"Jtnayem147","userId":6847810,"centralId":47182055} 
[Exception InvalidArgumentException] (/srv/mediawiki/php-1.28.0-wmf.8/includes/utils/MWCryptHash.php:110) Invalid key type: NULL
  #0 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CentralAuthUser.php(607): MWCryptHash::hmac(string, NULL, boolean)
  #1 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/api/ApiCentralAuthToken.php(62): CentralAuthUser->getAuthToken()
  #2 /srv/mediawiki/php-1.28.0-wmf.8/includes/api/ApiMain.php(1373): ApiCentralAuthToken->execute()
  #3 /srv/mediawiki/php-1.28.0-wmf.8/includes/api/ApiMain.php(438): ApiMain->executeAction()
  #4 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(57): ApiMain->execute()
  #5 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(112): EchoForeignWikiRequest->getCentralAuthToken(User)
  #6 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(92): EchoForeignWikiRequest->getQueryParams(string)
  #7 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/ForeignWikiRequest.php(29): EchoForeignWikiRequest->getRequestParams()
  #8 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(709): EchoForeignWikiRequest->execute()
  #9 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(770): MWEchoNotifUser->getForeignData()
  #10 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/includes/NotifUser.php(496): MWEchoNotifUser->getForeignTimestamp(string)
  #11 /srv/mediawiki/php-1.28.0-wmf.8/extensions/Echo/Hooks.php(1150): MWEchoNotifUser->resetNotificationCount()
  #12 /srv/mediawiki/php-1.28.0-wmf.8/includes/Hooks.php(195): EchoHooks::onUserSaveSettings(User)
  #13 /srv/mediawiki/php-1.28.0-wmf.8/includes/user/User.php(3952): Hooks::run(string, array)
  #14 /srv/mediawiki/php-1.28.0-wmf.8/includes/auth/AuthManager.php(1678): User->saveSettings()
  #15 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CentralAuthUtils.php(141): MediaWiki\Auth\AuthManager->autoCreateUser(User, string, boolean)
  #16 /srv/mediawiki/php-1.28.0-wmf.8/extensions/CentralAuth/includes/CreateLocalAccountJob.php(56): CentralAuthUtils::autoCreateUser(User)
  #17 /srv/mediawiki/php-1.28.0-wmf.8/includes/jobqueue/JobRunner.php(265): CentralAuthCreateLocalAccountJob->run()
  #18 /srv/mediawiki/php-1.28.0-wmf.8/includes/jobqueue/JobRunner.php(179): JobRunner->executeJob(CentralAuthCreateLocalAccountJob, BufferingStatsdDataFactory, integer)
  #19 /srv/mediawiki/rpc/RunJobs.php(47): JobRunner->run(array)
  #20 {main}

@Anomie said, "I think that one happens after a CAS conflict in updating the global user when CentralAuthUser->getAuthToken() calls CentralAuthUser->resetAuthToken()."

Related Objects

Event Timeline

• Mattflaschen-WMF created this task.Jul 12 2016, 8:07 PM
Restricted Application added subscribers: Zppix, Aklapper. · View Herald TranscriptJul 12 2016, 8:07 PM
• Mattflaschen-WMF mentioned this in T140144: Echo triggering CentralAuth "Can only obtain a centralauthtoken when using CentralAuth sessions" error.Jul 12 2016, 10:43 PM
greg subscribed.Jul 14 2016, 6:24 AM

@Anomie @Mattflaschen-WMF I asked over in T140144 but: do we have a guess of how prevalent this is in production?

Anomie added a comment.Jul 14 2016, 4:41 PM

https://gerrit.wikimedia.org/r/#/c/298963/ should help with this by reducing (and probably entirely eliminating for accounts created after it's merged) the cases in which CentralAuthUser->getAuthToken() needs to call CentralAuthUser->resetAuthToken().

• Mattflaschen-WMF added a comment.EditedJul 14 2016, 7:34 PM

It's very frequent recently. Seems like it was usually 0, 1, 2 before 2016-06-21, then went into the double-digits, then after Echo started using centralauthtoken, it spiked.

P3448 Invalid key type: NULL
1mattflaschen@fluorine:~$ zgrep -c -E "CentralAuthUser.*MWCryptHash::hmac\(string, NULL" /a/mw-log/archive/exception.log* /a/mw-log/exception.log
2/a/mw-log/archive/exception.log-20160415.gz:6
3/a/mw-log/archive/exception.log-20160416.gz:0
4/a/mw-log/archive/exception.log-20160417.gz:0
5/a/mw-log/archive/exception.log-20160418.gz:0
6/a/mw-log/archive/exception.log-20160419.gz:0
7/a/mw-log/archive/exception.log-20160420.gz:0
8/a/mw-log/archive/exception.log-20160421.gz:0
9/a/mw-log/archive/exception.log-20160422.gz:1
10/a/mw-log/archive/exception.log-20160423.gz:0
11/a/mw-log/archive/exception.log-20160424.gz:0
12/a/mw-log/archive/exception.log-20160425.gz:0
13/a/mw-log/archive/exception.log-20160426.gz:1
14/a/mw-log/archive/exception.log-20160427.gz:0
15/a/mw-log/archive/exception.log-20160428.gz:2
16/a/mw-log/archive/exception.log-20160429.gz:13
17/a/mw-log/archive/exception.log-20160430.gz:18
18/a/mw-log/archive/exception.log-20160501.gz:4
19/a/mw-log/archive/exception.log-20160502.gz:8
20/a/mw-log/archive/exception.log-20160503.gz:6
21/a/mw-log/archive/exception.log-20160504.gz:14
22/a/mw-log/archive/exception.log-20160505.gz:8
23/a/mw-log/archive/exception.log-20160506.gz:10
24/a/mw-log/archive/exception.log-20160507.gz:0
25/a/mw-log/archive/exception.log-20160508.gz:0
26/a/mw-log/archive/exception.log-20160509.gz:0
27/a/mw-log/archive/exception.log-20160510.gz:0
28/a/mw-log/archive/exception.log-20160511.gz:0
29/a/mw-log/archive/exception.log-20160512.gz:0
30/a/mw-log/archive/exception.log-20160513.gz:1
31/a/mw-log/archive/exception.log-20160514.gz:0
32/a/mw-log/archive/exception.log-20160515.gz:0
33/a/mw-log/archive/exception.log-20160516.gz:0
34/a/mw-log/archive/exception.log-20160517.gz:0
35/a/mw-log/archive/exception.log-20160518.gz:0
36/a/mw-log/archive/exception.log-20160519.gz:0
37/a/mw-log/archive/exception.log-20160520.gz:0
38/a/mw-log/archive/exception.log-20160521.gz:0
39/a/mw-log/archive/exception.log-20160522.gz:0
40/a/mw-log/archive/exception.log-20160523.gz:1
41/a/mw-log/archive/exception.log-20160524.gz:0
42/a/mw-log/archive/exception.log-20160525.gz:0
43/a/mw-log/archive/exception.log-20160526.gz:0
44/a/mw-log/archive/exception.log-20160527.gz:2
45/a/mw-log/archive/exception.log-20160528.gz:0
46/a/mw-log/archive/exception.log-20160529.gz:9
47/a/mw-log/archive/exception.log-20160530.gz:1
48/a/mw-log/archive/exception.log-20160531.gz:0
49/a/mw-log/archive/exception.log-20160601.gz:0
50/a/mw-log/archive/exception.log-20160602.gz:0
51/a/mw-log/archive/exception.log-20160603.gz:2
52/a/mw-log/archive/exception.log-20160604.gz:0
53/a/mw-log/archive/exception.log-20160605.gz:6
54/a/mw-log/archive/exception.log-20160606.gz:0
55/a/mw-log/archive/exception.log-20160607.gz:0
56/a/mw-log/archive/exception.log-20160608.gz:1
57/a/mw-log/archive/exception.log-20160609.gz:0
58/a/mw-log/archive/exception.log-20160610.gz:0
59/a/mw-log/archive/exception.log-20160611.gz:1
60/a/mw-log/archive/exception.log-20160612.gz:1
61/a/mw-log/archive/exception.log-20160613.gz:0
62/a/mw-log/archive/exception.log-20160614.gz:1
63/a/mw-log/archive/exception.log-20160615.gz:0
64/a/mw-log/archive/exception.log-20160616.gz:1
65/a/mw-log/archive/exception.log-20160617.gz:0
66/a/mw-log/archive/exception.log-20160618.gz:0
67/a/mw-log/archive/exception.log-20160619.gz:0
68/a/mw-log/archive/exception.log-20160620.gz:0
69/a/mw-log/archive/exception.log-20160621.gz:30
70/a/mw-log/archive/exception.log-20160622.gz:49
71/a/mw-log/archive/exception.log-20160623.gz:19
72/a/mw-log/archive/exception.log-20160624.gz:24
73/a/mw-log/archive/exception.log-20160625.gz:18
74/a/mw-log/archive/exception.log-20160626.gz:98
75/a/mw-log/archive/exception.log-20160627.gz:30
76/a/mw-log/archive/exception.log-20160628.gz:43
77/a/mw-log/archive/exception.log-20160629.gz:45
78/a/mw-log/archive/exception.log-20160630.gz:84
79/a/mw-log/archive/exception.log-20160701.gz:15
80/a/mw-log/archive/exception.log-20160702.gz:18
81/a/mw-log/archive/exception.log-20160703.gz:77
82/a/mw-log/archive/exception.log-20160704.gz:17
83/a/mw-log/archive/exception.log-20160705.gz:100
84/a/mw-log/archive/exception.log-20160706.gz:224
85/a/mw-log/archive/exception.log-20160707.gz:410
86/a/mw-log/archive/exception.log-20160708.gz:315
87/a/mw-log/archive/exception.log-20160709.gz:313
88/a/mw-log/archive/exception.log-20160710.gz:268
89/a/mw-log/archive/exception.log-20160711.gz:307
90/a/mw-log/archive/exception.log-20160712.gz:393
91/a/mw-log/archive/exception.log-20160713.gz:488
92/a/mw-log/archive/exception.log-20160714.gz:1164
93/a/mw-log/exception.log:602

It looks like Echo is exposing this issue (like the trace in my report above), but it should not be causing user-visible exceptions, just an inability for Echo to get a CentralAuth token (and thus get accurate counts). As shown in the trace (this is from logging the exception), we now catch this exception.

Aklapper added a comment.Jul 27 2016, 10:09 AM

If this is still very frequent, who should this task get assigned to and what should be its priority?

Anomie closed this task as Resolved.Jul 27 2016, 2:39 PM
Anomie claimed this task.

The last occurrence logged was 2016-07-21 14:30:40. The patch mentioned earlier seems to have worked.

greg added a project: Wikimedia-Incident.Jul 27 2016, 10:36 PM
MarcoAurelio moved this task from Backlog to Done on the MediaWiki-extensions-CentralAuth board.Dec 15 2016, 4:09 PM
Aklapper removed subscribers: • Mattflaschen-WMF, Anomie.Oct 16 2020, 5:39 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