Page MenuHomePhabricator
Create Task
Maniphest T101806

Investigate origin of ResourceLoader requests for private module 'user.tokens' and 'user.options'
Closed, ResolvedPublic
Actions

Description

ResourceLoader::respond: request for private module 'user.tokens' denied
ResourceLoader::respond: request for private module 'user.options' denied

About half of these are from third-party referrers and simply hit load.php with modules we no longer support publicly.

However a fair amount actually have production referrers such as:
http://en.wikipedia.org/wiki/List_of_Presidents_of_the_Philippines
https://es.m.wikipedia.org/wiki/Dimebag_Darrell

These private modules are embedded in OutputPage before any module load is triggered. So these shouldn't be possible. Investigate the origin and context of these requests.

Due to the response handling, these requests end up interrupting the dependency state machine. So whatever module ended up needing these will not executing due to missing dependencies. Would likely fail in an incomplete user interface or user-facing error of some kind.

Details

SubjectRepoBranchLines +/-
mw.loader: Omit private modules from the request queuemediawiki/coremaster+9 -0
Log a summary of scripts on the page with ModuleLoadFailuremediawiki/extensions/WikimediaEventsmaster+23 -5
Log 'resourceloader.forbidden' events from readersmediawiki/extensions/WikimediaEventsmaster+8 -4
Log 'resourceloader.forbidden' events from readersmediawiki/extensions/WikimediaEventswmf/1.26wmf9+8 -4
Log 'resourceloader.forbidden' events with ModuleLoadFailure schemamediawiki/extensions/WikimediaEventswmf/1.26wmf9+28 -0
Log 'resourceloader.forbidden' events with ModuleLoadFailure schemamediawiki/extensions/WikimediaEventsmaster+28 -0
[WMF] resourceloader: Add logging for T101806 private modulesmediawiki/corewmf/1.26wmf9+12 -0
[WMF] resourceloader: Add logging for T101806 private modulesmediawiki/corewmf/1.26wmf8+12 -0
Customize query in gerrit

Related Objects

Event Timeline

Krinkle created this task.Jun 9 2015, 3:19 AM
Krinkle raised the priority of this task from to High.
Krinkle updated the task description. (Show Details)
Krinkle added projects: MediaWiki-ResourceLoader, Wikimedia-production-error.
Krinkle subscribed.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 9 2015, 3:19 AM
gerritbot subscribed.Jun 9 2015, 3:21 AM

Change 216905 had a related patch set uploaded (by Krinkle):
[WMF] resourceloader: Add logging for T101806 private modules

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

gerritbot added a project: Patch-For-Review.Jun 9 2015, 3:21 AM

Change 216905 had a related patch set uploaded (by Krinkle):
[WMF] resourceloader: Add logging for T101806 private modules

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

gerritbot added a comment.Jun 9 2015, 4:26 PM

Change 217004 had a related patch set uploaded (by Krinkle):
Log 'resourceloader.forbidden' events with ModuleLoadFailure schema

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

gerritbot added a comment.Jun 9 2015, 4:44 PM

Change 217010 had a related patch set uploaded (by Krinkle):
[WMF] resourceloader: Add logging for T101806 private modules

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

gerritbot added a comment.Jun 9 2015, 4:44 PM

Change 216905 abandoned by Krinkle:
[WMF] resourceloader: Add logging for T101806 private modules

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

Krinkle claimed this task.Jun 9 2015, 4:50 PM
Krinkle moved this task from Inbox to Assigned on the MediaWiki-ResourceLoader board.
Krinkle set Security to None.
gerritbot added a comment.Jun 9 2015, 10:56 PM

Change 217184 had a related patch set uploaded (by Krinkle):
[WMF] resourceloader: Add logging for T101806 private modules

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

gerritbot added a comment.Jun 9 2015, 11:11 PM

Change 217010 merged by jenkins-bot:
[WMF] resourceloader: Add logging for T101806 private modules

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

gerritbot added a comment.Jun 9 2015, 11:11 PM

Change 217184 merged by jenkins-bot:
[WMF] resourceloader: Add logging for T101806 private modules

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

Krinkle mentioned this in rMW500c37be988b: [WMF] resourceloader: Add logging for T101806 private modules.Jun 9 2015, 11:11 PM
Catrope mentioned this in rMWa0b9c8afafcb: [WMF] resourceloader: Add logging for T101806 private modules.Jun 9 2015, 11:12 PM
He7d3r subscribed.Jun 10 2015, 1:31 AM
Jdforrester-WMF added a project: WMF-deploy-2015-05-27_(1.26wmf8).Jun 10 2015, 2:13 AM
Jdforrester-WMF added a project: WMF-deploy-2015-06-09_(1.26wmf9).
gerritbot added a comment.Jun 10 2015, 8:36 PM

Change 217004 merged by Ori.livneh:
Log 'resourceloader.forbidden' events with ModuleLoadFailure schema

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

