Page MenuHomePhabricator

Title::invalidateCache() called on GET request (TransactionProfiler warns about writes)
Closed, InvalidPublic

Description

MediaWiki	1.30.0-alpha (13ffedf)
PHP	7.1.1 (apache2handler)
MariaDB	10.1.21-MariaDB
ICU	57.1
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met:
query-m: UPDATE `page` SET page_touched = 'X') [TRX#7cbd00]
#0 ...\mw-master\includes\libs\rdbms\TransactionProfiler.php(218): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated('writes', 'query-m: UPDATE...')
#1 ...\mw-master\includes\libs\rdbms\database\Database.php(1024): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion('query-m: UPDATE...', 1496379772.2513, true, 1)
#2 ...\mw-master\includes\libs\rdbms\database\Database.php(925): Wikimedia\Rdbms\Database->doProfiledQuery('UPDATE  `page` ...', 'UPDATE /* Title...', true, 'Title::invalida...')
#3 ...\mw-master\includes\libs\rdbms\database\Database.php(1619): Wikimedia\Rdbms\Database->query('UPDATE  `page` ...', 'Title::invalida...')
#4 ...\mw-master\includes\Title.php(4492): Wikimedia\Rdbms\Database->update('`page`', Array, Array, 'Title::invalida...')
#5 ...\mw-master\includes\deferred\AutoCommitUpdate.php(42): Title->{closure}(Object(Wikimedia\Rdbms\DatabaseMysqli), 'Title::invalida...')
#6 ...\mw-master\includes\deferred\DeferredUpdates.php(259): AutoCommitUpdate->doUpdate()
#7 ...\mw-master\includes\deferred\DeferredUpdates.php(221): DeferredUpdates::runUpdate(Object(AutoCommitUpdate), Object(Wikimedia\Rdbms\LBFactorySimple), 1)
#8 ...\mw-master\includes\deferred\DeferredUpdates.php(124): DeferredUpdates::execute(Array, 'enqueue', 1)
#9 ...\mw-master\includes\MediaWiki.php(603): DeferredUpdates::doUpdates('enqueue', 1)
#10 ...\mw-master\includes\MediaWiki.php(572): MediaWiki::preOutputCommit(Object(RequestContext), Object(Closure))
#11 ...\mw-master\includes\MediaWiki.php(878): MediaWiki->doPreOutputCommit(Object(Closure))
#12 ...\mw-master\includes\MediaWiki.php(523): MediaWiki->main()
#13 ...\mw-master\index.php(43): MediaWiki->run()
#14 {main}

Comments from T166855 apply here as well.

Event Timeline

mwjames created this task.Jun 2 2017, 5:08 AM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 2 2017, 5:08 AM

@mwjames On what url did this happen? This doesn't look like a false positive. This isn't localisation cache or object cache. It's Title::invalidateCache(). This method should have no need for being called on a regular page view?

Krinkle renamed this task from TransactionProfiler spams log with "UPDATE `page`..." on AutoCommitUpdate::doUpdate to Title::invalidateCache() called on GET request (TransactionProfiler warns about writes).Jun 23 2017, 6:56 PM
Krinkle triaged this task as Medium priority.
Krinkle edited projects, added MediaWiki-Cache; removed MediaWiki-General.
Krinkle moved this task from Untriaged to HTTP Cache proxy on the MediaWiki-Cache board.

@mwjames On what url did this happen? This doesn't look like a false positive. This isn't localisation cache or object cache. It's Title::invalidateCache(). This method should have no need for being called on a regular page view?

@mwjames: Could you please answer the last comment? Thanks!

On what url did this happen?

After a month of inactivity on this ticket, I'm having a hard time to elaborate on the issue in retrospect. I provided all the information I had at the time and find myself not in a position to recall the specific circumstances of the reported issue but then again, problems around the TransactionProfiler hasn't been solved and remains the source for various reported issues.

Krinkle closed this task as Invalid.Jul 15 2017, 1:07 AM

This problem is about a wiki db write that is not cached related (UPDATE page SET page_touched = 'X') coming from Title::invalidateCache. That's a genuine violation detected by TransactionProfiler. If you can reproduce this on a regular GET request, please re-open. Specifically interested in what code would've queued such an update.