It seems like the effect happened on beta earlier, on September 16, which might also us to pinpoint the commit that caused it:

We're looking for something that was merged between 2020-09-16 16:10 and 2020-09-16 17:30 CEST

I'm extending the timeframe somewhat for those queries, as I don't know to what extent the times displayed in Grafana are rounded. I also can't query wpt.wmftest.org that far in the past to get the exact test run time.

MediaWiki core commits:

gilles@deploy1001:/srv/mediawiki-staging/php$ git log --after="2020-09-16 13:00" --before="2020-09-16 17:00" --pretty=fuller
commit 5e703cdf669f85e2924dee76c5a8831633259ce0
Author:     C. Scott Ananian <cscott@cscott.net>
AuthorDate: Wed Sep 16 10:56:37 2020 -0400
Commit:     C. Scott Ananian <cscott@cscott.net>
CommitDate: Wed Sep 16 12:27:51 2020 -0400

    Hard deprecate File::userCan() with $user=null
    
    The ArchivedFile::userCan and OldLocalFile::userCan() methods, along
    with a number of other methods where the user parameter was optional,
    were deprecated in 1.35, but this case was overlooked. This patch is
    intended for backport to 1.35, so that the $user parameter can be
    removed in 1.36 in accordance with the deprecation policy.
    
    This path is known to be used by LocalRepo::findFile(),
    FileRepo::findFile(), and FileRepo::findFileFromKey(), so hacky
    workarounds have been added in this patch to avoid triggering
    deprecation warnings in 1.35. T263033 has been filed to fix these
    'correctly' in 1.36.
    
    Bug: T263014
    Change-Id: I17cab8ce043a5965aeab089392068b91c686025e

commit 76ac517f40f8e560a98b42ea1a8402e8c9a557b4
Merge: 87f480d3b2 0c01d8cc52
Author:     jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
AuthorDate: Wed Sep 16 15:09:39 2020 +0000
Commit:     Gerrit Code Review <gerrit@wikimedia.org>
CommitDate: Wed Sep 16 15:09:39 2020 +0000

    Merge "resourceloader: Add skin-based 'mediawiki.skin.variables.less' import"

commit 87f480d3b28b9a20e82abfeb67edfcf8538f44ba
Merge: 74399847c7 a66e7a6b0c
Author:     jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
AuthorDate: Wed Sep 16 15:08:04 2020 +0000
Commit:     Gerrit Code Review <gerrit@wikimedia.org>
CommitDate: Wed Sep 16 15:08:04 2020 +0000

    Merge "Revert "Remove support for (Archived|OldLocal)File::userCan without a user""

commit 74399847c7970faddec4f7729e9f7ae71f9e250e
Merge: 61d36def2d 73674f9bc0
Author:     jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
AuthorDate: Wed Sep 16 13:25:13 2020 +0000
Commit:     Gerrit Code Review <gerrit@wikimedia.org>
CommitDate: Wed Sep 16 13:25:13 2020 +0000

    Merge "Allow REST API Responses to be JsonSerializable objects"

Extension commits:

gilles@deploy1001:/srv/mediawiki-staging/php$ git submodule foreach "git log --after=\"2020-09-16 13:00\" --before=\"2020-09-16 17:00\" --pretty=fuller"

Entering 'extensions/AbuseFilter'
commit 43e471d0568766f5b885265f7a3c991019f2ce23
Author:     Huji Lee <huji.huji@gmail.com>
AuthorDate: Tue Sep 8 09:22:01 2020 -0400
Commit:     Huji Lee <huji.huji@gmail.com>
CommitDate: Wed Sep 16 09:03:43 2020 -0400

    Introduce searchFilters.php
    
    A maintenance script that makes it easier for those with shell
    access to search for all filters matching a regular expression
    pattern on any of the wikis in a wiki farm.
    
    Bug: T262052
    Change-Id: Iea9e87a9055c0b1cedd06e8211fc99e3cef53c3a
Entering 'extensions/Wikibase'
commit 5854816195fbf7b75f14c687d972d8b1d99857f6
Author:     Amir Sarabadani <Ladsgroup@gmail.com>
AuthorDate: Tue Sep 15 17:45:11 2020 +0200
Commit:     Amir Sarabadani <Ladsgroup@gmail.com>
CommitDate: Wed Sep 16 17:24:08 2020 +0200

    Enable Termbox v2 for desktop behind a feature flag
    
    This is the first step on getting Universal Server Side Rendering
    
    You can enable it by setting:
    $wgWBRepoSettings['termboxDesktopEnabled'] = true;
    
    in LocalSettings.php
    
    This is done to test the look and integration of the new termbox with
    the desktop interface (Vector skin) and it's not production ready.
    
    Bug: T261488
    Change-Id: I0af3405e12862477ca9d2f0ba4c3df81b9f82beb

commit 3b548a4faca5a6f8aebce0d1b5cc1a17e32d0b48
Author:     Amir Sarabadani <Ladsgroup@gmail.com>
AuthorDate: Wed Sep 16 15:26:41 2020 +0200
Commit:     Amir Sarabadani <Ladsgroup@gmail.com>
CommitDate: Wed Sep 16 15:42:36 2020 +0200

    Rename changes_* schema files
    
    To make them consistent with the rest of schema files (name of the
    table). This wasn't done during the abstraction to make the code review
    easier.
    
    Bug: T205094
    Change-Id: Ia93a871c1ffccb5647ef563e70962b500a1397b0
Entering 'extensions/WikibaseMediaInfo'
commit fa4eefedeb8d95b27c7182ee3f0d4c8ed77cfdf2
Merge: 3db3507 5b5f948
Author:     jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
AuthorDate: Wed Sep 16 14:30:40 2020 +0000
Commit:     Gerrit Code Review <gerrit@wikimedia.org>
CommitDate: Wed Sep 16 14:30:40 2020 +0000

    Merge "Use a higher-resolution thumbnail for Quickview"

commit f4e23db364b17a1ed378a032e94cd80cde71e856
Author:     annet <atomasevich@wikimedia.org>
AuthorDate: Tue Sep 15 22:03:16 2020 -0400
Commit:     annet <atomasevich@wikimedia.org>
CommitDate: Wed Sep 16 09:28:45 2020 -0400

    Add horizontal scrolling to tabs on mobile
    
    When the tab list is wider than the viewport, add horizontal
    scrolling as well as a gradient at the end to indicate to the user
    that they can scroll.
    
    This also adds a hide event to the Observer base component.
    
    Bug: T258615
    Change-Id: If3f0c14547e3467baed866e7dbb109fe753baa38
Entering 'extensions/WikibaseQualityConstraints'
commit 84189d4e70571655fb0476ba927cff06d274de69
Author:     Lucas Werkmeister <lucas.werkmeister@wikimedia.de>
AuthorDate: Wed Sep 16 18:55:18 2020 +0200
Commit:     Lucas Werkmeister <lucas.werkmeister@wikimedia.de>
CommitDate: Wed Sep 16 18:55:18 2020 +0200

    Add return type to ConstraintsServices
    
    All the other return types were added in change Iff74422739 (commit
    43d8fca719); the ExpiryLock was added concurrently in change I155db371e6
    (commit 14faac4c42), so it was missed.
    
    Change-Id: Ib3a5ec40c959f95acedc821fe6ccec4a97d3e280
Entering 'skins/MinervaNeue'
commit 1cea34243153530e2ae7b21d1e1e2b7d99a832d4
Author:     Ed Sanders <esanders@wikimedia.org>
AuthorDate: Sat Sep 12 23:40:39 2020 +0100
Commit:     Jforrester <jforrester@wikimedia.org>
CommitDate: Wed Sep 16 13:48:53 2020 +0000

    build: Update eslint-config-wikimedia to 0.17.0
    
    Change-Id: I0b917095bc84ff8b3a745f2d8b1e8541b9817bc8