Krinkle mentioned this in rEWMVf0625fe7d2a9: Log 'resourceloader.forbidden' events with ModuleLoadFailure schema.Jun 10 2015, 8:36 PM
Krinkle mentioned this in rMEXTbeae6465387d: Updated mediawiki/extensions Project: mediawiki/extensions/WikimediaEvents….
• Forrestbot added a project: WMF-deploy-2015-06-16_(1.26wmf10).Jun 10 2015, 9:00 PM
• Forrestbot subscribed.
hashar moved this task from Untriaged to Jan 2019 / 1.33.wmf13–14 on the Wikimedia-production-error board.Jun 11 2015, 11:03 AM
hashar moved this task from Jan 2019 / 1.33.wmf13–14 to Mar 2019 / 1.33wmf20-23 on the Wikimedia-production-error board.
Krinkle removed projects: WMF-deploy-2015-06-16_(1.26wmf10), WMF-deploy-2015-06-09_(1.26wmf9), WMF-deploy-2015-05-27_(1.26wmf8), Patch-For-Review.Jun 11 2015, 4:07 PM
Krinkle removed subscribers: • Forrestbot, gerritbot.
• demon moved this task from Mar 2019 / 1.33wmf20-23 to Jan 2019 / 1.33.wmf13–14 on the Wikimedia-production-error board.Jun 11 2015, 4:09 PM
gerritbot added a comment.Jun 11 2015, 4:14 PM

Change 217535 had a related patch set uploaded (by Krinkle):
Log 'resourceloader.forbidden' events with ModuleLoadFailure schema

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

gerritbot added a project: Patch-For-Review.Jun 11 2015, 4:14 PM
• Forrestbot added a project: WMF-deploy-2015-06-16_(1.26wmf10).Jun 11 2015, 5:02 PM
gerritbot added a comment.Jun 11 2015, 6:31 PM

Change 217535 merged by jenkins-bot:
Log 'resourceloader.forbidden' events with ModuleLoadFailure schema

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

Krinkle mentioned this in rEWMV04989ce5c5bb: Log 'resourceloader.forbidden' events with ModuleLoadFailure schema.Jun 11 2015, 6:31 PM
• Forrestbot added a project: WMF-deploy-2015-06-09_(1.26wmf9).Jun 13 2015, 12:17 AM
Restricted Application added a subscriber: Mjbmr. · View Herald TranscriptJun 13 2015, 12:17 AM
gerritbot added a comment.Jun 13 2015, 4:45 PM

Change 218016 had a related patch set uploaded (by Krinkle):
Log 'resourceloader.forbidden' events from readers

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

gerritbot added a comment.Jun 13 2015, 4:46 PM

Change 218017 had a related patch set uploaded (by Krinkle):
Log 'resourceloader.forbidden' events from readers

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

gerritbot added a comment.Jun 13 2015, 4:46 PM

Change 218017 merged by jenkins-bot:
Log 'resourceloader.forbidden' events from readers

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

Krinkle mentioned this in rEWMV62eb013649ac: Log 'resourceloader.forbidden' events from readers.Jun 13 2015, 4:47 PM
Krinkle added a comment.EditedJun 15 2015, 1:47 PM

The log events captured server-side and sent to logstash only contain HTTP referer as context. The above patch uses client-side tracking in mw.loader to send events to EventLogging. Here are the results from hour period last Saturday evening.

There was a 6 hour window before this during which only logged-in users were tracked but not a single event was logged.

I aggregated the results manually.

eventlogging.filter(schema='ModuleLoadFailure')

Source:
- logged-in users (unsampled)
- logged-out users (1 in 100 page loads)

Start: 1434215736  Sat Jun 13 2015 18:15:36 GMT+0100 (BST)
End:   1434236726  Sun Jun 14 2015 00:05:26 GMT+0100 (BST)

hits: 62

users:
- anon (62)
- logged-in (0)

webHost:
     42 u'en.m.wikipedia.org',
     12 u'ru.m.wikipedia.org',
      4 u'bn.m.wikipedia.org',
      2 u'id.m.wikipedia.org',
      2 u'ar.m.wikipedia.org',

module:
# private module being requested despite being embedded in HTML
- u'user.options' (31)
- u'user.tokens' (31)

request:
# other modules in the same batch that have 'module' as a dependency.
- u'mediawiki.user' (62)

recvFrom:
- cp*.esams.wmnet (46)
- cp*.eqiad.wmnet (16)

userAgent:
- Linux (62)
- Android (62)
      2 Android 2.2.2;
      2 Android 2.2;
      2 Android 2.3.5;
      4 Android 2.3.6;
      2 Android 4.0.4;
      4 Android 4.1.1;
      6 Android 4.1.2;
      1 Android 4.2.1;
     17 Android 4.2.2;
      2 Android 4.3;
     10 Android 4.4.2;
      5 Android 4.4.4;
      3 Android 5.0.2;
      2 Android 5.1.1;
