Page MenuHomePhabricator

Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met
Closed, ResolvedPublicBUG REPORT

Description

What is the problem?

When a user opens a page to edit, this can trigger autoblocks to be created or updated. But, because it is a GET request, we get warnings in the logs of the form:

[rdbms] Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met (actual: 1) in trx #95a6ecc310:
role-primary: UPDATE  `block` SET bl_timestamp = '?',bl_expiry = '?' WHERE bl_id = '?'

#0 /var/www/html/w/includes/libs/rdbms/TransactionProfiler.php(359): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated()
#1 /var/www/html/w/includes/libs/rdbms/database/TransactionManager.php(574): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion()
#2 /var/www/html/w/includes/libs/rdbms/database/Database.php(858): Wikimedia\Rdbms\TransactionManager->recordQueryCompletion()
#3 /var/www/html/w/includes/libs/rdbms/database/Database.php(711): Wikimedia\Rdbms\Database->attemptQuery()
#4 /var/www/html/w/includes/libs/rdbms/database/Database.php(638): Wikimedia\Rdbms\Database->executeQuery()
#5 /var/www/html/w/includes/libs/rdbms/database/Database.php(1518): Wikimedia\Rdbms\Database->query()
#6 /var/www/html/w/includes/libs/rdbms/database/DBConnRef.php(127): Wikimedia\Rdbms\Database->update()
#7 /var/www/html/w/includes/libs/rdbms/database/DBConnRef.php(413): Wikimedia\Rdbms\DBConnRef->__call()
#8 /var/www/html/w/includes/libs/rdbms/querybuilder/UpdateQueryBuilder.php(332): Wikimedia\Rdbms\DBConnRef->update()
#9 /var/www/html/w/includes/block/DatabaseBlockStore.php(1608): Wikimedia\Rdbms\UpdateQueryBuilder->execute()
#10 /var/www/html/w/includes/block/DatabaseBlockStore.php(1536): MediaWiki\Block\DatabaseBlockStore->updateTimestamp()
#11 /var/www/html/w/includes/user/User.php(2716): MediaWiki\Block\DatabaseBlockStore->doAutoblock()
#12 /var/www/html/w/includes/user/User.php(2694): MediaWiki\User\User->spreadBlock()
#13 /var/www/html/w/includes/editpage/EditPage.php(687): MediaWiki\User\User->spreadAnyEditBlock()
#14 /var/www/html/w/includes/deferred/MWCallableUpdate.php(52): MediaWiki\EditPage\EditPage::MediaWiki\EditPage\{closure}()
#15 /var/www/html/w/includes/deferred/DeferredUpdates.php(459): MediaWiki\Deferred\MWCallableUpdate->doUpdate()
#16 /var/www/html/w/includes/deferred/DeferredUpdates.php(201): MediaWiki\Deferred\DeferredUpdates::attemptUpdate()
#17 /var/www/html/w/includes/deferred/DeferredUpdates.php(288): MediaWiki\Deferred\DeferredUpdates::run()
#18 /var/www/html/w/includes/deferred/DeferredUpdatesScope.php(243): MediaWiki\Deferred\DeferredUpdates::MediaWiki\Deferred\{closure}()
#19 /var/www/html/w/includes/deferred/DeferredUpdatesScope.php(172): MediaWiki\Deferred\DeferredUpdatesScope->processStageQueue()
#20 /var/www/html/w/includes/deferred/DeferredUpdates.php(307): MediaWiki\Deferred\DeferredUpdatesScope->processUpdates()
#21 /var/www/html/w/includes/MediaWikiEntryPoint.php(306): MediaWiki\Deferred\DeferredUpdates::doUpdates()
#22 /var/www/html/w/includes/MediaWikiEntryPoint.php(191): MediaWiki\MediaWikiEntryPoint->commitMainTransaction()
#23 /var/www/html/w/includes/actions/ActionEntryPoint.php(206): MediaWiki\MediaWikiEntryPoint->doPrepareForOutput()
#24 /var/www/html/w/includes/MediaWikiEntryPoint.php(174): MediaWiki\Actions\ActionEntryPoint->doPrepareForOutput()
#25 /var/www/html/w/includes/actions/ActionEntryPoint.php(153): MediaWiki\MediaWikiEntryPoint->prepareForOutput()
#26 /var/www/html/w/includes/MediaWikiEntryPoint.php(202): MediaWiki\Actions\ActionEntryPoint->execute()
#27 /var/www/html/w/index.php(58): MediaWiki\MediaWikiEntryPoint->run()
#28 {main}
[rdbms] MediaWiki\Block\DatabaseBlockStore::updateTimestamp [0.155ms] mariadb-main: UPDATE  `block` SET bl_timestamp = '20250415142748',bl_expiry = '20250416142748' WHERE bl_id = 936

