Page MenuHomePhabricator
Create Task
Maniphest T310809

"MWException: CAS update failed on user_touched" from VisualEditor hook
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error
normalized_message
[{reqId}] {exception_url}   MWException: CAS update failed on user_touched. The version of the user to be saved is older than the current version.
exception.trace
from /srv/mediawiki/php-1.39.0-wmf.15/includes/user/User.php(2838)
#0 /srv/mediawiki/php-1.39.0-wmf.15/includes/libs/rdbms/database/Database.php(3676): User->{closure}(Wikimedia\Rdbms\DatabaseMysqli, string)
#1 /srv/mediawiki/php-1.39.0-wmf.15/includes/libs/rdbms/database/DBConnRef.php(68): Wikimedia\Rdbms\Database->doAtomicSection(string, Closure)
#2 /srv/mediawiki/php-1.39.0-wmf.15/includes/libs/rdbms/database/DBConnRef.php(603): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#3 /srv/mediawiki/php-1.39.0-wmf.15/includes/user/User.php(2850): Wikimedia\Rdbms\DBConnRef->doAtomicSection(string, Closure)
#4 /srv/mediawiki/php-1.39.0-wmf.15/extensions/VisualEditor/includes/Hooks.php(352): User->saveSettings()
#5 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/MWCallableUpdate.php(38): MediaWiki\Extension\VisualEditor\Hooks::MediaWiki\Extension\VisualEditor\{closure}()
#6 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdates.php(535): MWCallableUpdate->doUpdate()
#7 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdates.php(418): DeferredUpdates::attemptUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti)
#8 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdates.php(228): DeferredUpdates::run(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti, Monolog\Logger, BufferingStatsdDataFactory, MediaWiki\JobQueue\JobQueueGroupFactory, string)
#9 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdatesScope.php(267): DeferredUpdates::{closure}(MWCallableUpdate, integer)
#10 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdatesScope.php(196): DeferredUpdatesScope->processStageQueue(integer, integer, Closure)
#11 /srv/mediawiki/php-1.39.0-wmf.15/includes/deferred/DeferredUpdates.php(249): DeferredUpdatesScope->processUpdates(integer, Closure)
#12 /srv/mediawiki/php-1.39.0-wmf.15/includes/MediaWiki.php(1127): DeferredUpdates::doUpdates()
#13 /srv/mediawiki/php-1.39.0-wmf.15/includes/MediaWiki.php(852): MediaWiki->restInPeace()
#14 /srv/mediawiki/php-1.39.0-wmf.15/includes/MediaWiki.php(595): MediaWiki->doPostOutputShutdown()
#15 /srv/mediawiki/php-1.39.0-wmf.15/index.php(50): MediaWiki->run()
#16 /srv/mediawiki/php-1.39.0-wmf.15/index.php(46): wfIndexMain()
#17 /srv/mediawiki/w/index.php(3): require(string)
#18 {main}
Impact
Notes

~1k of these in the last month.

Details

Request URL
https://bo.wikipedia.org/w/index.php?title=*&action=edit&redlink=*&venoscript=*
SubjectRepoBranchLines +/-
Update code for setting user preferencesmediawiki/extensions/VisualEditormaster+21 -22
Customize query in gerrit

Event Timeline

• brennen created this task.Jun 16 2022, 3:23 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 16 2022, 3:23 PM
ppelberg moved this task from To Triage to Triaged on the VisualEditor board.Jun 16 2022, 3:26 PM
ppelberg added a project: Editing-team.
ppelberg moved this task from Untriaged to Upcoming on the Editing-team board.
matmarex subscribed.Jun 21 2022, 4:58 PM

