Page MenuHomePhabricator

Echo master query spam on HTTP GET
Closed, ResolvedPublic

Description

About 130/min:

Expectation (masterConns <= 0) by MediaWiki::main not met:
[connect to 10.64.32.27 (enwiki)]
#0 /srv/mediawiki/php-1.28.0-wmf.20/includes/libs/rdbms/TransactionProfiler.php(156): TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.28.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(573): TransactionProfiler->recordConnection()
#2 /srv/mediawiki/php-1.28.0-wmf.20/includes/objectcache/SqlBagOStuff.php(190): LoadBalancer->getConnection()
#3 /srv/mediawiki/php-1.28.0-wmf.20/includes/objectcache/SqlBagOStuff.php(333): SqlBagOStuff->getDB()
#4 /srv/mediawiki/php-1.28.0-wmf.20/includes/objectcache/SqlBagOStuff.php(380): SqlBagOStuff->setMulti()
#5 /srv/mediawiki/php-1.28.0-wmf.20/includes/libs/objectcache/ReplicatedBagOStuff.php(90): SqlBagOStuff->set()
#6 /srv/mediawiki/php-1.28.0-wmf.20/includes/libs/objectcache/CachedBagOStuff.php(65): ReplicatedBagOStuff->set()
#7 /srv/mediawiki/php-1.28.0-wmf.20/extensions/Echo/includes/SeenTime.php(113): CachedBagOStuff->set()
#8 /srv/mediawiki/php-1.28.0-wmf.20/extensions/Echo/includes/SeenTime.php(92): EchoSeenTime->setTime()
#9 /srv/mediawiki/php-1.28.0-wmf.20/extensions/Echo/Hooks.php(1054): EchoSeenTime->getTime()
#10 /srv/mediawiki/php-1.28.0-wmf.20/includes/Hooks.php(195): EchoHooks::onOutputPageCheckLastModified()
#11 /srv/mediawiki/php-1.28.0-wmf.20/includes/OutputPage.php(772): Hooks::run()
#12 /srv/mediawiki/php-1.28.0-wmf.20/includes/actions/ViewAction.php(65): OutputPage->checkLastModified()
#13 /srv/mediawiki/php-1.28.0-wmf.20/includes/MediaWiki.php(505): ViewAction->show()
#14 /srv/mediawiki/php-1.28.0-wmf.20/includes/MediaWiki.php(289): MediaWiki->performAction()
#15 /srv/mediawiki/php-1.28.0-wmf.20/includes/MediaWiki.php(861): MediaWiki->performRequest()
#16 /srv/mediawiki/php-1.28.0-wmf.20/includes/MediaWiki.php(522): MediaWiki->main()
#17 /srv/mediawiki/php-1.28.0-wmf.20/index.php(43): MediaWiki->run()
#18 /srv/mediawiki/w/index.php(3): include()
#19 {main}

Details

Related Gerrit Patches:
mediawiki/extensions/Echo : masterDefer cache write in EchoSeenTime::setTime()

Event Timeline

aaron created this task.Sep 23 2016, 6:27 PM
Restricted Application added a project: Collaboration-Team-Triage. · View Herald TranscriptSep 23 2016, 6:27 PM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
Catrope claimed this task.Sep 23 2016, 6:40 PM

Hmm yeah that probably needs a DeferredUpdate. On it.

Hmm, hold on, this should not be happening in master because we switched from db-replicated to mainstash. Is it OK to write to MainStash from a GET, or should that be deferred too?

Change 312549 had a related patch set uploaded (by Catrope):
Defer cache write in EchoSeenTime::setTime()

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

Hmm, hold on, this should not be happening in master because we switched from db-replicated to mainstash. Is it OK to write to MainStash from a GET, or should that be deferred too?

Aaron says we should still defer, my patch does that.

Change 312549 merged by jenkins-bot:
Defer cache write in EchoSeenTime::setTime()

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

This patch won't stop the warnings in production until wmf.21 is deployed, but hopefully it did stop them in beta labs.

Did not see such warnings in deployment-fluorine02 /srv/mw-log/exception.log.

jmatazzoni closed this task as Resolved.Sep 29 2016, 11:20 PM