Closed Bug 1416103 Opened 3 years ago Closed 3 years ago

Intermittent browser/components/extensions/test/browser/browser_ext_omnibox.js | Uncaught exception - Waiting for the autocomplete result for "test 7" at [2] to appear - timed out after 50 tries.

Categories

(WebExtensions :: General, defect, P2)

Product:
WebExtensions
Component:
General
Type:
defect

Tracking

(firefox-esr60 wontfix, firefox62 fixed, firefox63 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla63
Tracking Flags:
Tracking Status
firefox-esr60 --- wontfix
firefox62 --- fixed
firefox63 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: robwu)

References

Details

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

Attachments

(1 file)

Bug 1416103 - Re-enable browser_ext_omnibox.js everywhere
59 bytes, text/x-review-board-request
aswan
: review+
Details
See Also: → 1415908
There are 40 failures in the last 7 days.
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1416103&startday=2018-02-17&endday=2018-02-24&tree=all

Platforms:
- Linux, Linux x64, linux32-stylo-disabled, linux64-stylo-disabled - debug
- Windows10-64-ccov - debug

Recent log failure:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=164080861&lineNumber=25953

Relevant part of the log:

INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_omnibox.js | Expected "on-input-changed-fired" to have fired with text: "7". - 
[task 2018-02-24T02:12:02.443Z] 02:12:02     INFO - Buffered messages finished
[task 2018-02-24T02:12:02.444Z] 02:12:02     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_omnibox.js | Uncaught exception - Waiting for the autocomplete result for "test 7" at [2] to appear - timed out after 50 tries.
[task 2018-02-24T02:12:02.444Z] 02:12:02     INFO - Leaving test bound 
[task 2018-02-24T02:12:02.445Z] 02:12:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-02-24T02:12:02.445Z] 02:12:02     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_omnibox.js | Extension left running at test shutdown - 
[task 2018-02-24T02:12:02.446Z] 02:12:02     INFO - Stack trace:
[task 2018-02-24T02:12:02.446Z] 02:12:02     INFO -     chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
[task 2018-02-24T02:12:02.461Z] 02:12:02     INFO -     chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:666
[task 2018-02-24T02:12:02.462Z] 02:12:02     INFO -     testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1363:11
[task 2018-02-24T02:12:02.462Z] 02:12:02     INFO -     run@chrome://mochikit/content/browser-test.js:1300:9
[task 2018-02-24T02:12:02.464Z] 02:12:02     INFO - GECKO(1046) | MEMORY STAT | vsize 1411MB | residentFast 426MB | heapAllocated 113MB
[task 2018-02-24T02:12:02.465Z] 02:12:02     INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_omnibox.js | took 18626ms

:ddurst, can you please take a look?
Flags: needinfo?(ddurst)
Whiteboard: [stockwell unknown] → [stockwell needswork]
Since 25th February there already are 31 failures.
:ddurst could you please take a look?
The test fails very often with patch from bug 1373708 (around 0.2 failures/push on try). To reproduce it locally, running it under rr makes it to fail in ~50% cases. Marco, you've fixed failures of this test in bug 1416142. Could you please have a look at this bug too?
Flags: needinfo?(mak77)
I may not have the time to look into this for at least another couple days, due to piled up last minute issues. I'm also not sure the fix for bug 1416142 may help us here at all.
In the meanwhile, it may be useful to check if increasing the timeout of requestIdleCallback helps, since you seem to be able to reproduce the failure more often.
It may also be useful to explain the behavior differences to expect with the landing of bug 1373708.
(In reply to Marco Bonardo [::mak] from comment #21)
> I may not have the time to look into this for at least another couple days,
> due to piled up last minute issues. I'm also not sure the fix for bug
> 1416142 may help us here at all.

The test was disabled by bug 1417052, so this no longer blocks async JAR bug. 

> In the meanwhile, it may be useful to check if increasing the timeout of
> requestIdleCallback helps, since you seem to be able to reproduce the
> failure more often.

This didn't help. I tried to increase all timeouts I could find in the test (both window.requestIdleCallback and BrowserTestUtils.waitForCondition).

> It may also be useful to explain the behavior differences to expect with the
> landing of bug 1373708.

The patch 1373708 moves blocking IO to a background thread, so its effect is that it no longer blocks main thread, but delivering of the data from the JAR channel can start a bit later.
(In reply to Michal Novotny (:michal) from comment #23)
> (In reply to Marco Bonardo [::mak] from comment #21)
> > I may not have the time to look into this for at least another couple days,
> > due to piled up last minute issues. I'm also not sure the fix for bug
> > 1416142 may help us here at all.
> 
> The test was disabled by bug 1417052, so this no longer blocks async JAR
> bug. 

AFAICT that is only a partial disable on lin/mac debug. If it would be complete we'd have lost testing of this API completely, and that wouldn't be good.
Are those 2 enough to prevent your failures?
I've done few retries on the try server and the test failed twice in 372 runs on windows. This seems to be similar ratio to what's reported in this bug without the JAR patch.
ok, good. I'll also track this in the search team backlog. It's possible the add-ons team figures out something before us, anyway whoever finds something is welcome to help.
It would be great to re-enable the test everywhere, since we have reduced CCOV now.
Priority: -- → P2
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][fxsearch]
For now there's no huge emergency and we're short on resources, it will keep being tracked.
Flags: needinfo?(mak77)
Product: Toolkit → WebExtensions
I think that this bug has the same cause as bug 1417052.

waitForAutocompleteResultAt wait for the presence of a search result at a specific index.
However, because other tests can inadvertently pollute the search result set, the test stalls because the menu item at the given position will never match the expected result.

I will wait for the patch to bug 1417052 to land, and then remove the skip-if at browser_ext_omnibox.js to see if the issue is resolved.
Assignee: nobody → rob
Status: NEW → ASSIGNED
Flags: needinfo?(ddurst)
Comment on attachment 8997815 [details]
Bug 1416103 - Re-enable browser_ext_omnibox.js everywhere

https://reviewboard.mozilla.org/r/261530/#review268638

thanks
Attachment #8997815 - Flags: review?(aswan) → review+
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/136c3952bbe0
Re-enable browser_ext_omnibox.js everywhere r=aswan
https://hg.mozilla.org/mozilla-central/rev/136c3952bbe0
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
status-firefox63: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla63
https://hg.mozilla.org/releases/mozilla-beta/rev/1a80ac4f1ab7
status-firefox62: --- → fixed
Flags: in-testsuite+
Whiteboard: [fxsearch][stockwell unknown] → [fxsearch][stockwell fixed]
You need to log in before you can comment on or make changes to this bug.