Closed Bug 1354681 Opened 7 years ago Closed 7 years ago

Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js | Test timed out

Categories

(WebExtensions :: General, defect, P2)

Product:
WebExtensions
Component:
General
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: aryx, Assigned: jmaher)

References

Details

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

Attachments

(2 files)

Bug 1354681 - Intermittent timeout in browser_ext_omnibox.js.
59 bytes, text/x-review-board-request
mattw
: review+
Details
temporarily disable on debug/asan until we get a fix
1.15 KB, patch
gbrown
: review+
Details | Diff | Splinter Review 
https://treeherder.mozilla.org/logviewer.html#?job_id=89644391&repo=autoland

No idea if this got more likely after bug 1353708 landed.

[task 2017-04-07T18:43:49.413443Z] 18:43:49     INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js | Expected "on-input-changed-fired" to have fired with text: "t". - 
[task 2017-04-07T18:43:49.415683Z] 18:43:49     INFO - Buffered messages finished
[task 2017-04-07T18:43:49.417976Z] 18:43:49     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js | Test timed out - 
[task 2017-04-07T18:43:49.421677Z] 18:43:49     INFO - Not taking screenshot here: see the one that was previously logged
[task 2017-04-07T18:43:49.425076Z] 18:43:49     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js | no tasks awaiting on messages - Got ["on-input-entered-fired"], expected []
[task 2017-04-07T18:43:49.427617Z] 18:43:49     INFO - Stack trace:
[task 2017-04-07T18:43:49.431446Z] 18:43:49     INFO -     chrome://mochikit/content/browser-test.js:test_is:911
[task 2017-04-07T18:43:49.433584Z] 18:43:49     INFO -     chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:31
[task 2017-04-07T18:43:49.436041Z] 18:43:49     INFO -     chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:437
[task 2017-04-07T18:43:49.438087Z] 18:43:49     INFO -     timeoutFn@chrome://mochikit/content/browser-test.js:817:9
[task 2017-04-07T18:43:49.440183Z] 18:43:49     INFO -     setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:779:9
[task 2017-04-07T18:43:49.444526Z] 18:43:49     INFO -     Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:655:7
[task 2017-04-07T18:43:49.446718Z] 18:43:49     INFO -     SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:791:59
[task 2017-04-07T18:43:49.452233Z] 18:43:49     INFO - Not taking screenshot here: see the one that was previously logged
[task 2017-04-07T18:43:49.454517Z] 18:43:49     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js | Extension left running at test shutdown - 
[task 2017-04-07T18:43:49.457538Z] 18:43:49     INFO - Stack trace:
[task 2017-04-07T18:43:49.459378Z] 18:43:49     INFO -     chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
[task 2017-04-07T18:43:49.461382Z] 18:43:49     INFO -     chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:437
[task 2017-04-07T18:43:49.464153Z] 18:43:49     INFO -     timeoutFn@chrome://mochikit/content/browser-test.js:817:9
[task 2017-04-07T18:43:49.467629Z] 18:43:49     INFO -     setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:779:9
[task 2017-04-07T18:43:49.471282Z] 18:43:49     INFO -     Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:655:7
[task 2017-04-07T18:43:49.473251Z] 18:43:49     INFO -     SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:791:59
ugh, one thing in this test is SimpleTest.waitForExplicitFinish(); used with add_task, that may not be working as expected (bug 1129936). There is also no finish() call anywhere.

