1307759 - WindowManager.setState should be asynchronous, window.restore() is not immediate

Status: NEW

(WebExtensions :: General, defect, P3)

Description

[Rob Wu [:robwu]]

With the patches from bug 1287007, the browser_ext_windows_update.js test started to fail consistently on the Linux try bot (I cannot reproduce locally on Linux nor Mac).

For example: https://treeherder.mozilla.org/#/jobs?repo=try&revision=8e0d09fb798082f04787f442821a04d886022846&selectedJob=28435584
The relevant part of the test is [1]:

.then(() => updateWindow(windowId, {state: "maximized"}, {state: "STATE_MAXIMIZED"}))
.then(() => updateWindow(windowId, {state: "minimized"}, {state: "STATE_MINIMIZED"}))
.then(() => updateWindow(windowId, {state: "normal"}, {state: "STATE_NORMAL"}))

The first failure is at the third test. The above code ultimately reaches WindowManager.setState in ext-utils.js, which looks like this [2]:

        // Restore sometimes returns the window to its previous state, rather
        // than to the "normal" state, so it may need to be called anywhere from
        // zero to two times.
        window.restore();
        if (window.windowState != window.STATE_NORMAL) {
          window.restore();

From the logging that I added, I inferred that right after the first window.restore() call, window.windowState is immediately STATE_NORMAL. However, the log shows that when the sizemodechange event is fired, it transitions from state 2 (STATE_MINIMIZED) to state 1 (STATE_MAXIMIZED), where state 3 (STATE_NORMAL) was expected.

Based on this observation, I added an artificial delay between the first window.restore() call and the window.windowState check, and the test passed (https://treeherder.mozilla.org/#/jobs?repo=try&revision=555eb5dae9ee&selectedJob=28540495).

What I think that is happening (I didn't check whether the stack really looks like this, but the above logs support this hypothesis):
- restore() calls nsWindow::SetSizeMode(nsSizeMode_Normal)  [3]
- nsWindow::SetSizeMode is called (there is also nsBaseWidget::SetSizeMode, but it is a simple setter without side effects)  [4]
- nsWindow::SetSizeMode calls nsBaseWidget::SetSizeMode, which effectively sets window.windowState to 3 (STATE_NORMAL).
- nsWindow::SetSizeMode calls gtk_window_deiconify to restore the window.
- nsWindow::OnWindowStateEvent is called asynchronously when GTK has restored the window. It was previously maximized, so now window.windowState is 1 (STATE_MAXIMIZED)  [5]


If this analysis is correct, then to solve the problem we can register a sizemodechange event listener before calling restore() (and minimize() / maximize() ?) and only call the callback of browser.windows.update (and .create?) when the state matches the expectation. Don't forget to register a close listener in case the window is closed earlier. Things get even more complex if we have to account for window state changes while waiting for the callback (e.g. two successive calls to windows.update with different states, without waiting for the callback).


To get back to the opening line of this bug report: Those patches at bug 1287007 introduce an extra delay between the execution of browser.tabs.update and the invocation of the callback (due to IPC). This minimal delay is probably sufficient to allow restore() to fully finish (i.e. restore to the previous maximize result). To rule out any other changes from bug 1287007, I ran another test where the only change is the following

          browser.test.sendMessage("check-window", expected);
+          setTimeout(function() {
+            browser.test.sendMessage("check-window", expected);
+          }, 2000);
         });

... and see exactly the same failures: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d08232690662&selectedJob=28600999


[1] http://searchfox.org/mozilla-central/rev/c1e745733c84630821ef53754b627f2c0b0b5202/browser/components/extensions/test/browser/browser_ext_windows_update.js#91
[2] http://searchfox.org/mozilla-central/rev/c1e745733c84630821ef53754b627f2c0b0b5202/browser/components/extensions/ext-utils.js#944
[3] http://searchfox.org/mozilla-central/rev/c1e745733c84630821ef53754b627f2c0b0b5202/dom/base/nsGlobalWindow.cpp#13605
[4] http://searchfox.org/mozilla-central/rev/c1e745733c84630821ef53754b627f2c0b0b5202/widget/gtk/nsWindow.cpp#1271
[5] http://searchfox.org/mozilla-central/rev/c1e745733c84630821ef53754b627f2c0b0b5202/widget/gtk/nsWindow.cpp#3338

Comment 1

[Rob Wu [:robwu]]

Typo, the diff at the end should be:

-          browser.test.sendMessage("check-window", expected);
+          setTimeout(function() {
+            browser.test.sendMessage("check-window", expected);
+          }, 2000);
         });

(the original line was removed, not kept)

Comment 2

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: Bug_1307759___Workaround__window_update_restore_windows_in_maximized_mode_on_Linux__issue_.patch

I've been able to reproduce this issue locally, it is intermittent but it fails often enough to be able to dig into it locally a bit more (and to be able to record one of the failed runs using rr... I love rr, it is amazing)

I've been playing a bit with the failed run replayed by rr, and the behavior that I've observed locally seems to be pretty consistent with what Rob has described in Comment 0.

I've tried to adapt the method using the approaches proposed by Rob:
unfortunately the sizemodechange event doesn't seem to help here because it is fired twice, and so even if we wait for the first sizemodechange the tests fails because the window has been maximized between the first sizemodechange event and the time the test checks for the current window size mode (which is still maximized instead of normal)

I've been able to make this intermittent test to always pass by turning the method into an asynchronous method which always return a promise, and by introducing an artifical delay between the first and the second window.restore() calls.

I'm not really happy of this workaround, especially because it is based on the introduction of an "arbitrary" delay time, anyway I'm attaching the patch to this issue for further discussions.

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

The severity field for this bug is relatively low, S3. However, the bug has 231 votes.
:robwu, could you consider increasing the bug severity?

For more information, please visit auto_nag documentation.

Comment 4

[BugBot (nomail) [:suhaib / :marco/ :calixte]]

The last needinfo from me was triggered in error by recent activity on the bug. I'm clearing the needinfo since this is a very old bug and I don't know if it's still relevant.