Page MenuHomePhabricator

(4 hrs) ResourceLoader timestamp for mobile.usermodule changes constantly
Closed, ResolvedPublic

Description

A log line is appended to fluorine:/a/mw-log/resourceloader.log whenever a ResourceLoader module definition is invalidated. When I grep the file for module names and rank by number of appearances, I notice that mobile.usermodule is at the top, and that the rate at which it is refreshed is an order of magnitude greater than the module in second place (user).

What is going on?

[fluorine:/a/mw-log] $ grep -Po '(?<=New definition hash for module )\S+' resourceloader.log  | sort | uniq -c | sort -rn | head
  15050 mobile.usermodule
   1625 user
   1198 ext.globalCssJs.user
    158 site
     93 user.groups
     83 ext.math.mathjax.localization
     60 ext.geshi.language.blitzbasic
     55 skins.vector.headerjs.beta
     55 mediawiki.skinning.content.parsoid
     55 ext.geshi.language.bibtex

Event Timeline

ori created this task.Feb 23 2015, 4:39 AM
ori raised the priority of this task from to Needs Triage.
ori updated the task description. (Show Details)
ori added subscribers: ori, Jdlrobson.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 23 2015, 4:39 AM
MaxSem claimed this task.Feb 23 2015, 6:56 PM

Mmm...

$ grep -oP 'New definition hash for module mobile\.usermodule.*$' resourceloader.log | grep -oP '2015\d+T\d+' | sort | uniq -c | sort -rn | less

   3422 20150218T222452
    522 20150219T172738
    495 20150219T162641
    400 20150219T155952
    392 20150219T172735
    357 20150218T222457
    353 20150221T031621
    325 20150219T154431
    256 20150219T154347
    242 20150218T222501
    240 20150219T160118

Change 192580 had a related patch set uploaded (by MaxSem):
Don't modify an array while iterating over it

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

Patch-For-Review

Change 192580 merged by jenkins-bot:
Don't modify an array while iterating over it

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

This is strange. getModifiedTime is usually what generates the hash
MobileUserModule extends ResourceLoaderUserModule which extends ResourceLoaderWikiModule
I wonder if it's because mobile.usermodule lists the dependency mobile.startup

The desktop version has no dependencies:
'user' => array( 'class' => 'ResourceLoaderUserModule' ),

I would guess removing the dependency would make this work again, I doubt Max's patch will fix it.

The commit above didn't help, so this is still a problem.

kaldari renamed this task from ResourceLoader definition hash for mobile.usermodule changes suspiciously frequently to ResourceLoader definition hash for mobile.user module changes suspiciously frequently.Mar 13 2015, 8:19 PM
KLans_WMF triaged this task as High priority.Mar 13 2015, 8:23 PM
Krinkle renamed this task from ResourceLoader definition hash for mobile.user module changes suspiciously frequently to ResourceLoader timestamp for mobile.usermodule changes constantly.EditedApr 2 2015, 8:42 AM
Krinkle added a subscriber: Krinkle.

Fresh samples:

2015-04-02 08:43:08 mw1113 enwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "en|ltr|minerva|Afgrahmat||||||20150401T223124Z"
2015-04-02 08:43:10 mw1098 enwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "en|ltr|minerva|Leonhutchinson123||||||20150401T223124Z"
2015-04-02 08:43:10 mw1236 enwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "en|ltr|minerva|Mertttzzt||||||20150401T223124Z"
2015-04-02 08:43:18 mw1177 kowiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "ko|ltr|minerva|오은지||||||20150401T223323Z"
2015-04-02 08:43:30 mw1059 enwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "en|ltr|minerva|Johnhalton||||||20150401T223124Z"
2015-04-02 08:43:33 mw1056 svwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "sv|ltr|minerva|Swetubes||||||20150401T223125Z"
2015-04-02 08:43:35 mw1184 dewiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "de|ltr|minerva|DerBoss3001||||||20150401T223125Z"
2015-04-02 08:43:52 mw1213 svwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "sv|ltr|minerva|Jabez Stone||||||20150401T223125Z"
2015-04-02 08:43:52 mw1214 ruwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "ru|ltr|minerva|דניאל לויטין||||||20150401T223126Z"
2015-04-02 08:43:53 mw1249 enwiki: ResourceLoaderModule::getDefinitionMtime: New definition for module mobile.usermodule in context "en|ltr|minerva|امیر کریمی 2||||||20150401T223124Z"

While this mobile module occurs much more often (several orders of magnitude), this may be related to T94810: User modules constantly invalidate their cache timestamp.

Any ideas what is going on here @Krinkle I took another look and it's basically doing the same as the ResourceLoaderWikiModule [1] (it extends the getPages function/)

[1] http://git.wikimedia.org/blob/mediawiki%2Fextensions%2FMobileFrontend.git/e574355604bb5962f48fa0c96515dacde2190fd3/includes%2Fmodules%2FMobileUserModule.php

JKatzWMF renamed this task from ResourceLoader timestamp for mobile.usermodule changes constantly to (4 hrs) ResourceLoader timestamp for mobile.usermodule changes constantly.Apr 15 2015, 5:45 PM
JKatzWMF moved this task from Triaged but Future to 2016-17 Q2 on the Readers-Web-Backlog board.
Krinkle moved this task from Tag to Doing on the Performance Issue board.May 13 2015, 12:25 PM
hashar added a subscriber: hashar.Jun 1 2015, 1:41 PM

Is that still a problem? Doesn't seem to happen anymore.

@Krinkle can you confirm one way or the other?

Krinkle added a comment.EditedJun 2 2015, 4:42 PM

The logging for this has been removed. T94810 is now resolved and enables modules to stop using time-hash mapping, which is what caused this problem for mobile.

If mobile was only using the default time-hash mapping for the module's definition summary, then T94810 fixed that retroactively. If mobile was using other time-hash mapping, then this will need to be migrated to use hashed directly.

It looks like the only custom modules in MobileFrontend are MobileSiteModule and MobileUserModule which have been fixed as they extend MediaWiki's ResourceLoaderWikiModule.

Krinkle closed this task as Resolved.Jun 2 2015, 4:44 PM
mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:12 PM