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

Assigned To

None

Authored By

	mwjames
	Jun 2 2017, 5:08 AM

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.

Related Objects

Mentioned In: T154424: TransactionProfiler should not apply to SqlBagOStuff
Mentioned Here: T166855: TransactionProfiler spams log with "DELETE FROM `l10n_cache` ..." on LocalisationCache::recache

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 mentioned this in T154424: TransactionProfiler should not apply to SqlBagOStuff.Jun 15 2017, 2:56 PM

@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-libs-BagOStuff; removed MediaWiki-General.

Krinkle moved this task from General to HTTP Cache on the MediaWiki-libs-BagOStuff board.

In T166856#3375497, @Krinkle wrote:

@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.

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.

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

Description

Related Objects

Event Timeline

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