Entering 'skins/MonoBook'
commit 404eade86e7ba5239346ee6bc3f8ab2ef2493bf1
Merge: 548e0b4 0fe9a86
Author:     jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
AuthorDate: Wed Sep 16 15:09:44 2020 +0000
Commit:     Gerrit Code Review <gerrit@wikimedia.org>
CommitDate: Wed Sep 16 15:09:44 2020 +0000

    Merge "Implement mediawiki.skin.variables.less for MonoBook"
Entering 'skins/Vector'
commit 7e0731de484acaa09b2bb5bd88e496e2ddf8ea58
Author:     Timo Tijhof <krinklemail@gmail.com>
AuthorDate: Sun May 20 20:58:47 2018 +0200
Commit:     Volker E <volker.e@wikimedia.org>
CommitDate: Wed Sep 16 08:39:13 2020 -0700

    Implement mediawiki.skin.variables.less for Vector
    
    For now, only define:
    
    - @font-family-sans
    - @border-radius-base
    
    Bug: T112747
    Depends-On: Icf86c930a3b5524254bb549624737d3b9dccb032
    Change-Id: I47da3046678117d5214354d1efe635f32f307dad

MediaWiki config commits:

commit 0563e9605178feb92ab4deb6d662f2055c7d2ac7
Author:     Lucas Werkmeister <lucas.werkmeister@wikimedia.de>
AuthorDate: Wed Sep 16 17:29:17 2020 +0200
Commit:     Lucas Werkmeister <lucas.werkmeister@wikimedia.de>
CommitDate: Wed Sep 16 17:30:09 2020 +0200

    Rename wmgWikibaseClientLocalEntitySourceName to wmgWikibaseClientItemAndPropertySourceName on Beta
    
    This can be done in one commit since we don<E2><80><99>t manually do file-per-file
    scap on Beta anyways. I think.
    
    Change-Id: I2e133583df16fcd91e4574d8b9b3e85def41dbfd

commit 9dd141219e9303ae1aa073fa24a569be473e172b
Author:     Itamar Givon <itamar.givon@wikimedia.de>
AuthorDate: Fri Aug 28 15:26:48 2020 +0200
Commit:     Lucas Werkmeister (WMDE) <lucas.werkmeister@wikimedia.de>
CommitDate: Wed Sep 16 15:06:52 2020 +0000

    Remove `wmgWikibaseClientLocalEntitySourceName` from InitialiseSettings.php
    
    Bug: T258060
    Depends-On: I8433dbebaf0f90ab8916c1b638e2fefdcd8a4568
    Change-Id: I80e3ac284601f8bb98572342c3203d7e0fec58b9

commit 27bfd018ee3e2e0dcbcaf5b8773088f8b1f69a43
Author:     Itamar Givon <itamar.givon@wikimedia.de>
AuthorDate: Fri Aug 28 15:23:36 2020 +0200
Commit:     Lucas Werkmeister (WMDE) <lucas.werkmeister@wikimedia.de>
CommitDate: Wed Sep 16 15:06:35 2020 +0000

    Use `wmgWikibaseClientItemAndPropertySourceName` instead of `wmgWikibaseClientLocalEntitySourceName` in Wikibase.php
    
    Bug: T258060
    Depends-On: I068ae176b3feb7b0c8047a30b2bde5490b811a26
    Change-Id: I8433dbebaf0f90ab8916c1b638e2fefdcd8a4568

commit 46cc9d3c3d4a242e24c241a1b25df1e5ffa6467f
Author:     Itamar Givon <itamar.givon@wikimedia.de>
AuthorDate: Wed Aug 26 18:24:35 2020 +0200
Commit:     Lucas Werkmeister (WMDE) <lucas.werkmeister@wikimedia.de>
CommitDate: Wed Sep 16 15:06:10 2020 +0000

    Add `wmgWikibaseClientItemAndPropertySourceName` to InitialiseSettings.php
    
    Bug: T258060
    Depends-On: Idab35296a9c5fa508eefa445810d8c5ab9b577e6
    Change-Id: I068ae176b3feb7b0c8047a30b2bde5490b811a26

