Page MenuHomePhabricator

[Regression wmf.4] "Publish Changes" button stays disabled while trying to re-edit a page
Closed, ResolvedPublic

Description

Steps to reproduce:

  1. Open VE
  2. Make an edit
  3. Save the edit
  4. Re-open VE
  5. Make another edit

Observe that, the "Publish Changes" button are not getting enabled, user can't make anymore edit.

Event Timeline

Ryasmeen renamed this task from [Regression pre-wmf.6] "Publish Changes" button stays disabled while trying to re-edit a page to [Regression pre-wmf.6] "Publish Changes" button stays disabled while trying to re-edit a page on Firefox.Nov 14 2018, 11:22 PM

@matmarex: Did you try on Firefox? This is specific to Firefox browser.

That is Firefox 64 on Windows 10.

I was able to replicate it this morning, but not anymore. I think this was related to T209451. So maybe it's now fixed.

matmarex changed the task status from Open to Stalled.Nov 15 2018, 11:29 PM
Ryasmeen renamed this task from [Regression pre-wmf.6] "Publish Changes" button stays disabled while trying to re-edit a page on Firefox to [Regression wmf.4] "Publish Changes" button stays disabled while trying to re-edit a page .Nov 26 2018, 9:33 PM
Ryasmeen changed the task status from Stalled to Open.
Ryasmeen added subscribers: TerraCodes, Esanders.

This is actually a regression from wmf.4, since I can replicate it on en.wiki by following the exact same steps.

User:Popcornduff can reproduce this in Chrome at the English Wikipedia.

I think I identified the cause of the problem: rEVEDb2718b186abc: Separate handling of document HTML and edit metadata.

In short: we accidentally removed an early return statement when moving code around, which in rare cases (editing a page that was very recently edited) causes the editor to attempt to load twice, in turn causing this bug.

Details below. Maybe this helps someone debug or avoid a similar problem in the future.


What seems to be happening is that the event handler ve.init.mw.ArticleTarget#updateToolbarSaveButtonState, which should be bound to ve.dm.Surface history event, is mysteriously missing. This method is responsible for enabling/disabling the "Publish" button.

