1585954 - Intermittent browser/components/search/test/browser/browser_searchbar_openpopup.js | Test timed out | Uncaught exception received from previously timed out test - at chrome://mochitests/content/browser/browser/components/search/test/browser/browser_search

Status: RESOLVED FIXED

(Firefox :: Search, defect, P2)

Description

[Treeherder Bug Filer]

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=269590940&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/Y2iw77TzSeWdl-xOTFHmOQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-10-03T11:15:05.246Z] 11:15:05 INFO - TEST-START | browser/components/search/test/browser/browser_searchbar_openpopup.js
[task 2019-10-03T11:16:35.357Z] 11:16:35 INFO - TEST-PASS | browser/components/search/test/browser/browser_searchbar_openpopup.js | Should have selected all of the text -
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - Leaving test bound focus_change_closes_popup
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - Entering test bound focus_change_closes_small_popup
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - Buffered messages finished
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_searchbar_openpopup.js | Test timed out -
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - GECKO(2200) | [Child 8996, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - Search engine removed: testEngine.xml
[task 2019-10-03T11:16:35.358Z] 11:16:35 INFO - GECKO(2200) | [Child 8996, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-03T11:16:35.359Z] 11:16:35 INFO - GECKO(2200) | [Child 8996, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-03T11:16:35.397Z] 11:16:35 INFO - GECKO(2200) | MEMORY STAT | vsize 2104343MB | vsizeMaxContiguous 65853019MB | residentFast 305MB | heapAllocated 78MB
[task 2019-10-03T11:16:35.397Z] 11:16:35 INFO - TEST-OK | browser/components/search/test/browser/browser_searchbar_openpopup.js | took 90145ms

Comment 1

[Intermittent Failures Robot]

19 failures in 619 pushes (0.031 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 6
• autoland: 13

Platform breakdown:

• windows10-64-qr: 8
• windows10-64: 5
• windows10-64-ccov: 2
• windows7-32: 2
• macosx1014-64-shippable: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1585954&startday=2019-10-04&endday=2019-10-04&tree=all

Comment 2

[Cosmin Sabou [:CosminS]]

Retriggered till here: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&searchStr=windows%2C10%2Cx64%2Cquantumrender%2Cdebug%2Cmochitests%2Ctest-windows10-64-qr%2Fdebug-mochitest-browser-chrome-e10s-4%2Cm%28bc4%29&tochange=effee4ab270cba85ad53b7be844212bc458ec1a6&fromchange=6e61b9db030d34f1c70974b8b6f3610303fb6e94&selectedJob=269976410

Comment 3

[Intermittent Failures Robot]

27 failures in 4292 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 9
• autoland: 18

Platform breakdown:

• windows10-64: 6
• windows10-64-ccov: 4
• windows7-32: 3
• windows10-64-qr: 12
• macosx1014-64-shippable: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1585954&startday=2019-09-30&endday=2019-10-06&tree=all

Comment 4

[Mark Banner (:standard8)]

This looks like a regression from Megabar, the code in the test is:

  gURLBar.focus();

  let promise = promiseEvent(searchPopup, "popupshown");
  // For some reason sending the mouse event immediately doesn't open the popup.
  SimpleTest.executeSoon(() => {
    EventUtils.synthesizeMouseAtCenter(searchIcon, {});
  });
  await promise;

So we're focussing the megabar and then clicking in the middle of the searchIcon. However, the screenshot shows that the Megabar is now covering the search icon...

I suspect this is only intermittent since there's an animation time when focussing the megabar - sometimes we win the race and click the button before megabar finishes expanding.

I guess bug 1586386 might be fixing this?

Comment 5

[Dão Gottwald [:dao]]

(In reply to Mark Banner (:standard8) from comment #4)

This looks like a regression from Megabar, the code in the test is:

  gURLBar.focus();

  let promise = promiseEvent(searchPopup, "popupshown");
  // For some reason sending the mouse event immediately doesn't open the popup.
  SimpleTest.executeSoon(() => {
    EventUtils.synthesizeMouseAtCenter(searchIcon, {});
  });
  await promise;

So we're focussing the megabar and then clicking in the middle of the searchIcon. However, the screenshot shows that the Megabar is now covering the search icon...

I suspect this is only intermittent since there's an animation time when focussing the megabar - sometimes we win the race and click the button before megabar finishes expanding.

I guess bug 1586386 might be fixing this?

Bug 1586232 fixed this by disabling megabar expansion for this test: https://searchfox.org/mozilla-central/rev/7cc0f0e89cb40e43bf5c96906f13d44705401042/browser/components/search/test/browser/browser_searchbar_openpopup.js#63-65

Comment 6

[Intermittent Failures Robot]

1 failures in 4727 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1585954&startday=2020-05-18&endday=2020-05-24&tree=all