commit 524fb26452311745386186f36e02c1a1ddb68701
Author:     Lars Wirzenius <lwirzenius@wikmedia.org>
AuthorDate: Wed Sep 16 13:00:35 2020 +0000
Commit:     Lars Wirzenius <lwirzenius@wikmedia.org>
CommitDate: Wed Sep 16 13:00:35 2020 +0000

    group1 wikis to 1.36.0-wmf.9
    
    Change-Id: I2a9b2ad52bbfc5abeaf21a44e42addfc082c8aeb

I don't see any commit in that list that could explain this change, but maybe I'm missing something. It's really odd because the timing is very consistent between something getting into master on September 16 causing an issue on Beta and then deployed as part of 1.36.0-wmf.10 yesterday causing an issue in production. Maybe the timing of the change isn't exactly the timing of the commit because something might have remained cached for a bit?

Here are the last good test run and first bad test run on Beta, compared: http://wpt.wmftest.org/video/compare.php?tests=200916_D8_AQ%2C200916_KN_BR&thumbSize=200&ival=100&end=visual#

The sudden increase in total blocking time is consistent with what we're seeing in production as of yesterday. There should be less differences in payloads between those runs on Beta, by looking at the content differences we might be able to find out what caused the problem.

I'm seeing differences in the HTML:

This might explain why there are no suspicious commits in the timeframe, as well as why in production we're seeing it happen later for the Barack Obama article. It just stayed in cache longer than the Facebook one. The trigger is that the affected article must have had its html re-generated. The actual change must have been merged to master in the days preceding 2020-09-16 15:40 UTC.

I see that there was some heavy-duty work going on with MobileFrontend sections around that time: T261769: MobileFormatter follow up work

This is my best lead so far. @Jdlrobson @Peter.ovchyn can you imagine ways in which this HTML change might cause some very significant layout and/or JS execution cost increase for the browser?

This is what we're seeing when it kicked in on Beta:

And the same just happened in production, RUM included, now that this got release with 1.36.0-wmf.10.

Comparing the startup module manifest, there are a lot of differences in module version hashes between the last good run and the first bad run, but the first big long task in the first bad run begins before any of those modules are loaded (it starts after the HTML and startup module have finished downloading, though):

It's worth noting that Desktop isn't affected at all, on Beta or in production. Which is another reason why this MobileFrontend work is the best lead so far.

@Gilles that sounds reasonable. I'll check the performance impact of my changes carefully and get back to as soon as I have any conclusion on that.

Thanks for looking into this @Peter.ovchyn

Looking at the same last good run/first bad run in production for the Facebook article: http://wpt.wmftest.org/video/compare.php?tests=200924_G3_F9%2C200924_HS_GB&thumbSize=200&ival=100&end=visual#

We can clearly see the same phenomenon, whereby a new revision is made, the HTML is regenerated with that change again:

And exact same thing with the Barack Obama article, which happened later, because it took longer for the first edit to happen after the deployment of 1.36.0-wmf.10: http://wpt.wmftest.org/video/compare.php?tests=200925_RD_2H%2C200925_37_3G&thumbSize=200&ival=100&end=visual#

And in the case of the Barack Obama last good run/first bad run comparison, the startup modules are absolutely identical, which narrows it down to the HTML change.

I don't know the context of that change, but it seems to me like we could revert it on master, purge the test article and our synthetic tests running on Beta should recover in terms of performance if it really is the culprit.

Looking at the effect on RUM, it's severe on Safari as well, not just on Chrome:

And it's only going to get worse as more and more articles are edited/purged. The final magnitude of it might be as great as what we see in synthetic tests once all articles get the new HTML.

Change 630147 had a related patch set uploaded (by Peter.ovchyn; owner: Peter.ovchyn):
[mediawiki/extensions/MobileFrontend@master] Make all section collapsible during server side rendering

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

