Watchlist get requests should be idempotent; Logstash info: Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3)
Closed, ResolvedPublic5 Estimated Story Points
Actions

Description

About 6000 every 3 hours I'm seeing

Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3):
query-m: INSERT IGNORE INTO `user_properties` (up_user,up_property,up_value) VALUES ('X') [TRX#fc1af7]
#0 /srv/mediawiki/php-1.31.0-wmf.5/includes/libs/rdbms/TransactionProfiler.php(219): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.31.0-wmf.5/includes/libs/rdbms/database/Database.php(1037): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion()
#2 /srv/mediawiki/php-1.31.0-wmf.5/includes/libs/rdbms/database/Database.php(937): Wikimedia\Rdbms\Database->doProfiledQuery()
#3 /srv/mediawiki/php-1.31.0-wmf.5/includes/libs/rdbms/database/Database.php(1608): Wikimedia\Rdbms\Database->query()
#4 /srv/mediawiki/php-1.31.0-wmf.5/includes/user/User.php(5423): Wikimedia\Rdbms\Database->insert()
#5 /srv/mediawiki/php-1.31.0-wmf.5/includes/user/User.php(4061): User->saveOptions()
#6 /srv/mediawiki/php-1.31.0-wmf.5/extensions/MobileFrontend/includes/specials/SpecialMobileWatchlist.php(87): User->saveSettings()
#7 /srv/mediawiki/php-1.31.0-wmf.5/includes/deferred/MWCallableUpdate.php(30): Closure$SpecialMobileWatchlist::executeWhenAvailable()
#8 /srv/mediawiki/php-1.31.0-wmf.5/includes/deferred/DeferredUpdates.php(259): MWCallableUpdate->doUpdate()
#9 /srv/mediawiki/php-1.31.0-wmf.5/includes/deferred/DeferredUpdates.php(210): DeferredUpdates::runUpdate()
#10 /srv/mediawiki/php-1.31.0-wmf.5/includes/deferred/DeferredUpdates.php(131): DeferredUpdates::execute()
#11 /srv/mediawiki/php-1.31.0-wmf.5/includes/MediaWiki.php(897): DeferredUpdates::doUpdates()
#12 /srv/mediawiki/php-1.31.0-wmf.5/includes/MediaWiki.php(719): MediaWiki->restInPeace()
#13 (): Closure$MediaWiki::doPostOutputShutdown()
#14 {main}

https://logstash.wikimedia.org/app/kibana#/discover?_g=(refreshInterval:(display:Off,pause:!f,value:0),time:(from:now-7d,mode:quick,to:now))&_a=(columns:!(_source),index:'logstash-*',interval:auto,query:(query_string:(analyze_wildcard:!t,query:'message:%22User-%3EsaveSettings()%22')),sort:!('@timestamp',desc))

As Timo points out a GET request is supposed to be idempotent

I'm not sure if this will resolve the logstash issue, but moving this code to JS, seems like a sane thing to do. The stickiness of the tab is not the most important of features and could be done in the client after inspecting the value mw.user.options.get('mfWatchlistView') and comparing it to the current view.

Options:

Remove feature SpecialMobileWatchlist::updateStickyTabs and surrounding code
Add logic to client-side instead.

mw.loader.using('mediawiki.api.options').done( () => {
  new mw.Api().saveOption('mfWatchlistView', 'a-z')
} )

Make view switch a form with button instead of link. (See T179445#3725385 for other benefits, and proposal by @Krinkle)

Details

	Subject	Repo	Branch	Lines +/-
	Watchlist sticky preference is moved to client	mediawiki/extensions/MobileFrontend	master	+43 -60

Customize query in gerrit

Event Timeline

Jdlrobson created this task.Oct 31 2017, 10:48 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptOct 31 2017, 10:48 PM

Jdlrobson moved this task from Incoming to Needs Prioritization on the Web-Team-Backlog board.Oct 31 2017, 10:48 PM

Since violations are reported for 1, 2, and 3 writes, I guess the number of incidents is probably ~2000.

It appears that Special:MobileWatchlist has a feature that is designed to write to the database from a GET page view, this violates best practices from a technical perspective. From a user perspective, it seems that an invisible user preference is saved every time the page is viewed to memorise which version of the page is used, presumably as way of saving as a default for a future visit.

It might be better (and more efficient) to only save the setting when the user changes the view mode, and such switch would need to occur over a POST request instead, not by following a navigation link, which are expected to be "safe" and stateless. E.g. let the server output the anchor link based on preference, and the button to change view be a form that submits over POST.

Indirectly, the current approach creates a security problem because it means someone can point you to a link within a hidden iframe (resulting in a plain navigation to a predictable url) and the mere loading of this insecure URL would lead to a database write on behalf of your user account (and change your user preferences).

By changing the switch to be explicit via a form, you can also start to distinguish between the user visiting the alternate view directly (e.g. via a shared link), and the user explicitly switching their view within the page (you'd only save the latter case). This also has the benefit of not needing client-side JavaScript.

Agreed @Krinkle

What else needs clarification with this task? Can we update the description with some A/C and move the task along?

Jdlrobson triaged this task as Medium priority.Nov 2 2017, 11:03 PM

Jdlrobson updated the task description. (Show Details)

Jdlrobson moved this task from Needs Prioritization to Triaged but Future on the Web-Team-Backlog board.

pmiazga set the point value for this task to 5.Nov 8 2017, 6:02 PM

During Sprint prioritization we decided to give 5 points value mostly because of risk that some code might depend on the modified state and it might require a bit more work than only removing the DB UPDATE action and adding that logic within the client.

I also want to say, that having a check that GET request did 0 db update queries is one of the most awesome things I saw so far. It's great we have checks like that.

ovasileva moved this task from Triaged but Future to Upcoming on the Web-Team-Backlog board.Nov 14 2017, 10:53 AM

Krinkle added a project: Performance-Team (Radar).Nov 17 2017, 9:16 PM

Krinkle moved this task from Limbo to Watching on the Performance-Team (Radar) board.

• bmansurov unsubscribed.Dec 22 2017, 9:48 PM

Jdlrobson renamed this task from Logstash info: Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3) to Watchlist get requests should be idempotent; Logstash info: Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3).Jan 10 2018, 5:20 PM

Krinkle updated the task description. (Show Details)Feb 16 2018, 7:59 AM

Krinkle updated the task description. (Show Details)

ovasileva added a project: Readers-Web-Kanbanana-Board-Old.Feb 21 2018, 4:04 PM

ovasileva moved this task from To Do to Needs Design Review on the Readers-Web-Kanbanana-Board-Old board.Feb 21 2018, 6:28 PM

ovasileva moved this task from Upcoming to 2017-18 Q3 on the Web-Team-Backlog board.Feb 21 2018, 6:34 PM

Jdlrobson claimed this task.Feb 26 2018, 4:55 PM

Jdlrobson moved this task from Needs Design Review to Doing on the Readers-Web-Kanbanana-Board-Old board.

Jdlrobson moved this task from Doing to Needs Code Review on the Readers-Web-Kanbanana-Board-Old board.Feb 26 2018, 11:10 PM

Change 414852 had a related patch set uploaded (by Jdlrobson; owner: Jdlrobson):
[mediawiki/extensions/MobileFrontend@master] Watchlist sticky preference is moved to client

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

gerritbot added a project: Patch-For-Review.Feb 26 2018, 11:12 PM

pmiazga claimed this task.Feb 27 2018, 7:35 PM

pmiazga removed pmiazga as the assignee of this task.Feb 27 2018, 10:37 PM

pmiazga removed a project: Patch-For-Review.

pmiazga moved this task from Needs Code Review to Needs QA on the Readers-Web-Kanbanana-Board-Old board.

Change 414852 merged by jenkins-bot:
[mediawiki/extensions/MobileFrontend@master] Watchlist sticky preference is moved to client

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

This is skipping QA as we'll want to verify the fix via logstash. Any devs open to helping with this?

I reviewed the Logstash dashboard as part of my chores today. I only see a single event reported but it's for Echo so I'm calling this task done.

{"@timestamp":"2018-02-27T03:18:16.000000+00:00","@version":1,"host":"mw1323","message":"Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3):
query-m: DELETE FROM `user_newtalk` WHERE user_id = 'X' [TRX
db7]
#0 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/TransactionProfiler.php(219): Wikimedia\\Rdbms\\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/Database.php(1055): Wikimedia\\Rdbms\\TransactionProfiler->recordQueryCompletion()
#2 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/Database.php(953): Wikimedia\\Rdbms\\Database->doProfiledQuery()
#3 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/Database.php(2425): Wikimedia\\Rdbms\\Database->query()
#4 /srv/mediawiki/php-1.31.0-wmf.22/includes/user/User.php(2434): Wikimedia\\Rdbms\\Database->delete()
#5 /srv/mediawiki/php-1.31.0-wmf.22/includes/user/User.php(2469): User->deleteNewtalk()
#6 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Echo/includes/NotifUser.php(375): User->setNewtalk()
#7 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Echo/Hooks.php(932): MWEchoNotifUser->markRead()
#8 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/MWCallableUpdate.php(34): Closure$EchoHooks::onPersonalUrls()
#9 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(259): MWCallableUpdate->doUpdate()
#10 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(210): DeferredUpdates::runUpdate()
#11 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(131): DeferredUpdates::execute()
#12 /srv/mediawiki/php-1.31.0-wmf.22/includes/MediaWiki.php(907): DeferredUpdates::doUpdates()
#13 /srv/mediawiki/php-1.31.0-wmf.22/includes/MediaWiki.php(727): MediaWiki->restInPeace()
#14 (): Closure$MediaWiki::doPostOutputShutdown()
#15 {main}","type":"mediawiki","channel":"DBPerformance","level":"WARNING","shard":"s4","normalized_message":"Expectation ({measure} <= {max}) by {by} not met (actual: {actual}):
{query}
#0 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/TransactionProfiler.php(219): Wikimedia\\Rdbms\\TransactionProfiler->reportExpectationViolated()
#1 /srv/mediawiki/php-1.31.","url":"/w/index.php?title=User_talk:Hi%C3%A0n&action=edit&autoclick=wpSave&actoken=444c08e870d6551a&autoimpl=np20140416&autosummary=Revert%20to%20revision%20$1%20dated%20$2%20by%20$3%20using%20[[:en:Wikipedia:Tools/Navigation_popups|popups]]&autorv=286174484&oldid=286174484","ip":"10.64.0.102","http_method":"GET","server":"commons.wikimedia.org","referrer":"https://commons.wikimedia.org/wiki/Special:Watchlist?hidemyself=1&hidepreviousrevisions=1&translations=filter&hidecategorization=1&hideWikibase=1&limit=250&days=3&urlversion=2","unique_id":"WpTN@ApAICwAAFt2GUcAAACB","wiki":"commonswiki","mwversion":"1.31.0-wmf.22","reqId":"WpTN@ApAICwAAFt2GUcAAACB","measure":"writes","max":0,"by":"MediaWiki::restInPeace","actual":3,"query":"query-m: DELETE FROM `user_newtalk` WHERE user_id = 'X' [TRX
db7]"}

ReleaseTaggerBot added a project: MW-1.31-release-notes (WMF-deploy-2018-03-06 (1.31.0-wmf.24)).Mar 6 2018, 10:01 AM

fgiunchedi added a project: observability.Aug 19 2019, 2:31 PM

Watchlist get requests should be idempotent; Logstash info: Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3)Closed, ResolvedPublic5 Estimated Story PointsActions

Description

Details

Event Timeline

Watchlist get requests should be idempotent; Logstash info: Expectation (writes <= 0) by MediaWiki::restInPeace not met (actual: 3)
Closed, ResolvedPublic5 Estimated Story Points
Actions