Another problem is that startInputSession doesn't wait for autocomplete to be done. It puts values and then checks gURLBar.popup.richlistbox.children immediately. It should probably do something like this
http://searchfox.org/mozilla-central/rev/78cefe75fb43195e7f5aee1d8042b8d8fc79fc70/browser/base/content/test/urlbar/head.js#159
to properly wait for the search to have returnes results before trying to use them.
I don't know if this solves the problem, but it's worth a try.
Whiteboard: [stockwell needswork]
Hm, unfortunately, even if this doesn't make things worse, it doesn't solve the problem:
https://treeherder.mozilla.org/logviewer.html#?job_id=90120933&repo=try&lineNumber=10029
The screenshow shows "test c" in the awesomebar. I hope someone with more knowledge about this test can chime in.
Based on where the test is failing, I think it might have to do with not waiting for the suggestions to be added here: http://searchfox.org/mozilla-central/source/browser/components/extensions/test/browser/browser_ext_omnibox.js#41. Do you know if _addMatch is asynchronous? If so, maybe we need to figure out a way to have it return a Promise which resolves once it's complete? What do you think?
(In reply to Matthew Wein [:mattw] from comment #7)
> Based on where the test is failing, I think it might have to do with not
> waiting for the suggestions to be added here:
> http://searchfox.org/mozilla-central/source/browser/components/extensions/
> test/browser/browser_ext_omnibox.js#41. Do you know if _addMatch is
> asynchronous? If so, maybe we need to figure out a way to have it return a
> Promise which resolves once it's complete? What do you think?

addMatch is synchronous, it invokes invalidate in the autocomplete widget, that invokes _appendCurrentResult...
all the process is synchronous, thus I don't think that's the problem :(
is it possible to get a fix for this soon rather than later?  We have 250 failures this last week alone- if there is anything I could do to help, please let me know.
May someone in the webext team have a look at this?
It's quite common (I hit it at every try run). I attached all the ideas I had, while that is probably something to do, it's not enough.
Flags: needinfo?(mwein)
(In reply to Marco Bonardo [::mak] from comment #1)
> ugh, one thing in this test is SimpleTest.waitForExplicitFinish(); used with
> add_task, that may not be working as expected (bug 1129936). There is also
> no finish() call anywhere.

waitForExplicitFinish is automatic when calling add_task. But browser tests and plain/chrome mochitests have separate waitForExplicitFinish functions, and the SimpleTest console monitors used to complain if you didn't call the SimpleTest version in browser chrome mochitests.
Comment on attachment 8859225 [details] [diff] [review]
temporarily disable on debug/asan until we get a fix

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

Be aware that there are some opt and pgo failures too. This should eliminate most failures, but a few will persist.
Attachment #8859225 - Flags: review?(gbrown) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/6be239740d80
Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_omnibox.js. temporarily disable on debug and asan. r=gbrown
temporarily disabling this, I assume that the fix that ::mak did will end up with a r+ soon and we can re-enable this test.  AS :gbrown pointed out we have opt/pgo failures (at a much lower rate), so we will see failures here, but continue to get coverage.
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled]
Matt, please look into this ASAP. We really need this being tested properly on debug builds.
Assignee: nobody → mwein
Severity: normal → critical
Priority: -- → P1
(In reply to Joel Maher ( :jmaher) from comment #22)
> temporarily disabling this, I assume that the fix that ::mak did will end up
> with a r+ soon and we can re-enable this test.

my fix is likely correct by itself, but it won't fix the intermittent.
Comment on attachment 8856440 [details]
Bug 1354681 - Intermittent timeout in browser_ext_omnibox.js.

https://reviewboard.mozilla.org/r/128400/#review134456
Attachment #8856440 - Flags: review?(mwein) → review+
when we land this fix, please reenable the test, basically remove the line added here:
https://hg.mozilla.org/mozilla-central/rev/6be239740d80
Pushed by mak77@bonardo.net:
https://hg.mozilla.org/integration/autoland/rev/c5ab3b44dbf1
Intermittent timeout in browser_ext_omnibox.js. r=mattw
Just to be crystal clear and avoid misunderdtandings:

=> THIS HAS NOT FIX YET. MY PATCH DOES NOT FIX THE INTERMITTENT. <=

so leave-open stays.
thanks ::mak
this picked up quite a bit, sitting around 20 failures per week, even this week:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1354681

this is primarily on linux+!debug.

lets keep an eye on this for now.
Assignee: matthewjwein → nobody
Severity: critical → normal
Priority: P1 → P2
I re-enabled the test everywhere in Bug 1406860 with a tweak in the way it waits for matches. Let's see how it goes, I didn't see failures in a large number of retriggers.

In the worst case we can disable it again...
Depends on: 1406860
Whiteboard: [stockwell disabled]
Whiteboard: [stockwell disabled]
Joel, did you mean to change the whiteboard to [stockwell fixed] as opposed to [stockwell disabled]? The test is not disabled.
Flags: needinfo?(matthewjwein) → needinfo?(jmaher)
thanks for catching this, I made a mistake here when I saw my patch from 7 months ago, I now see the fix in bug 1406860.
Flags: needinfo?(jmaher)
Keywords: leave-open
Whiteboard: [stockwell disabled] → [stockwell fixed:other]
I guess it makes sense to also mark this bug as fixed then. I will do so.
Status: NEW → RESOLVED
Closed: 7 years ago
Component: WebExtensions: Untriaged → WebExtensions: General
Resolution: --- → FIXED
Product: Toolkit → WebExtensions
Assignee: nobody → jmaher
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: