User:SPage (WMF)/Bypassing the cache

From mediawiki.org

Need to turn all this into actionable documentation. Gerrit change 67231 Remove template parse operation on every page view

This was responsible for 90% of Revision::fetchFromConds queries seen at the enwiki master DB server, and perhaps 30% of overall enwiki master query load. 

    public static function onMakeGlobalVariablesScript( &$vars, $out ) {
        $vars['wgGuidedTourHelpGuiderUrl'] =
            wfMessage( 'guidedtour-help-guider-url' )->inContentLanguage()->plain();
        
        $vars['wgGuidedTourTestWikitextDescription'] =
            wfMessage( 'guidedtour-tour-test-wikitext-description' )->parse();
    
        return true;
    }


'guidedtour-tour-test-wikitext-description' is

'A guider in your on-wiki tour can contain wikitext using onShow and parseDescription. Use it to create a wikilink to the [[{{MediaWiki:Guidedtour-help-url}}|Guided tours documentation]]. Or an external link [https://github.com/tychay/mwgadget.GuidedTour to GitHub], for instance.',

In turn MediaWiki:Guidedtour-help-url is

'Help:Guided tours'

but this page doesn't exist on enwiki, which caused a master DB query hit. Tim Starling comments "it was a template fetch, the reason it hit the master is because the page didn't exist so the fallback case in Revision::newFromConds was hit"

  • ?? The new login form does the same thing, including URLs like Help:Logging_in in parsed messages when they may not exist on the wiki in question.

IRC log lines[edit]

(04:08:18 PM) TimStarling: http://ganglia.wikimedia.org/latest/graph.php?r=week&z=xlarge&c=MySQL+eqiad&h=db1056.eqiad.wmnet&jr=&js=&v=7130&m=mysql_connections&vl=conns&ti=mysql_connections
(04:08:59 PM) TimStarling: 80% of enwiki master queries and about 80% of master connections also were due to a testing hack in GuidedTour
(04:09:26 PM) TimStarling: the other wikis where GuidedTour was enabled were affected also
(04:09:51 PM) TimStarling: I submitted a patch to fix it, by removing the test, Matt Flaschen merged it, and I deployed it

(04:10:27 PM) binasher: TimStarling: were those Revision::fetchFromConds queries?
(04:10:31 PM) TimStarling: yes


(04:26:15 PM) binasher: TimStarling: the rate of several other master query types increased by 2-3x on enwiki right after the guidedtour fix was deployed
(04:26:28 PM) binasher: thanks to being faster
(04:27:27 PM) binasher: https://ishmael.wikimedia.org/sample/more.php?host=db1056&hours=24&checksum=4058300124652897056
(04:27:39 PM) binasher: https://ishmael.wikimedia.org/sample/more.php?host=db1056&hours=24&checksum=484571594445205663
(04:28:02 PM) ***binasher buys TimStarling all the drinks

(04:34:33 PM) TimStarling: binasher: it was a template fetch, the reason it hit the master is because the page didn't exist
(04:34:48 PM) TimStarling: so the fallback case in Revision::newFromConds was hit
(04:35:40 PM) binasher: wow.


(05:38:12 PM) Aaron|home: I see it under
(05:38:18 PM) ***Aaron|home does trace profiling in eval.php
(05:38:30 PM) Aaron|home: Parser::braceSubstitution-title-Guidedtour-help-url
(05:38:47 PM) TimStarling: only a few seconds now, you'd better be quick
(05:38:57 PM) TimStarling: oh, there we go, spoiler alert
(05:39:08 PM) Aaron|home: > Parser::braceSubstitution-loadtpl
(05:40:27 PM) icinga-wm: PROBLEM - Puppetmaster HTTPS on stafford is CRITICAL: CRITICAL - Socket timeout after 10 seconds
(05:41:18 PM) icinga-wm: RECOVERY - Puppetmaster HTTPS on stafford is OK: HTTP OK: Status line output matched 400 - 336 bytes in 0.125 second response time
(05:41:51 PM) Aaron|home: I need to make those profile calls use prefixedDBKey
(05:43:19 PM) TimStarling: have you read the patch now? the issue was that GuidedTour was using {{MediaWiki:Guidedtour-help-url}} as a way to get a message in the content language
(05:43:36 PM) TimStarling: that page doesn't exist anywhere, it's just a default message
(05:43:58 PM) TimStarling: so Revision::loadFromConds() was hitting the missing revision case and falling back to the master
(05:44:25 PM) Aaron|home: I figured that loadFromConds was hitting the "not in slave" case, yes
(05:44:36 PM) TimStarling: after that fails, it does the message fetch:
(05:44:45 PM) TimStarling: 			} elseif ( $title->getNamespace() == NS_MEDIAWIKI ) {
(05:44:46 PM) TimStarling: 				global $wgContLang;
(05:44:46 PM) TimStarling: 				$message = wfMessage( $wgContLang->lcfirst( $title->getText() ) )->inContentLanguage();
(05:44:54 PM) TimStarling: which is the behaviour GuidedTour actually wanted
(05:44:59 PM) Aaron|home: yep
(05:45:21 PM) Aaron|home: heh
(05:45:58 PM) tfinc left the room (quit: Remote host closed the connection).
(05:46:07 PM) TimStarling: I guess it would be more efficient to go to the message cache first, since it has a complete cache of the MediaWiki namespace in it
(05:46:38 PM) StevenW [~StevenW@wikimedia/steven-walling] entered the room.
(05:46:52 PM) Reedy left the room (quit: Remote host closed the connection).
(05:46:53 PM) TimStarling: then {{MediaWiki:blah}} would be a proper substitute for the relevant missing feature e.g. {{int:blah|lang=content}}

(03:01:29 PM) superm401: StevenW, re 67231:
(03:01:50 PM) superm401: The part of guidedtour-tour-test-wikitext-description that caused the problem was {{MediaWiki:Guidedtour-help-url}}
(03:02:10 PM) superm401: Even though that's a MW page, it's treated like a regular template transclusion, which requires a db hit.
(03:02:39 PM) superm401: guidedtour-help-guider-url doesn't even require a parse.  The only reason it's a special case is that I'm requesting content language.
(03:02:52 PM) superm401: But that just changes *where* in the cache it's pulled from, it's still cached.
(03:03:15 PM) superm401: StevenW, but I did realize I don't know why it hit the master DB, when it's a read.
Retrieved from "https://www.mediawiki.org/w/index.php?title=User:SPage_(WMF)/Bypassing_the_cache&oldid=3945676"