Closed Bug 1490639 Opened Last year Closed 2 months ago

TEST-UNEXPECTED-FAIL | [snip]/mozmill/folder-tree-modes/test-mode-switching.js

Categories

(Thunderbird :: Testing Infrastructure, defect)

defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED
Thunderbird 71.0

People

(Reporter: jorgk-bmo, Unassigned)

Details

(Keywords: intermittent-failure, Whiteboard: [Thunderbird-testfailure: Z Linux][Thunderbird-disabled-test])

Attachments

(1 file, 1 obsolete file)

TEST-UNEXPECTED-FAIL | /builds/worker/workspace/build/tests/mozmill/folder-tree-modes/test-mode-switching.js | test-mode-switching.js::test_toggling_modes

This is now our top failing test, mostly seen on Linux.

I went back a bit, and unless I missed something, it was first seen here:
Mon, Sep 3, 2018, 18:07:46
https://treeherder.mozilla.org/#/jobs?repo=comm-central&selectedJob=197235922&revision=5a27c6b6d6c9e02ee6188e9ef88f3a89d9c49cd7

Maybe not much point looking for a regression here. The log back then said:
https://taskcluster-artifacts.net/TvLyZM4SRdGU2sqPMiLloA/0/public/logs/live_backing.log

INFO -  SUMMARY-UNEXPECTED-FAIL | test-mode-switching.js | test-mode-switching.js::test_toggling_modes
INFO -    EXCEPTION: Popup never opened! id=menu_View_Popup, state=showing
INFO -      at: utils.js line 396
INFO -         TimeoutError utils.js:396 13
INFO -         waitFor utils.js:434 11
INFO -         _click_menus test-window-helpers.js:959 9
INFO -         assert_mode_selected test-mode-switching.js:89 17
INFO -         subtest_switch_to_all_folders test-mode-switching.js:135 3
INFO -         test_toggling_modes test-mode-switching.js:259 3

Today's log
https://taskcluster-artifacts.net/UOOVU5DGSKGPv2IEXs8a_Q/0/public/logs/live_backing.log
is almost the same but with:

INFO -  SUMMARY-UNEXPECTED-FAIL | test-mode-switching.js | test-mode-switching.js::test_toggling_modes
INFO -    EXCEPTION: Popup never opened! id=menu_View_Popup, state=closed

NI not as an obligation to fix this, just to draw attention ;-)
Flags: needinfo?(geoff)
Flags: needinfo?(acelists)
Clicking menus in mozmill on Linux was always unreliable.
There is some problem with focus or point where the click event is sent so that the menu popup starts to open but hangs in state=showing forever until the time runs out.

But the case with state=closed is strange.
This adds some waiting to let the mode switch to finish, before continuing the test. This does not seem to fix the test, but should make the mode switching more correct.
Attachment #9013169 - Flags: review?(jorgk)
Comment on attachment 9013169 [details] [diff] [review]
1490639.patch preliminary work [landed and backed out]

Review of attachment 9013169 [details] [diff] [review]:
-----------------------------------------------------------------

::: mail/base/content/folderPane.js
@@ +1471,5 @@
>        }
>      }
> +
> +    this._treeElement.dispatchEvent(new Event("mapRebuilt",
> +      { bubbles: true, cancelable: false }));

So we do this purely to support the tests? Are there more cases like that? At least a comment might help, no?
Comment on attachment 9013169 [details] [diff] [review]
1490639.patch preliminary work [landed and backed out]

Review of attachment 9013169 [details] [diff] [review]:
-----------------------------------------------------------------

::: mail/base/content/folderPane.js
@@ +1471,5 @@
>        }
>      }
> +
> +    this._treeElement.dispatchEvent(new Event("mapRebuilt",
> +      { bubbles: true, cancelable: false }));