In T263832#6493906, @Gilles wrote:

I don't know the context of that change, but it seems to me like we could revert it on master, purge the test article and our synthetic tests running on Beta should recover in terms of performance if it really is the culprit.

I just wonder. Are we talking about performance degradation during loading the page on client side or during generating it on server side?
I believe it's about client.
I see the following order is the best here:

1. Apply patch https://gerrit.wikimedia.org/r/c/mediawiki/extensions/MobileFrontend/+/630147

If it doesn't work then

2. Revert https://gerrit.wikimedia.org/r/c/mediawiki/extensions/MobileFrontend/+/626162 and https://gerrit.wikimedia.org/r/c/mediawiki/extensions/MobileFrontend/+/627436 on master

Its in the client (in the browser).

In T263832#6493991, @Peter wrote:

Its in the client (in the browser).

Nice, then patch https://gerrit.wikimedia.org/r/c/mediawiki/extensions/MobileFrontend/+/630147 should really fix that.

Change 630065 had a related patch set uploaded (by Jdlrobson; owner: Peter.ovchyn):
[mediawiki/extensions/MobileFrontend@wmf/1.36.0-wmf.10] Make all section collapsible during server side rendering

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

@Peter.ovchyn thank you for the fast response. Let's purge one article on Beta and one in production as soon as the patches merge and then on the next synthetic test runs we'll be able to verify the fix.

The raw HTML contains an onclick handler and has a collapsible-section class on all sections. Without those there will be a reflow as the section collapsing is applied. The onclick handler accounts for slow connections and connections where JS doesn't fully load. I can confirm our refactors removed those (accidentally) and that the above patch fixes this.

https://fr.m.wikipedia.org/wiki/Spain is a good example to see the problem here (on mobile device watch as the sections display and then collapse).

Unfortunately, these pages are in cache now, so the quicker we get the patch on production the better.

I think that the articles that got the "bad HTML" since yesterday did so because of edits. Which means that they're most likely articles that get edited frequently, i.e. things should get back to normal in the next 48 hours (assuming that the fix works). To put things simply, if an article was edited in the last 24 hours, it's pretty likely that it's going to get edited again in the next 48 hours. There will be a long tail that won't, of course, but I have a feeling it's going to be pretty small traffic-wise, since edit frequency and read traffic tend to be correlated as well.

If global performance metrics are still elevated on Monday, then we can issue a mass purge of all articles if necessary.

Change 630147 merged by jenkins-bot:
[mediawiki/extensions/MobileFrontend@master] Make all section collapsible during server side rendering

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

I confirm that the inline JS and collapsible-block class are back on Beta after purging the test article.

@Jdlrobson @Peter.ovchyn are you deploying the backport today?

I don't have deploy rights, but I can be around to test if necessary. Peter should be finished for the day.

Change 630065 merged by jenkins-bot:
[mediawiki/extensions/MobileFrontend@wmf/1.36.0-wmf.10] Make all section collapsible during server side rendering

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