I think the error is coming from this bit of code, it's the only thing in VisualEditor Hooks.php that generates a MWCallableUpdate:

	public static function onCustomEditor( Article $article, User $user ) {
		...
		if ( $req->getVal( 'venoscript' ) ) {
			$req->response()->setCookie( 'VEE', 'wikitext', 0, [ 'prefix' => '' ] );
			$services->getUserOptionsManager()->setOption( $user, 'visualeditor-editor', 'wikitext' );
			if ( !$services->getReadOnlyMode()->isReadOnly() && $user->isRegistered() ) {
				DeferredUpdates::addCallableUpdate( static function () use ( $user ) {
					$user->saveSettings();
				} );
			}
			return true;
		}

I don't entirely understand what "CAS update failed" means, but two things about this code look fishy: we're using the same User object in the deferred update that we got from the hook; and we're using User::saveSettings when we only want to save user preferences, we should be using something from UserOptionsManager instead.

matmarex claimed this task.Jun 21 2022, 5:41 PM
matmarex edited projects, added Editing-team (Kanban Board); removed Editing-team.
gerritbot added a comment.Jun 21 2022, 5:51 PM

Change 807193 had a related patch set uploaded (by Bartosz Dziewoński; author: Bartosz Dziewoński):

[mediawiki/extensions/VisualEditor@master] Update code for setting user preferences

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

gerritbot added a project: Patch-For-Review.Jun 21 2022, 5:51 PM
matmarex moved this task from Incoming to Code Review on the Editing-team (Kanban Board) board.Jun 21 2022, 5:51 PM
• brennen moved this task from Untriaged to Jun 2022 on the Wikimedia-production-error board.Jun 23 2022, 3:49 PM
Krinkle renamed this task from "MWException: CAS update failed on user_touched. The version of the user to be saved is older than the current version." from VisualEditor hook to "MWException: CAS update failed on user_touched" from VisualEditor hook.Jun 23 2022, 3:50 PM
Krinkle subscribed.Jun 23 2022, 3:56 PM

@matmarex The issue with this general pattern is the delay between the setOption and saveSettings. Likely there was something else in-between for the same user (possibly something we script that changes a hidden preference), and thus the token is no longer valid by then.

The general pattern we recommend for this, and have applied to other CAS errors in the past, is to make sure the User object is created, loaded, modified, and saved in the same scope.

Indeed, given the VE hook only needs to modify options, and not the User row itself, using UserOptionsManager naturally avoids CAS errors. (The UserOptionsManager::saveOptions method does the above automatically for you: It creates a new temp User object and then immediately calls checkAndSetTouched to ensure we induce the expected CAS failures when races happen, but on a much tighter time scale there naturally.)

• brennen moved this task from Backlog to Logs/Train on the User-brennen board.Jul 21 2022, 5:40 PM
gerritbot added a comment.Aug 10 2022, 4:44 PM

Change 807193 merged by jenkins-bot:

[mediawiki/extensions/VisualEditor@master] Update code for setting user preferences

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

ReleaseTaggerBot added a project: MW-1.39-notes (1.39.0-wmf.25; 2022-08-15).Aug 10 2022, 5:00 PM
Maintenance_bot removed a project: Patch-For-Review.Aug 10 2022, 5:30 PM
matmarex moved this task from Code Review to Blocked / Needs More Work on the Editing-team (Kanban Board) board.Aug 10 2022, 6:42 PM

Check logs after deployment to confirm

matmarex added a comment.EditedAug 20 2022, 3:57 AM

I had a look today to confirm the fix, and… it looks like something else has already mostly fixed it more than a month ago, on 2022-07-08. There have been only a few of those errors after that date.

Logstash query for "MWException: CAS update failed on user_touched" AND "*VisualEditor*": https://logstash.wikimedia.org/goto/7795f5bcbe71feb9e923a2d547a7a976

image.png (535×2 px, 62 KB)

Still, there were a few every couple of days, and there have been none since 2022-08-18 when the new patch has been deployed, so I guess that's mildly reassuring.

matmarex moved this task from Blocked / Needs More Work to Ready for Sign Off on the Editing-team (Kanban Board) board.Aug 20 2022, 3:58 AM
matmarex added a project: Skipped QA.
ppelberg closed this task as Resolved.Aug 26 2022, 11:54 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits