Page MenuHomePhabricator

Frequent Echo DB_MASTER write queries on HTTP GET
Open, Needs TriagePublic

Description

The main two offenders are:

Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 5):
query-m: DELETE FROM `echo_unread_wikis` WHERE euw_user = 'X'
#0 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/TransactionProfiler.php(245): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(1318): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion()
#2 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(1198): Wikimedia\Rdbms\Database->attemptQuery()
#3 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(3004): Wikimedia\Rdbms\Database->query()
#4 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/UnreadWikis.php(141): Wikimedia\Rdbms\Database->delete()
#5 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/NotifUser.php(440): EchoUnreadWikis->updateCount()
#6 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/NotifUser.php(249): MWEchoNotifUser->resetNotificationCount()
#7 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/EchoHooks.php(940): MWEchoNotifUser->markRead()
#8 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/MWCallableUpdate.php(34): Closure$EchoHooks::processMarkAsRead#2()
#9 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(273): MWCallableUpdate->doUpdate()
#10 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(219): DeferredUpdates::runUpdate()
#11 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(143): DeferredUpdates::execute()
#12 /srv/mediawiki/php-1.33.0-wmf.23/includes/MediaWiki.php(909): DeferredUpdates::doUpdates()
#13 /srv/mediawiki/php-1.33.0-wmf.23/includes/MediaWiki.php(733): MediaWiki->restInPeace()
#14 (): Closure$MediaWiki::doPostOutputShutdown()
#15 {main}
Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 13):
query-m: INSERT INTO `echo_event` (event_type,event_variant,event_deleted,event_extra,event_agent_id,event_page_id) VALUES ('X')
#0 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/TransactionProfiler.php(245): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(1318): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion()
#2 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(1198): Wikimedia\Rdbms\Database->attemptQuery()
#3 /srv/mediawiki/php-1.33.0-wmf.23/includes/libs/rdbms/database/Database.php(2123): Wikimedia\Rdbms\Database->query()
#4 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/mapper/EventMapper.php(22): Wikimedia\Rdbms\Database->insert()
#5 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/model/Event.php(232): EchoEventMapper->insert()
#6 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/model/Event.php(167): EchoEvent->insert()
#7 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/DiscussionParser.php(95): EchoEvent::create()
#8 /srv/mediawiki/php-1.33.0-wmf.23/extensions/Echo/includes/EchoHooks.php(561): EchoDiscussionParser::generateEventsForRevision()
#9 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/MWCallableUpdate.php(34): Closure$EchoHooks::onPageContentSaveComplete()
#10 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(273): MWCallableUpdate->doUpdate()
#11 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(219): DeferredUpdates::runUpdate()
#12 /srv/mediawiki/php-1.33.0-wmf.23/includes/deferred/DeferredUpdates.php(143): DeferredUpdates::execute()
#13 /srv/mediawiki/php-1.33.0-wmf.23/includes/MediaWiki.php(909): DeferredUpdates::doUpdates()
#14 /srv/mediawiki/php-1.33.0-wmf.23/includes/MediaWiki.php(733): MediaWiki->restInPeace()
#15 (): Closure$MediaWiki::doPostOutputShutdown()
#16 {main}

Event Timeline

aaron created this task.Mar 29 2019, 8:53 AM
aaron renamed this task from Frequent Echo queries on HTTP GET to Frequent Echo DB_MASTER write queries on HTTP GET.Mar 29 2019, 5:32 PM
aaron removed aaron as the assignee of this task.May 1 2019, 5:29 PM

The first stack trace is from a deferred update scheduled from EchoHooks::processMarkAsRead() on read requests with a ?markasread=123 query parameter. If writing from deferred updates on GET requests is not allowed, how are we supposed to schedule a write when we notice that it's needed in a GET request? Do we submit a job to the job queue?

The second stack trace confuses me. It comes from a deferred update scheduled from EchoHooks::onPageContentSaveComplete(). How is it possible for the PageContentSaveComplete hook to be fired in a GET request? It seems like a reasonable assumption that a hook with "SaveComplete" in the name will only be fired in POST requests.

Catrope moved this task from Inbox to Upcoming Work on the Growth-Team board.Jul 31 2019, 2:10 AM
aaron added a comment.Jul 31 2019, 6:16 AM

Jobs are fine...though this case is complicated since people want their "latest views" to be immediately reflected...so it would have to do something like WatchedItemStore.