Page MenuHomePhabricator

TransactionProfiler produces warnings when a AbuseFilter trip results in a block
Open, Needs TriagePublic

Description

normalized_message
Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: {actualSeconds}) in trx #{trxId}:
{query}
trace
from /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/TransactionProfiler.php(542)
#0 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/TransactionProfiler.php(347): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated(string, Wikimedia\Rdbms\GeneralizedSql, integer, string, string)
#1 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/TransactionManager.php(615): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, double, boolean, integer, string, string)
#2 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/Database.php(923): Wikimedia\Rdbms\TransactionManager->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, double, boolean, integer, string)
#3 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/Database.php(813): Wikimedia\Rdbms\Database->attemptQuery(Wikimedia\Rdbms\Query, string, boolean)
#4 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/Database.php(734): Wikimedia\Rdbms\Database->executeQuery(Wikimedia\Rdbms\Query, string, integer)
#5 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/Database.php(1564): Wikimedia\Rdbms\Database->query(Wikimedia\Rdbms\Query, string)
#6 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/DBConnRef.php(119): Wikimedia\Rdbms\Database->insert(string, array, string)
#7 /srv/mediawiki/php-1.41.0-wmf.15/includes/libs/rdbms/database/DBConnRef.php(397): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#8 /srv/mediawiki/php-1.41.0-wmf.15/extensions/CheckUser/src/Hooks.php(426): Wikimedia\Rdbms\DBConnRef->insert(string, array, string)
#9 /srv/mediawiki/php-1.41.0-wmf.15/extensions/CheckUser/src/Hooks.php(192): MediaWiki\CheckUser\Hooks::insertIntoCuChangesTable(array, string, MediaWiki\User\UserIdentityValue, RecentChange)
#10 /srv/mediawiki/php-1.41.0-wmf.15/extensions/CheckUser/src/Hooks.php(834): MediaWiki\CheckUser\Hooks::updateCheckUserData(RecentChange)
#11 /srv/mediawiki/php-1.41.0-wmf.15/includes/HookContainer/HookContainer.php(153): MediaWiki\CheckUser\Hooks->onRecentChange_save(RecentChange)
#12 /srv/mediawiki/php-1.41.0-wmf.15/includes/HookContainer/HookRunner.php(3212): MediaWiki\HookContainer\HookContainer->run(string, array)
#13 /srv/mediawiki/php-1.41.0-wmf.15/includes/changes/RecentChange.php(472): MediaWiki\HookContainer\HookRunner->onRecentChange_save(RecentChange)
#14 /srv/mediawiki/php-1.41.0-wmf.15/includes/logging/ManualLogEntry.php(439): RecentChange->save(boolean)
#15 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/MWCallableUpdate.php(38): ManualLogEntry->{closure}()
#16 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesManager.php(506): MWCallableUpdate->doUpdate()
#17 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesManager.php(432): MediaWiki\Deferred\DeferredUpdatesManager->attemptUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#18 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesManager.php(257): MediaWiki\Deferred\DeferredUpdatesManager->run(MWCallableUpdate, string)
#19 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesScope.php(267): MediaWiki\Deferred\DeferredUpdatesManager->MediaWiki\Deferred\{closure}(MWCallableUpdate, integer)
#20 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesScope.php(196): DeferredUpdatesScope->processStageQueue(integer, integer, Closure)
#21 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdatesManager.php(278): DeferredUpdatesScope->processUpdates(integer, Closure)
#22 /srv/mediawiki/php-1.41.0-wmf.15/includes/deferred/DeferredUpdates.php(159): MediaWiki\Deferred\DeferredUpdatesManager->doUpdates(integer)
#23 /srv/mediawiki/php-1.41.0-wmf.15/includes/MediaWiki.php(1135): DeferredUpdates::doUpdates()
#24 /srv/mediawiki/php-1.41.0-wmf.15/includes/MediaWiki.php(858): MediaWiki->restInPeace()
#25 /srv/mediawiki/php-1.41.0-wmf.15/includes/MediaWiki.php(606): MediaWiki->doPostOutputShutdown()
#26 /srv/mediawiki/php-1.41.0-wmf.15/index.php(50): MediaWiki->run()
#27 /srv/mediawiki/php-1.41.0-wmf.15/index.php(46): wfIndexMain()
#28 /srv/mediawiki/w/index.php(3): require(string)
#29 {main}

Extra info
The examples from logstash seem to indicate that this occurs when the AbuseFilter extension causes a block after a user trips an AbuseFilter. The TransactionProfiler should be told that when a user is blocked by the AbuseFilter extension, the block will cause a write into the DB.

Event Timeline

Dreamy_Jazz renamed this task from TransactionProfiler produces warnings when a AbuseFilter trip results a block to TransactionProfiler produces warnings when a AbuseFilter trip results in a block.Jun 30 2023, 11:23 PM
Dreamy_Jazz updated the task description. (Show Details)

Should be solved by T359648. Will wait until the change is deployed to verify this.

Like T359648, this should have been fixed by wmf.23.