Closed Bug 1255985 Opened 4 years ago Closed 3 years ago

Intermittent browser_bookmark_popup.js | Test timed out - | Found a tab after previous test timed out: about:home -

Categories

(Firefox :: Bookmarks & History, defect, P3)

defect

Tracking

()

RESOLVED FIXED
Firefox 54
Tracking Status
firefox52 --- fixed
firefox53 --- fixed
firefox54 --- fixed

People

(Reporter: aryx, Assigned: jaws)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])

Attachments

(1 file)

https://treeherder.mozilla.org/logviewer.html#?job_id=7975353&repo=fx-team

20:03:38     INFO -  108 INFO Entering test bound panel_shown_for_new_bookmarks_mouseover_mouseout
20:03:38     INFO -  109 INFO Console message: [JavaScript Error: "NotFoundError: The operation failed because the requested database object could not be found. For example, an object store did not exist but was being opened." {file: "chrome://browser/content/abouthome/aboutHome.js" line: 155}]
20:03:38     INFO -  110 INFO TEST-PASS | browser/base/content/test/general/browser_bookmark_popup.js | Page should only be starred prior to popupshown if editing bookmark -
20:03:38     INFO -  111 INFO TEST-PASS | browser/base/content/test/general/browser_bookmark_popup.js | Panel should be 'closed' to start test -
20:03:38     INFO -  112 INFO TEST-PASS | browser/base/content/test/general/browser_bookmark_popup.js | Panel should be 'open' after shownPromise is resolved -
20:03:38     INFO -  113 INFO Waiting for mouseover event
20:03:38     INFO -  114 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_bookmark_popup.js | Test timed out -
20:03:38     INFO -  MEMORY STAT | vsize 903MB | vsizeMaxContiguous 4400699MB | residentFast 276MB | heapAllocated 81MB
20:03:38     INFO -  115 INFO TEST-OK | browser/base/content/test/general/browser_bookmark_popup.js | took 45060ms
20:03:38     INFO -  Not taking screenshot here: see the one that was previously logged
20:03:38     INFO -  116 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_bookmark_popup.js | Found a tab after previous test timed out: about:home -
20:03:38     INFO -  117 INFO checking window state
20:03:38     INFO -  118 INFO TEST-START | browser/base/content/test/general/browser_bug1003461-switchtab-override.js
20:03:38     INFO -  119 INFO Entering test bound test_switchtab_override
20:03:38     INFO -  120 INFO Opening first tab
20:03:38     INFO -  121 INFO Wait tab event: load
20:03:38     INFO -  122 INFO Tab event received: load
20:03:38     INFO -  123 INFO Opening and selecting second tab
20:03:38     INFO -  124 INFO Wait for autocomplete
20:03:39     INFO -  125 INFO TEST-PASS | browser/base/content/test/general/browser_bug1003461-switchtab-override.js | The autocomplete popup is correctly open -
20:03:39     INFO -  126 INFO Select second autocomplete popup entry
20:03:39     INFO -  127 INFO TEST-PASS | browser/base/content/test/general/browser_bug1003461-switchtab-override.js | switch to tab entry found -
20:03:39     INFO -  128 INFO Override switch-to-tab
20:03:39     INFO -  129 INFO Wait tab event: load
20:03:39     INFO -  130 INFO gURLBar.value = http://example.org/browser/browser/base/content/test/general/dummy_page.html
20:03:39     INFO -  131 INFO Tab event received: load
20:03:39     INFO -  132 INFO Leaving test bound test_switchtab_override
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
:jaws - It seems this test has been failing intermittently for most of its history. Can you make it better?
Flags: needinfo?(jaws)
I looked at the test, and it is timing out in various places during different test runs. 2/38 runs time out when the following code is run to open the popup:
      EventUtils.synthesizeMouse(bookmarkStar, 10, 10, { clickCount: 2 },
                                 window);
and 36/38 runs time out when the following code is run to open the popup:
      bookmarkStar.click();

We don't get any timeouts when:
      EventUtils.synthesizeKey("D", {accelKey: true}, window);
is run to open the popup, though it occurs much less in the test file.

The test helper function at the top of the test doesn't use BrowserTestUtils.removeTab, and so there could be a race condition with closing the tab before the next subtest begins. I'll attach a patch that changes the test to use BrowserTestUtils.withNewTab instead of openNewForegroundTab.

Paolo, you have a note in head.js about promisePopupHidden being unreliable unless promisePopupShown has been called first. Do you know why it would be unreliable? In this case, the test is hanging on promisePopupShown.
Flags: needinfo?(jaws) → needinfo?(paolo.mozmail)
(In reply to Jared Wein [:jaws] (please needinfo? me) from comment #37)
> Paolo, you have a note in head.js about promisePopupHidden being unreliable
> unless promisePopupShown has been called first. Do you know why it would be
> unreliable? In this case, the test is hanging on promisePopupShown.

The reason for this comment, at least as I observed it in that particular case, was that if you tried to close the panel but you didn't wait for it to be fully opened first, the sequence of events would sometimes confuse the logic in promisePopupHidden.

I believe this can be related to the additional "showing" and "hiding" popup states. It's possible that the four panel states won't reliably predict whether a future "popupshowing" or "popuphiding" event is to be expected. In this case, there would be no way to write a robust promisePopupEvent function that works in whatever circumstance it's called.

A careful review of the popup code would reveal if that's the case. In particular, worth looking into how the event handlers are called, what happens if the panel is opened or closed from within in the event handlers themselves, and what happens in the event loop ticks and Promise microtasks that immediately follow the event handlers.
Flags: needinfo?(paolo.mozmail)
Comment on attachment 8830909 [details]
Bug 1255985 - Switch from using BrowserTestUtils.openNewForegroundTab to .withNewTab to make sure that we yield until the tab is fully closed.

https://reviewboard.mozilla.org/r/107578/#review108898

It's worth making this change anyways.

::: browser/base/content/test/general/browser_bookmark_popup.js:19
(Diff revision 1)
>  
>  StarUI._closePanelQuickForTesting = true;
>  
>  function* test_bookmarks_popup({isNewBookmark, popupShowFn, popupEditFn,
>                                  shouldAutoClose, popupHideFn, isBookmarkRemoved}) {
> -  let tab = yield BrowserTestUtils.openNewForegroundTab(gBrowser, "about:home");
> +  yield BrowserTestUtils.withNewTab({gBrowser, url: "about:home"}, function*(linkedBrowser) {

nit: the argument is usually called just "browser"
Attachment #8830909 - Flags: review?(paolo.mozmail) → review+
Assignee: nobody → jaws
Status: NEW → ASSIGNED
Pushed by jwein@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/222e3a9abd94
Switch from using BrowserTestUtils.openNewForegroundTab to .withNewTab to make sure that we yield until the tab is fully closed. r=Paolo
https://hg.mozilla.org/mozilla-central/rev/222e3a9abd94
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 54
Whiteboard: [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.