I found that there is only one place where this handler is bound (ve.init.mw.ArticleTarget#surfaceReady) and only one where it is removed (ve.init.mw.ArticleTarget#teardown), so my working theory was that either teardown is called too soon, or ready is not called at all.

I started investigating the first idea (it's a lot easier to find out why something happens than why it doesn't happen, since you can put breakpoints on it). I spent a lot more time trying to see if teardown was being called too soon and being frustrated by the issue magically disappearing when I tried to debug it¹.

At first I found and investigated the code which creates and then tears down a "dummy surface", which is never shown, and its purpose is to allow the toolbar to be created while we're loading the page, rather than afterwards. But this didn't look like the cause of the problem.

Finally I placed breakpoints all over the place and found that ve.init.mw.ArticleTarget#surfaceReady was sometimes called twice during loading the editor with two difference surfaces. First time, it sets up everything with the first surface; then it is called with the second surface, but at this point the Target is in a broken state and it thinks loading the editor was cancelled and it does nothing with the second surface (this happens in ve.init.mw.DesktopArticleTarget#surfaceReady). So our event handler on the second surface (the one that ends up being used) is never bound!

Why is it called twice? I compared the two stack traces to find what is calling the method (copied from Chrome's debugger).

1ve.init.mw.DesktopArticleTarget.surfaceReady (ve.init.mw.DesktopArticleTarget.js?8546c:778)
2(anonymous) (ve.init.mw.Target.js?dcd59:398)
3setTimeout (async)
4ve.init.mw.Target.addSurface (ve.init.mw.Target.js?dcd59:388)
5ve.init.mw.DesktopArticleTarget.addSurface (ve.init.mw.DesktopArticleTarget.js?8546c:176)
6(anonymous) (ve.init.mw.Target.js?dcd59:359)
7setTimeout (async)
8(anonymous) (ve.init.mw.Target.js?dcd59:358)
9setTimeout (async)
10ve.init.mw.Target.setupSurface (ve.init.mw.Target.js?dcd59:345)
11ve.init.mw.Target.documentReady (ve.init.mw.Target.js?dcd59:217)
12ve.init.mw.ArticleTarget.documentReady (ve.init.mw.ArticleTarget.js?bc214:497)
13ve.init.mw.ArticleTarget.loadSuccess (ve.init.mw.ArticleTarget.js?bc214:356)
14ve.init.mw.DesktopArticleTarget.loadSuccess (ve.init.mw.DesktopArticleTarget.js?8546c:338)
15fire (jquery.js?6a07d:3268)
16fireWith (jquery.js?6a07d:3398)
17mightThrow (jquery.js?6a07d:3593)
18process (jquery.js?6a07d:3602)
19setTimeout (async)
20(anonymous) (jquery.js?6a07d:3640)
21fire (jquery.js?6a07d:3268)
22fireWith (jquery.js?6a07d:3398)
23fire (jquery.js?6a07d:3406)
24fire (jquery.js?6a07d:3268)
25fireWith (jquery.js?6a07d:3398)
26(anonymous) (jquery.js?6a07d:3781)
27fire (jquery.js?6a07d:3268)
28fireWith (jquery.js?6a07d:3398)
29mightThrow (jquery.js?6a07d:3593)
30process (jquery.js?6a07d:3602)
31setTimeout (async)
32(anonymous) (jquery.js?6a07d:3640)
33fire (jquery.js?6a07d:3268)
34fireWith (jquery.js?6a07d:3398)
35fire (jquery.js?6a07d:3406)
36fire (jquery.js?6a07d:3268)
37fireWith (jquery.js?6a07d:3398)
38deferred.(anonymous function) (jquery.js?6a07d:3736)
39(anonymous) (index.js?75efe:277)
40fire (jquery.js?6a07d:3268)
41fireWith (jquery.js?6a07d:3398)
42done (jquery.js?6a07d:9305)
43(anonymous) (jquery.js?6a07d:9548)
44load (async)
45send (jquery.js?6a07d:9567)
46ajax (jquery.js?6a07d:9206)
47jQuery.ajax (jquery.migrate.js?cacf7:233)
48ajax (index.js?75efe:249)
49get (index.js?75efe:137)
50requestParsoidData (ve.init.mw.ArticleTargetLoader.js?e0c8f:222)
51requestPageData (ve.init.mw.ArticleTargetLoader.js?e0c8f:178)
52ve.init.mw.ArticleTarget.load (ve.init.mw.ArticleTarget.js?bc214:1324)
53ve.init.mw.DesktopArticleTarget.activate (ve.init.mw.DesktopArticleTarget.js?8546c:467)
54(anonymous) (ve.init.mw.DesktopArticleTarget.init.js?3a978:415)
55mightThrow (jquery.js?6a07d:3534)
56process (jquery.js?6a07d:3602)
57setTimeout (async)
58(anonymous) (jquery.js?6a07d:3640)
59fire (jquery.js?6a07d:3268)
60add (jquery.js?6a07d:3327)
61(anonymous) (jquery.js?6a07d:3660)
62jQuery.Deferred (jquery.migrate.js?cacf7:616)
63then (jquery.js?6a07d:3645)
64activateTarget (ve.init.mw.DesktopArticleTarget.init.js?3a978:401)
65activatePageTarget (ve.init.mw.DesktopArticleTarget.init.js?3a978:453)
66activateVe (ve.init.mw.DesktopArticleTarget.init.js?3a978:934)
67onEditTabClick (ve.init.mw.DesktopArticleTarget.init.js?3a978:880)
68dispatch (jquery.js?6a07d:5183)
69elemData.handle (jquery.js?6a07d:4991)
1ve.init.mw.DesktopArticleTarget.surfaceReady (ve.init.mw.DesktopArticleTarget.js?8546c:778)
2(anonymous) (ve.init.mw.Target.js?dcd59:398)
3setTimeout (async)
4ve.init.mw.Target.addSurface (ve.init.mw.Target.js?dcd59:388)
5ve.init.mw.DesktopArticleTarget.addSurface (ve.init.mw.DesktopArticleTarget.js?8546c:176)
6(anonymous) (ve.init.mw.Target.js?dcd59:359)
7setTimeout (async)
8(anonymous) (ve.init.mw.Target.js?dcd59:358)
9setTimeout (async)
10ve.init.mw.Target.setupSurface (ve.init.mw.Target.js?dcd59:345)
11ve.init.mw.Target.documentReady (ve.init.mw.Target.js?dcd59:217)
12ve.init.mw.ArticleTarget.documentReady (ve.init.mw.ArticleTarget.js?bc214:497)
13ve.init.mw.ArticleTarget.loadSuccess (ve.init.mw.ArticleTarget.js?bc214:356)
14ve.init.mw.DesktopArticleTarget.loadSuccess (ve.init.mw.DesktopArticleTarget.js?8546c:338)
15fire (jquery.js?6a07d:3268)
16fireWith (jquery.js?6a07d:3398)
17mightThrow (jquery.js?6a07d:3593)
18process (jquery.js?6a07d:3602)
19setTimeout (async)
20(anonymous) (jquery.js?6a07d:3640)
21fire (jquery.js?6a07d:3268)
22fireWith (jquery.js?6a07d:3398)
23fire (jquery.js?6a07d:3406)
24fire (jquery.js?6a07d:3268)
25fireWith (jquery.js?6a07d:3398)
26(anonymous) (jquery.js?6a07d:3781)
27fire (jquery.js?6a07d:3268)
28fireWith (jquery.js?6a07d:3398)
29mightThrow (jquery.js?6a07d:3593)
30process (jquery.js?6a07d:3602)
31setTimeout (async)
32(anonymous) (jquery.js?6a07d:3640)
33fire (jquery.js?6a07d:3268)
34fireWith (jquery.js?6a07d:3398)
35fire (jquery.js?6a07d:3406)
36fire (jquery.js?6a07d:3268)
37fireWith (jquery.js?6a07d:3398)
38deferred.(anonymous function) (jquery.js?6a07d:3736)
39(anonymous) (index.js?75efe:277)
40fire (jquery.js?6a07d:3268)
41fireWith (jquery.js?6a07d:3398)
42done (jquery.js?6a07d:9305)
43(anonymous) (jquery.js?6a07d:9548)
44load (async)
45send (jquery.js?6a07d:9567)
46ajax (jquery.js?6a07d:9206)
47jQuery.ajax (jquery.migrate.js?cacf7:233)
48ajax (index.js?75efe:249)
49get (index.js?75efe:137)
50requestParsoidData (ve.init.mw.ArticleTargetLoader.js?e0c8f:222)
51requestPageData (ve.init.mw.ArticleTargetLoader.js?e0c8f:178)
52ve.init.mw.ArticleTarget.load (ve.init.mw.ArticleTarget.js?bc214:1324)
53ve.init.mw.ArticleTarget.parseMetadata (ve.init.mw.ArticleTarget.js?bc214:436)
54ve.init.mw.ArticleTarget.loadSuccess (ve.init.mw.ArticleTarget.js?bc214:347)
55ve.init.mw.DesktopArticleTarget.loadSuccess (ve.init.mw.DesktopArticleTarget.js?8546c:338)
56fire (jquery.js?6a07d:3268)
57fireWith (jquery.js?6a07d:3398)
58mightThrow (jquery.js?6a07d:3593)
59process (jquery.js?6a07d:3602)
60setTimeout (async)
61(anonymous) (jquery.js?6a07d:3640)
62fire (jquery.js?6a07d:3268)
63fireWith (jquery.js?6a07d:3398)
64fire (jquery.js?6a07d:3406)
65fire (jquery.js?6a07d:3268)
66fireWith (jquery.js?6a07d:3398)
67(anonymous) (jquery.js?6a07d:3781)
68fire (jquery.js?6a07d:3268)
69fireWith (jquery.js?6a07d:3398)
70mightThrow (jquery.js?6a07d:3593)
71process (jquery.js?6a07d:3602)
72setTimeout (async)
73(anonymous) (jquery.js?6a07d:3640)
74fire (jquery.js?6a07d:3268)
75fireWith (jquery.js?6a07d:3398)
76fire (jquery.js?6a07d:3406)
77fire (jquery.js?6a07d:3268)
78fireWith (jquery.js?6a07d:3398)
79deferred.(anonymous function) (jquery.js?6a07d:3736)
80(anonymous) (index.js?75efe:277)
81fire (jquery.js?6a07d:3268)
82fireWith (jquery.js?6a07d:3398)
83done (jquery.js?6a07d:9305)
84(anonymous) (jquery.js?6a07d:9548)
85load (async)
86send (jquery.js?6a07d:9567)
87ajax (jquery.js?6a07d:9206)
88jQuery.ajax (jquery.migrate.js?cacf7:233)
89ajax (index.js?75efe:249)
90get (index.js?75efe:137)
91requestParsoidData (ve.init.mw.ArticleTargetLoader.js?e0c8f:222)
92requestPageData (ve.init.mw.ArticleTargetLoader.js?e0c8f:178)
93ve.init.mw.ArticleTarget.load (ve.init.mw.ArticleTarget.js?bc214:1324)
94ve.init.mw.DesktopArticleTarget.activate (ve.init.mw.DesktopArticleTarget.js?8546c:467)
95(anonymous) (ve.init.mw.DesktopArticleTarget.init.js?3a978:415)
96mightThrow (jquery.js?6a07d:3534)
97process (jquery.js?6a07d:3602)
98setTimeout (async)
99(anonymous) (jquery.js?6a07d:3640)
100fire (jquery.js?6a07d:3268)
101add (jquery.js?6a07d:3327)
102(anonymous) (jquery.js?6a07d:3660)
103jQuery.Deferred (jquery.migrate.js?cacf7:616)
104then (jquery.js?6a07d:3645)
105activateTarget (ve.init.mw.DesktopArticleTarget.init.js?3a978:401)
106activatePageTarget (ve.init.mw.DesktopArticleTarget.init.js?3a978:453)
107activateVe (ve.init.mw.DesktopArticleTarget.init.js?3a978:934)
108onEditTabClick (ve.init.mw.DesktopArticleTarget.init.js?3a978:880)
109dispatch (jquery.js?6a07d:5183)
110elemData.handle (jquery.js?6a07d:4991)

The top and bottom end of them is very similar, the difference is in the middle. The first one is reached via ve.init.mw.ArticleTarget.load, while the second via ve.init.mw.ArticleTarget.load→ve.init.mw.ArticleTarget.parseMetadata→ve.init.mw.ArticleTarget.load (recursively calling load() twice). Apparently the issue occurs when we have to retry loading the page content!

Background: to open the editor, VisualEditor has to separately download page content and page metadata². In the configuration used on Wikipedia, page content is downloaded from RESTBase, while page metadata is downloaded from MediaWiki API³. Unfortunately, due to caching, the data returned by those services can be generated from a different revisions of the page – especially if the page was very recently edited. When this occurs, we retry, explicitly specifying we want to edit the more recent of the two revisions that we got the results for⁴.

Apparently changes in rEVEDb2718b186abc: Separate handling of document HTML and edit metadata made it so that retrying does not abort the current attempt to load the page. Both the original load and the retried load complete, setting up two surfaces (you can actually see the first surface with the old page content appear for a fraction of a second – not that you can tell the difference when editing a real article).

It's actually a wonder that nothing else breaks when this happens. Every feature of the editor appears to work correctly, except for the "Publish" button. (And I suppose it might cause some weirdness when we log event timings – we might have two "load success" events for some "load attempt" events?)

¹ I can now guess that pausing the process at various breakpoints made it slow enough that I never ran into the case where RESTBase returns cached data belonging to a different revision and we have to retry loading, which is necessary to trigger this bug.
² This includes: edit notices; configuration for checkboxes in the save form (this depends on whether user is allowed to watch the page, mark edit as minor, or mark edit as reviewed through FlaggedRevs/PendingChanges); list of templates and redlinks on the page.
³ You can also configure it to download both of these from MediaWiki API, in which case the issue does not occur. I use this configuration locally, which is why I couldn't reproduce. This way is slower, since MediaWiki API itself has to get the page content from RESTBase.
⁴ Why not always specify we want to edit the latest revision of the page? Because someone else might have edited the page while you were reading it, so the latest revision VisualEditor knows of (the one you're reading) might not be the real latest revision. Figuring out which is the real latest revision would require another API query, making loading slower in the common case.

Change 476442 had a related patch set uploaded (by Bartosz Dziewoński; owner: Bartosz Dziewoński):
[mediawiki/extensions/VisualEditor@master] ve.init.mw.ArticleTarget: Stop when we fail to load metadata

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

Change 476442 merged by jenkins-bot:
[mediawiki/extensions/VisualEditor@master] ve.init.mw.ArticleTarget: Stop when we fail to load metadata

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

Change 476761 had a related patch set uploaded (by Bartosz Dziewoński; owner: Bartosz Dziewoński):
[mediawiki/extensions/VisualEditor@wmf/1.33.0-wmf.4] ve.init.mw.ArticleTarget: Stop when we fail to load metadata

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

Change 476762 had a related patch set uploaded (by Bartosz Dziewoński; owner: Bartosz Dziewoński):
[mediawiki/extensions/VisualEditor@wmf/1.33.0-wmf.6] ve.init.mw.ArticleTarget: Stop when we fail to load metadata

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

Change 476761 abandoned by Bartosz Dziewoński:
ve.init.mw.ArticleTarget: Stop when we fail to load metadata

Reason:
No longer needed, 1.33.0-wmf.6 was deployed everywhere

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

Change 476762 merged by jenkins-bot:
[mediawiki/extensions/VisualEditor@wmf/1.33.0-wmf.6] ve.init.mw.ArticleTarget: Stop when we fail to load metadata

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

Mentioned in SAL (#wikimedia-operations) [2018-11-30T00:57:36Z] <thcipriani@deploy1001> Synchronized php-1.33.0-wmf.6/extensions/VisualEditor: SWAT: [[gerrit:476612|Rename configs for tracking block notices on visual editor]] [[gerrit:476762|ve.init.mw.ArticleTarget: Stop when we fail to load metadata]] T209542 (duration: 00m 48s)