I am surprised this bug has not already been raised (I couldn't find one when I searched). It must have existed for a while.

Steps to reproduce problem
  1. Block a user, with the autoblock checkbox checked
  2. Login as that user and attempt to edit a page
  3. Check in the logs for the wiki (on my local docker wiki this is cache/mw-debug-web.log)

Expected behaviour: Don't see a warning.
Observed behaviour: See a warning like Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met.

Environment

Wiki(s): local docker MediaWiki 1.44.0-alpha (c8ddfa4) 07:05, 15 April 2025.

Derived Requirement

Ensure that no database write operations (e.g., autoblock timestamp updates) are triggered during GET requests when a blocked user attempts to edit a page. This prevents warnings like *"Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met"* from appearing in logs.


Test Result - Beta|Prod

Status: ✅ PASS / ❓Need More Info / ❌ FAIL
Environment: beta
OS: macOS Sequoia 15.6
Browser: Chrome 136
Device: MBA
Emulated Device: NA

Test Artifact(s):

Test Steps

Test Case 1: Ensure no write is triggered during GET request for blocked user editing a page

*Preconditions:*

  • User A is blocked with autoblock enabled.
  1. As User A, attempt to edit any page using the "Edit" link (triggers a GET request).
  2. Check the server log file (mw-debug-web.log) or the equivalent application log.
  3. ✅❓❌⬜ AC1: Confirm that there is no log warning stating Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met.

QA Results - Local

ACStatusDetails
1T391980#10877749

Event Timeline

Change #1140267 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/core@master] block: Suppress transaction profiler warning on User::spreadBlock

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

Change #1140267 merged by jenkins-bot:

[mediawiki/core@master] block: Suppress transaction profiler warning on User::spreadBlock

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

@tstarling Confirmed that there is no log warning stating Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met as seen in the screenshots. I will move this to Done. Thanks for all your work!

Test Result - Local

Status: ✅ PASS
Environment: Local 1.45.0-alpha (6436535) 18:23, 2 June 2025
OS: macOS Sequoia 15.6
Browser: Chrome 136
Device: MBA
Emulated Device: NA

Test Artifact(s):

Test Steps

Test Case 1: Ensure no write is triggered during GET request for blocked user editing a page

*Preconditions:*

  • User A is blocked with autoblock enabled.
  1. As User A, attempt to edit any page using the "Edit" link (triggers a GET request).
  2. Check the server log file (mw-debug-web.log) or the equivalent application log.
  3. AC1: Confirm that there is no log warning stating Expectation (writes <= 0) by MediaWiki\Actions\ActionEntryPoint::execute not met.
Special: BlockBlock ListUser BlockServer Log
2025-06-02_11-44-29.png (1,441×915 px, 155 KB)
2025-06-02_11-44-21.png (1,425×869 px, 176 KB)
2025-06-02_11-45-01.png (1,431×983 px, 213 KB)
2025-06-02_11-56-45.png (1,476×729 px, 268 KB)
GMikesell-WMF updated the task description. (Show Details)
GMikesell-WMF updated Other Assignee, removed: GMikesell-WMF.