- UCBrowser (62)
      1 UCBrowser/9.9.2
      2 UCBrowser/10.0.0
      2 UCBrowser/10.0.1
      8 UCBrowser/10.0.2
      2 UCBrowser/10.1.0
      6 UCBrowser/10.2.0
      9 UCBrowser/10.3.0
     11 UCBrowser/10.4.1
     19 UCBrowser/10.5.0
      2 UCBrowser/10.5.2

Interesting is that all hits are only from the mobile sites, and only from the UCBrowser on Android.

All requests loaded both "user.options" and "user.tokens" (matches are 50/50 spread, and all in pairs from the same client).

All requests loaded those two modules in the same batch with "mediawiki.user".

The only moduleson en.m.wikipedia.org that depends on user.options is:

["mediawiki.user"]

The only modules on en.m.wikipedia.org that depend on mediawiki.user:

["ext.visualEditor.mediawiki", "ext.visualEditor.mwcore", "mobile.user", "ext.flow.components", "ext.flow.editor"]

The request therefore must be triggered by the client loading either mediawiki.user directly, or through one of the above modules.

In order for such request to trigger broken loading of "user.tokens" or "user.options", the request would have to be made in one of two ways. Either:

  • The page HTML was corrupted or several months old and didn't include the embedded user modules.
  • The page somehow made an mw.loader.load() call before the embedded user modules in the HTML.
Krinkle removed projects: WMF-deploy-2015-06-09_(1.26wmf9), WMF-deploy-2015-06-16_(1.26wmf10), Patch-For-Review.Jun 15 2015, 1:47 PM
Krinkle added a comment.Jun 15 2015, 7:34 PM
In T101806#1365499, @Krinkle wrote:

[..] In order for such request to trigger broken loading of "user.tokens" or "user.options" [..] Either:

  • The page HTML was corrupted or several months old and didn't include the embedded user modules.
  • The page somehow made an mw.loader.load() call before the embedded user modules in the HTML.

The request response for startup and jquery/mediawiki can't be outdated because it includes the new instrumentation recently added for this task.

The request response for the article HTML can't be outdated because it includes mw.loader.load( ... ext.wikimediaEvents ..); which was only recently introduced.

That would leave corruption of the HTML stream and/or some obscure JavaScript execution bug that would skip certain inline script tags.

gerritbot added a comment.Jun 16 2015, 3:37 PM

Change 218016 merged by jenkins-bot:
Log 'resourceloader.forbidden' events from readers

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

Krinkle mentioned this in rMEXTf4de174e36f1: Updated mediawiki/extensions Project: mediawiki/extensions/WikimediaEvents….Jun 16 2015, 3:37 PM
• Gilles mentioned this in rEWMV04ce736c562f: Log 'resourceloader.forbidden' events from readers.Jun 16 2015, 3:39 PM
• Forrestbot added a project: WMF-deploy-2015-06-16_(1.26wmf10).Jun 16 2015, 4:00 PM
gerritbot added a comment.Jun 16 2015, 6:47 PM

Change 218680 had a related patch set uploaded (by Krinkle):
Log a summary of scripts on the page with ModuleLoadFailure

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

gerritbot added a project: Patch-For-Review.Jun 16 2015, 6:47 PM
gerritbot added a comment.Jun 16 2015, 7:01 PM

Change 218692 had a related patch set uploaded (by Krinkle):
Log a summary of scripts on the page with ModuleLoadFailure

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

gerritbot added a comment.Jun 16 2015, 8:27 PM

Change 218680 abandoned by Krinkle:
Log a summary of scripts on the page with ModuleLoadFailure

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

gerritbot added a comment.Jun 16 2015, 8:27 PM

Change 218692 abandoned by Krinkle:
Log a summary of scripts on the page with ModuleLoadFailure

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

Krinkle lowered the priority of this task from High to Medium.Jun 17 2015, 2:57 AM
Krinkle removed projects: Patch-For-Review, WMF-deploy-2015-06-16_(1.26wmf10), Wikimedia-production-error.
gerritbot added a comment.Jun 17 2015, 3:21 PM

Change 218913 had a related patch set uploaded (by Krinkle):
mw.loader: Omit private modules from the request queue

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

gerritbot added a project: Patch-For-Review.Jun 17 2015, 3:21 PM
gerritbot added a comment.Jun 26 2015, 4:18 AM

Change 218913 merged by jenkins-bot:
mw.loader: Omit private modules from the request queue

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

Krinkle mentioned this in rMW1dd739037264: mw.loader: Omit private modules from the request queue.Jun 26 2015, 4:18 AM
• Forrestbot added projects: MW-1.26-release, WMF-deploy-2015-06-30_(1.26wmf12).Jun 26 2015, 5:00 AM
Krinkle closed this task as Resolved.Jun 29 2015, 7:06 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