Page MenuHomePhabricator

FlaggedRevsHooks::autoMarkPatrolled hook from RecentChange::save sometimes failed with "Lock wait timeout exceeded"
Closed, DeclinedPublicPRODUCTION ERROR

Description

Having to update the just-inserted RecentChanges entry in FlaggedRevsHooks is very expensive and sometimes fails. See for example:

2016-03-21 09:17:09 mw1161 ruwiki 1.27.0-wmf.17 exception ERROR: [9a801118] /rpc/RunJobs.php?wiki=ruwiki&type=ChangeNotification&maxtime=60&maxmem=300M   DBQueryError from line 934 of /srv/mediawiki/php-1.27.0-wmf.17/includes/db/Database.php: A database error has occurred. Did you forget to run maintenance/update.php after upgrading?  See: https://www.mediawiki.org/wiki/Manual:Upgrading#Run_the_update_script
Query: UPDATE  `recentchanges` SET rc_patrolled = '1' WHERE rc_cur_id = '4078029' AND rc_type = '1' AND (rc_timestamp <= '20151109111526')
Function: RevisionReviewForm::updateRecentChanges
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.16.12)
 {"exception_id":"9a801118"}
[Exception DBQueryError] (/srv/mediawiki/php-1.27.0-wmf.17/includes/db/Database.php:934) A database error has occurred. Did you forget to run maintenance/update.php after upgrading?  See: https://www.mediawiki.org/wiki/Manual:Upgrading#Run_the_update_script
Query: UPDATE  `recentchanges` SET rc_patrolled = '1' WHERE rc_cur_id = '4078029' AND rc_type = '1' AND (rc_timestamp <= '20151109111526')
Function: RevisionReviewForm::updateRecentChanges
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.16.12)

  #0 /srv/mediawiki/php-1.27.0-wmf.17/includes/db/Database.php(901): DatabaseBase->reportQueryError(string, integer, string, string, boolean)
  #1 /srv/mediawiki/php-1.27.0-wmf.17/includes/db/Database.php(1511): DatabaseBase->query(string, string)
  #2 /srv/mediawiki/php-1.27.0-wmf.17/extensions/FlaggedRevs/business/RevisionReviewForm.php(569): DatabaseBase->update(string, array, array, string, array)
  #3 /srv/mediawiki/php-1.27.0-wmf.17/extensions/FlaggedRevs/backend/FlaggedRevs.hooks.php(649): RevisionReviewForm::updateRecentChanges(RecentChange, string, FlaggedRevision)
  #4 /srv/mediawiki/php-1.27.0-wmf.17/includes/Hooks.php(195): FlaggedRevsHooks::autoMarkPatrolled(RecentChange)
  #5 /srv/mediawiki/php-1.27.0-wmf.17/includes/changes/RecentChange.php(315): Hooks::run(string, array)
  #6 /srv/mediawiki/php-1.27.0-wmf.17/extensions/Wikidata/extensions/Wikibase/client/includes/Changes/WikiPageUpdater.php(152): RecentChange->save()
  #7 /srv/mediawiki/php-1.27.0-wmf.17/extensions/Wikidata/extensions/Wikibase/client/includes/Changes/ChangeHandler.php(256): Wikibase\Client\Changes\WikiPageUpdater->injectRCRecords(array, Wikibase\ItemChange)
  #8 /srv/mediawiki/php-1.27.0-wmf.17/extensions/Wikidata/extensions/Wikibase/client/includes/Changes/ChangeHandler.php(175): Wikibase\Client\Changes\ChangeHandler->applyUpdateAction(string, array, Wikibase\ItemChange)
  #9 /srv/mediawiki/php-1.27.0-wmf.17/extensions/Wikidata/extensions/Wikibase/client/includes/Changes/ChangeHandler.php(141): Wikibase\Client\Changes\ChangeHandler->handleChange(Wikibase\ItemChange)
  #10 /srv/mediawiki/php-1.27.0-wmf.17/extensions/Wikidata/extensions/Wikibase/lib/includes/ChangeNotificationJob.php(124): Wikibase\Client\Changes\ChangeHandler->handleChanges(array)
  #11 /srv/mediawiki/php-1.27.0-wmf.17/includes/jobqueue/JobRunner.php(263): Wikibase\ChangeNotificationJob->run()
  #12 /srv/mediawiki/php-1.27.0-wmf.17/includes/jobqueue/JobRunner.php(177): JobRunner->executeJob(Wikibase\ChangeNotificationJob, BufferingStatsdDataFactory, integer)
  #13 /srv/mediawiki/rpc/RunJobs.php(47): JobRunner->run(array)
  #14 {main}

FlaggedRevs should be able to use a hook that runs in RecentChanges::save (pre-save) in order to change the value of rc_patrolled pre-save so that we already have the right value in the initial insert.

Event Timeline

Krinkle renamed this task from FlaggedRevsHooks::autoMarkPatrolled shouldn't need to update the RC entry that has just been saved to FlaggedRevsHooks::autoMarkPatrolled hook from RecentChange::save sometimes failed with "Lock wait timeout exceeded".Sep 6 2018, 1:05 AM
Krinkle subscribed.

Assuming the write isn't a no-op, it should indeed use an earlier hook to inform the value to be written instead of changing it immediately afterwards.

It's still curious that it would deadlock, though, and even curiouser that it isn't deterministic.

Krinkle moved this task from Older to Dec2019/1.35.wmf.10+ on the Wikimedia-production-error board.

Mistook it for another one. This one hasn't been seen for at least 30 days. Closing for now.

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:11 PM