I assume the reason these timestamps are computed from a startup module request. It seems these have a user name in their request context.

• How come we have a user session in the startup module on bits.wikimedia.org?
• Assuming that's not the case, where are they coming from?
• Can we fix those sessions?

See also T44094: Startup manifest for logged-in users are minified and cause rapid objectcache growth.

Change 206433 had a related patch set uploaded (by Krinkle):
resourceloader: Add logging for T94810

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

Change 206436 had a related patch set uploaded (by Krinkle):
resourceloader: Add logging for T94810

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

Change 206437 had a related patch set uploaded (by Krinkle):
resourceloader: Add logging for T94810

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

Change 206433 merged by jenkins-bot:
resourceloader: Add logging for T94810

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

Change 206437 merged by jenkins-bot:
resourceloader: Add logging for T94810

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

Change 206436 merged by jenkins-bot:
resourceloader: Add logging for T94810

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

In T94810#1199543, @Krinkle wrote:

I assume the reason these timestamps are computed from a startup module request. It seems these have a user name in their request context.

• How come we have a user session in the startup module on bits.wikimedia.org?
• Assuming that's not the case, where are they coming from?
• Can we fix those sessions?

See also T44094: Startup manifest for logged-in users are minified and cause rapid objectcache growth.

None of the logged entries originate from bits.wikimedia.org/..modules=startup.. so that's good.

Raw samples:

2015-04-29 16:59:27 mw1042 wikidatawiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context "de|ltr|vector|.." from /wiki/Wikidata:Project_chat {"private":false}
.. Request with user parameter in context "sr|ltr|vector|.." from /wiki/File:Stevan_Kragujevic,_Slobodan_Penezic_Krcun.JPG {"private":false}
.. Request with user parameter in context "en|ltr|minerva.." from /w/load.php?debug=false&lang=en&modules=mobile.notifications%2Cusermodule&skin=minerva&user=..&* {"private":false}
.. Request with user parameter in context "ar|rtl|minerva.." from /w/load.php?debug=false&lang=ar&modules=mobile.notifications%2Cusermodule&skin=minerva&user=..&* {"private":false}
.. Request with user parameter in context "en|ltr|vector|.." from /wiki/File:State_law_reports.png {"private":false}
.. Request with user parameter in context "fr|ltr|vector|.." from /w/load.php?debug=false&lang=fr&modules=ext.globalCssJs.user&only=styles&skin=vector&user=..&* {"private":false}

Trend of past 24 hours:

$ grep 'getDefinitionMtime: Request with user' resourceloader.log | cut -d ' ' -f4- | sed 's/context "[^"]\+"/context/g' | sed 's/&user\=.\+$//g' | sort | uniq -c | sort -nr | head
   2018 enwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=en&modules=mobile.notifications%2Cusermodule&skin=minerva
    281 jawiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=ja&modules=mobile.notifications%2Cusermodule&skin=minerva
    214 ruwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=ru&modules=mobile.notifications%2Cusermodule&skin=minerva
    210 eswiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=es&modules=mobile.notifications%2Cusermodule&skin=minerva
    191 dewiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=de&modules=mobile.notifications%2Cusermodule&skin=minerva
    175 arwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=ar&modules=mobile.notifications%2Cusermodule&skin=minerva
    153 itwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=it&modules=mobile.notifications%2Cusermodule&skin=minerva
    146 frwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=fr&modules=mobile.notifications%2Cusermodule&skin=minerva
    120 ptwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=pt&modules=mobile.notifications%2Cusermodule&skin=minerva
     98 zhwiki resourceloader INFO: ResourceLoaderModule::getDefinitionMtime: Request with user parameter in context from /w/load.php?debug=false&lang=zh-tw&modules=mobile.notifications%2Cusermodule&skin=minerva

It's primarily:

1. Desktop views from logged-in users

This makes sense as OutputPage has to generate urls to user-module requests and includes a version number. While not for the startup manifest, the path traverses the same ResourceLoaderModule::getModifiedTime path.

2. Hardcoded requests from mobile to user-specific modules.

When handling requests for these hardcoded requests from OutputPage, like any other load request, ResourceLoader responds with a Last-Modified header. This is the max() of getModifiedTime of all modules being loaded in that patch. This header is a reflection of the server's current timestamps, regardless of the =version parameter in the url. And is especially important for unversioned requests, though that's not relevant here.

Hardcoded modules:

• site
• user
• user.groups
• ext.globalCssJs.user
• mobile.usermodule (same as 'user', but without common.)

Like most other modules, WikiModules track their definition summary (which includes the page names). This definition varies over time when the user creates, deletes or restores their subpages (timestamp of wiki revisions is not sufficient). As such, this essentially results in upto total wikis * total logged-in users * total skins different definitions being tracked by ResourceLoader for these user modules.

Aside from things dropping out of memcached, these are most likely genuine cache misses. Either the user created/deleted one of the four associated script/style pages ({common,skin}.{js,css}), or the user visited this wiki/skin combo for the first time since we introduced the definition tracking.

This hash-to-timestamp mapping via memcached is suboptimal. We'd be better off replacing using hashes directly (see T94074). So that we don't need to track anything.

However that doesn't yet explain why mobile's requests specifically are so dominant here. There is likely something else going on.

Change 207661 had a related patch set uploaded (by Krinkle):
[WIP] resourceloader: Implement version hashes instead of timestamps

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

rMWf37cee996ee9: resourceloader: Replace timestamp system with version hashing is way too large to be backported to REL1_25, and required a few extension updates too IIRC. Going to remove this as a 1.25 blocker.