Mentioned in SAL (#wikimedia-operations) [2020-09-25T17:47:14Z] <lucaswerkmeister-wmde@deploy1001> Synchronized php-1.36.0-wmf.10/extensions/MobileFrontend/: Backport: [[gerrit:630065|Make all section collapsible during server side rendering (T263832)]] (duration: 00m 59s)

I deployed the backport and @Jdlrobson said it was working on mwdebug2001, but I don’t know how to confirm it after deployment. There are lots of screenshots of dashboards in this task, but I haven’t found any of those dashboards yet.

One relevant dashboard should be https://grafana.wikimedia.org/d/000000057/webpagetest-drilldown?orgId=1&var-base=sitespeed_io&var-path=webpagetestEmulatedMobile&var-group=en_m_wikipedia_org&var-page=_wiki_Facebook&var-browser=&var-location=us-east-chrome&var-connectivity=3gfast&var-view=firstView&from=1600812000000&to=1601071199000&refresh=5m – if all is well, the Metrics panel should go back to normal with the next test run, if I understand correctly.

When we rollbacked it got much better but I can see on our new mobile phone setup (running tests on a Moto G5) that we introduced longer CPU tasks (meaning the browser will freeze for the user) than before:

For example pages we test it increased by 400-500 ms. So I think maybe there are work that still needs to be done.

@Jdlrobson @Peter.ovchyn can you think of ways that despite the backported fix the refactor could still cause some amount of new long tasks?

@Peter I'm not seeing the same elevated levels after the revert on WebPageTest, is WebPageReplay the only place where you're seeing this?

In T263832#6497743, @Gilles wrote:

@Peter I'm not seeing the same elevated levels after the revert on WebPageTest, is WebPageReplay the only place where you're seeing this?

I've been working on this over past days, but have no good understanding on what's going on so far. I this some more info could help me:

1. Is there a way to get cached html for certain page at some time. It would be helpful if I could compare htmls for 9/24 16:00 and 9/25 20:00.

2. Could you please give more info (as I'm not 100% aware of all your infra). What do you mean by "revert" word. As far I I understand we didn't revert code, we applied a hotfix, right? Also, what are WebPageTest and WebPageReplay , could I play them locally?

Here's some info about those systems:

WebPageTest
WebPageReplay

@Peter are you talking about the Kobiton WebPageReplay? Is that where that dashboard's data is coming from?

On emulated mobile I see that things have gone back to pre-deployment levels of long tasks: https://grafana.wikimedia.org/d/000000059/webpagereplay-drilldown?orgId=1&var-base=sitespeed_io&var-path=emulatedMobileReplay&var-group=en_m_wikipedia_org&var-page=_wiki_Sweden&var-browser=chrome&var-connectivity=100&var-function=median

If we're only seeing sustained elevated levels on the Kobiton data, I'm not sure it's to be trusted, given how new it is and the fact that WPT and classic WPR have gone back to normal. We don't have historical data to verify either.

@Gilles thanks, that's helpful!

@Gilles yep. I think the data on Kobiton are correct and the others are screwed :) The reason is that I can see that on both Moto G4 and Moto G5. The test on WebPageTest and the test with WebPageReplay/Browsertime run on AWS and I think this is proof of that the CPU on that c5.large hides a lot of problems that we get on lower end phones. However one of the phones lost its internet connection a couple of days ago and it hasn't been fixed yet so it's hard to see numbers across the board.

I checked the metrics again: https://grafana.wikimedia.org/d/bB670cFGk/mobile-performance-synthetic-testing vs https://grafana.wikimedia.org/d/Tw-s6iKMz/mobile-webpagereplay and it is actually only using WebPageReplay that the CPU time spent is higher after the fix, so it that is probably not correct ( even though we have little data for the tests that runs direct against Wikipedia).

@Peter @Gilles is there any way to get snapshots of html of a real page before issue appeared and after? Do we store them somehow?

@Peter.ovchyn you can set that from WebPageTest runs, that's how I discovered the HTML differences before and after the deployment. Explore a particular WPT run and you can look at the list of requests the browser made and get the response body. In my previous comments from Friday you'll find links I posted to WPT runs before and after the problem.

In T263832#6498132, @Gilles wrote:

@Peter.ovchyn you can set that from WebPageTest runs, that's how I discovered the HTML differences before and after the deployment. Explore a particular WPT run and you can look at the list of requests the browser made and get the response body. In my previous comments from Friday you'll find links I posted to WPT runs before and after the problem.

Sorry, there's too much information. Maybe therefore I can't find a link to exact run (or, maybe, list of runs) and html that run was based on. Coun you please point?

following along with @Gilles and @Peter conversation it sounds like nothing further is needed from reading web? Please reach out to me and the team if that's not the case via a new phabricator ticket.

Nothing more is needed, indeed. @Peter.ovchyn I'm happy to point you in the direction of where to look at before/after HTML in WebPageTest with screenshots if you want to learn how to do that.