Actually, a few lines up (#1455) we already dispatch the same event that no one listens so far. So why do it twice?
Oh, I see it now, the old one is "mapRebuild", the new one "mapRebuilt". Looks like the old one should have been "mapRebuilt" since when it's dispatched, the map has already been rebuilt. And clearly the new one should have a different name, like treeRebuilt or foldersRebuilt.
OK, that badly named event was introduced here: https://hg.mozilla.org/comm-central/rev/809750e4c971
It should have been called "rebuilt" and you can see the grammar problem also in the commit message :-(
add event so that extensions can mutate the folder pane rowMap when it's build, r=bienvenu, 474822

Now we're stuck with this nonsense forever :-(
Comment on attachment 9013169 [details] [diff] [review]
1490639.patch preliminary work [landed and backed out]

OK, let's try it and see whether it becomes better. I've got the permission to change the event name to something more inline with what we do otherwise, like xxx-yyy-zzz.
Attachment #9013169 - Flags: review?(jorgk) → review+
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/8f55290ad6a2
wait for folder mode switch to finish in MozMill tests. r=jorgk
The test failed again in that push on a Sunday night with low server load, so can we see what the see what the screenshots show? The log is the same:

INFO -    EXCEPTION: Popup never opened! id=menu_View_Popup, state=showing
INFO -      at: utils.js line 396
INFO -         TimeoutError utils.js:396 13
INFO -         waitFor utils.js:434 11
INFO -         _click_menus test-window-helpers.js:982 9
INFO -         assert_mode_selected test-mode-switching.js:95 17
INFO -         subtest_switch_to_all_folders test-mode-switching.js:141 3
INFO -         test_toggling_modes test-mode-switching.js:265 3

This is the failing code:
  if (!mc.mozmillModule.isMac) {
    // On OS X the main menu seems not accessible for clicking from mozmill.
    mc.click(view_menu);
95  popuplist = mc.click_menus_in_sequence(view_menupopup, [ { id: modeList_menu.parentNode.id } ], true);
    assert_true(modeList_menu.querySelector('[value="' + baseMode + '"]').hasAttribute("checked"));
    mc.close_popup_sequence(popuplist);
  }
I added this debug:

function set_folder_mode(aTree, aMode, aFunction) {
  let foldersRebuilt = false;
  aTree._treeElement.addEventListener("folder-tree-rebuilt", () => foldersRebuilt = true,
                                      { once: true });
  let date1 = Date.now();
  if (aFunction)
    aFunction(aMode);
  else
    aTree.mode = aMode;
  dump(`=== took ${Date.now()-date1}ms\n`);
  mc.waitFor(() => { dump(`=== foldersRebuilt=${foldersRebuilt}\n`); return foldersRebuilt; });
}

and at least on Windows, the wait loop only runs once. This is what I see:
=== took 5ms
=== foldersRebuilt=true
=== took 375ms
=== foldersRebuilt=true
=== took 422ms
=== foldersRebuilt=true
=== took 375ms
=== foldersRebuilt=true

So based on this, I'd back out the patch.
Yes, it seems to me too now, that the tree.mode does not return until the tree is rebuilt so there is no waiting needed.
Unless we want to keep the waiting for the future when the tree building becomes async :)
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/064d247285aa
backed out changeset 8f55290ad6a2 for not having the desired effect. Mode switch is sync, no waiting required. a=backout
Attachment #9013169 - Attachment description: 1490639.patch preliminary work → 1490639.patch preliminary work [landed and backed out]
Attachment #9013169 - Attachment is obsolete: true
Whiteboard: [Thunderbird-testfailure: Z Linux] → [Thunderbird-testfailure: Z Linux][Thunderbird-disabled-test]
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/0680cc858ed9
switch off failing test-mode-switching.js::test_toggling_modes on Linux. rs=bustage-fix DONTBUILD

Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/77ba41e70f44
re-enable test-mode-switching::test_toggling_modes on Linux. a=backout

Status: NEW → RESOLVED
Closed: 2 months ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 71.0
You need to log in before you can comment on or make changes to this bug.