Closed Bug 1332862 Opened 7 years ago Closed 7 years ago

Intermittent dom/browser-element/mochitest/test_browserElement_inproc_AudioPlayback.html, test_browserElement_inproc_BackForward.html | Assertion count 6 is greater than expected range 0-0 assertions.

Categories

(Core :: DOM: Core & HTML, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla56
Tracking Status
firefox56 --- fixed

People

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

References

Details

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

Attachments

(2 files)

See Also: → 1332850
https://public-artifacts.taskcluster.net/H5PtdZDJTwqqVttETeYUsg/0/public/test_info//logcat-emulator-5554.log

01-23 09:34:37.345   788   808 I Gecko   : [Parent 788] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3329
01-23 09:34:37.355   788   808 I Gecko   : [Parent 788] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3329
01-23 09:34:37.355   788   808 I Gecko   : [Parent 788] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3329
01-23 09:34:37.355   788   808 I Gecko   : [Parent 788] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3329
01-23 09:34:37.355   788   808 I Gecko   : [Parent 788] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3329
01-23 09:34:37.804   788   808 D GeckoIdleService: Registering Idle observer callback
01-23 09:34:37.804   788   808 D GeckoIdleService: Register idle observer 0x5537c180 for 180 seconds
01-23 09:34:37.804   788   808 D GeckoIdleService: Register: adjusting next switch from -1 to 180 seconds
01-23 09:34:37.814   788   808 D GeckoIdleService: next timeout 179987 msec from now
01-23 09:34:37.814   788   808 D GeckoIdleService: SetTimerExpiryIfBefore: next timeout 179985 msec from now
01-23 09:34:37.814   788   808 D GeckoIdleService: reset timer expiry to 179994 msec from now
01-23 09:34:38.325   788   827 I Gecko   : [Parent 788] WARNING: waitpid failed pid:1375 errno:10: file /home/worker/workspace/build/src/ipc/chromium/src/base/process_util_posix.cc, line 276
01-23 09:34:38.535  1375  1388 I Gecko   : 
01-23 09:34:38.535  1375  1388 I Gecko   : ###!!! [Child][MessageChannel] Error: (msgtype=0x4400FC,name=PContent::Msg_AccumulateChildHistogram) Closed channel: cannot send/recv
01-23 09:34:38.535  1375  1388 I Gecko   : 
01-23 09:34:38.535  1375  1388 I Gecko   : [Child 1375] WARNING: MsgDropped in ContentChild: file /home/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 2143
01-23 09:34:38.555  1375  1388 I Gecko   : [Child 1375] WARNING: '!contentChild->SendAccumulateChildHistogram(accumulationsToSend)', file /home/worker/workspace/build/src/toolkit/components/telemetry/TelemetryIPCAccumulator.cpp, line 209
01-23 09:34:38.555  1375  1388 I Gecko   : [Child 1375] ###!!! ASSERTION: Potential deadlock detected:
01-23 09:34:38.555  1375  1388 I Gecko   : Cyclical dependency starts at
01-23 09:34:38.555  1375  1388 I Gecko   : Mutex : nsAppShell.Queue
01-23 09:34:38.555  1375  1388 I Gecko   : Next dependency:
01-23 09:34:38.555  1375  1388 I Gecko   : Mutex : StaticMutex
01-23 09:34:38.555  1375  1388 I Gecko   : Next dependency:
01-23 09:34:38.555  1375  1388 I Gecko   : Mutex : StaticMutex
01-23 09:34:38.555  1375  1388 I Gecko   : Next dependency:
01-23 09:34:38.555  1375  1388 I Gecko   : Mutex : TimerThread.mMonitor
01-23 09:34:38.555  1375  1388 I Gecko   : Next dependency:
01-23 09:34:38.555  1375  1388 I Gecko   : ReentrantMonitor : SharedThreadPool (currently acquired)
01-23 09:34:38.555  1375  1388 I Gecko   : Cycle completed at
01-23 09:34:38.555  1375  1388 I Gecko   : Mutex : nsAppShell.Queue
01-23 09:34:38.555  1375  1388 I Gecko   : Deadlock may happen for some other execution
01-23 09:34:38.555  1375  1388 I Gecko   : 
01-23 09:34:38.555  1375  1388 I Gecko   : : 'Error', file /home/worker/workspace/build/src/xpcom/glue/BlockingResourceBase.cpp, line 307
01-23 09:34:39.265  1375  1388 I Gecko   : [Child 1375] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file /home/worker/workspace/build/src/xpcom/threads/nsThread.cpp, line 1004
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → DUPLICATE
Because we break a lot of things in a lot of ways all at once, this wasn't actually just an Android bug from the test being enabled on Android, it also fails on other platforms.
Assignee: gbrown → nobody
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
while Android was the most offensive, we still have many other instances on linux and osx.
On linux and osx, we typically hit 6 to 10 instances of

[task 2017-01-31T00:38:25.842721Z] 00:38:25     INFO - TEST-START | dom/browser-element/mochitest/test_browserElement_inproc_AudioPlayback.html
[task 2017-01-31T00:38:25.870136Z] 00:38:25     INFO - [Parent 4959] ###!!! ASSERTION: AreDialogsEnabled() called without a top window?: 'Error', file /home/worker/workspace/build/src/dom/base/nsGlobalWindow.cpp, line 3338
[task 2017-01-31T00:38:56.350181Z] 00:38:56     INFO - #01: nsGlobalWindow::AlertOrConfirm [dom/base/nsGlobalWindow.cpp:6941]
[task 2017-01-31T00:38:56.351249Z] 00:38:56     INFO - 
[task 2017-01-31T00:38:56.351327Z] 00:38:56     INFO - #02: mozilla::dom::WindowBinding::alert [obj-firefox/dom/bindings/WindowBinding.cpp:2595]
[task 2017-01-31T00:38:56.352025Z] 00:38:56     INFO - 
[task 2017-01-31T00:38:56.352118Z] 00:38:56     INFO - #03: mozilla::dom::WindowBinding::genericMethod [obj-firefox/dom/bindings/WindowBinding.cpp:15425]
[task 2017-01-31T00:38:56.352755Z] 00:38:56     INFO - 
[task 2017-01-31T00:38:56.353453Z] 00:38:56     INFO - #04: ??? (???:???)
I don't see any recent changes that look related to this frequent intermittent failure. The AreDialogsEnabled() assertion has been in place for a long time and doesn't seem to be hit during other tests. 

Andrew - Would it be okay to allow assertions in this test (mark with something like expectAssertions(0,10)) ?
Flags: needinfo?(overholt)
(In reply to Geoff Brown [:gbrown] from comment #10)
> I don't see any recent changes that look related to this frequent
> intermittent failure. The AreDialogsEnabled() assertion has been in place
> for a long time and doesn't seem to be hit during other tests. 
> 
> Andrew - Would it be okay to allow assertions in this test (mark with
> something like expectAssertions(0,10)) ?

I don't know but Gabor or maybe baku probably do.
Flags: needinfo?(overholt)
Flags: needinfo?(gkrizsanits)
Flags: needinfo?(amarchesini)
(In reply to Geoff Brown [:gbrown] from comment #10)
> I don't see any recent changes that look related to this frequent
> intermittent failure. The AreDialogsEnabled() assertion has been in place
> for a long time and doesn't seem to be hit during other tests. 
> 
> Andrew - Would it be okay to allow assertions in this test (mark with
> something like expectAssertions(0,10)) ?

How much is that better than just disabling this test? If we ignore that this test fails we should just disable it so it's more obvious (which might be the right call I don't know how much we care about the browser element in general).

I don't know anything about this area but the concerning error is:
[task 2017-02-01T06:27:49.131682Z] 06:27:49     INFO - JavaScript error: resource://gre/components/BrowserElementParent.js, line 227: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIXPCComponents_Utils.isDeadWrapper]
Which means that the browser element is being used before it is initialized. It's not obvious to me where is it used from that can trigger this error.
Flags: needinfo?(gkrizsanits)
(In reply to Gabor Krizsanits [:krizsa :gabor] from comment #14)
> (In reply to Geoff Brown [:gbrown] from comment #10)
> > Andrew - Would it be okay to allow assertions in this test (mark with
> > something like expectAssertions(0,10)) ?
> 
> How much is that better than just disabling this test? If we ignore that
> this test fails we should just disable it so it's more obvious (which might
> be the right call I don't know how much we care about the browser element in
> general).

Either approach is fine with me. expectAssertions() is a good solution when the test is considered valuable but the assertion is not understood, or not important in the test context.
(In reply to Geoff Brown [:gbrown] from comment #15)
> Either approach is fine with me. expectAssertions() is a good solution when
> the test is considered valuable but the assertion is not understood, or not
> important in the test context.

I question the value of this test with these assertions, but either version
works for me too.
OK, I'll skip it.
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/8cf10b012ee2
Skip test_browserElement_inproc_AudioPlayback.html for frequent failures; r=me,test-only
https://hg.mozilla.org/mozilla-central/rev/8cf10b012ee2
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla54
Sorry, should have marked leave-open.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Whiteboard: [test disabled]
395ms
01-23 09:32:26.595   788   808 E GeckoConsole: [JavaScript Error: "too much recursion" {file: "resource://gre/modules/BrowserElementPromptService.jsm" line: 563}]
01-23 09:32:26.675   788   808 E GeckoConsole: [JavaScript Error: "NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS: [JavaScript Error: "too much recursion" {file: "resource://gre/modules/BrowserElementPromptService.jsm" line: 563}]'[JavaScript Error: "too much recursion" {file: "resource://gre/modules/BrowserElementPromptService.jsm" line: 563}]' when calling method: [nsIPromptFactory::getPrompt]" {file: "chrome://mochitests/content/chrome/dom/browser-element/mochitest/file_browserElement_AudioChannel_nested.html" line: 6}]

This seems to be the origin of this bug.
Flags: needinfo?(amarchesini)
See Also: → 1337593
(In reply to Andrea Marchesini [:baku] from comment #25)
> 395ms
> 01-23 09:32:26.595   788   808 E GeckoConsole: [JavaScript Error: "too much
> recursion" {file: "resource://gre/modules/BrowserElementPromptService.jsm"
> line: 563}]
> 01-23 09:32:26.675   788   808 E GeckoConsole: [JavaScript Error:
> "NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS: [JavaScript Error: "too much
> recursion" {file: "resource://gre/modules/BrowserElementPromptService.jsm"
> line: 563}]'[JavaScript Error: "too much recursion" {file:
> "resource://gre/modules/BrowserElementPromptService.jsm" line: 563}]' when
> calling method: [nsIPromptFactory::getPrompt]" {file:
> "chrome://mochitests/content/chrome/dom/browser-element/mochitest/
> file_browserElement_AudioChannel_nested.html" line: 6}]
> 
> This seems to be the origin of this bug.

I don't see that in most of the failure logs.
As soon as I skipped test_browserElement_inproc_AudioPlayback.html, we started getting the same type of failures in bug 1337593, in test_browserElement_inproc_BackForward.html. 

In try pushes, I found that if test_browserElement_inproc_BackForward.html was skipped, then the next test started failing.

By trial and error, I found all's well if both test_browserElement_inproc_AudioPlayback.html and test_browserElement_inproc_AudioChannel.html are skipped. (Assertions cause failed tests if only one or the other is skipped.)

https://treeherder.mozilla.org/#/jobs?repo=try&revision=cf90e037ab63c0e3df9dc845d831bc29fb75d71f
Attachment #8836241 - Flags: review?(gkrizsanits)
Summary: Intermittent dom/browser-element/mochitest/test_browserElement_inproc_AudioPlayback.html | Assertion count 6 is greater than expected range 0-0 assertions. → Intermittent dom/browser-element/mochitest/test_browserElement_inproc_AudioPlayback.html, test_browserElement_inproc_BackForward.html | Assertion count 6 is greater than expected range 0-0 assertions.
Attachment #8836241 - Flags: review?(gkrizsanits) → review+
Comment on attachment 8836241 [details] [diff] [review]
skip inproc_AudioChannel too

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

This code soon will be all removed anyway, thanks for the patch!
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/46f095237243
Skip test_browserElement_inproc_AudioChannel, for frequent assertions; r=gabor
Keywords: leave-open
*Still* failing....
Flags: needinfo?(gbrown)
Keywords: leave-open
It looks like we also need to skip test_browserElement_inproc_AudioChannel_nested.html: https://treeherder.mozilla.org/#/jobs?repo=try&revision=837ceaa9603cc1e26468a87ad62faa01d2174474
Flags: needinfo?(gbrown)
Keywords: leave-open
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9b7942f48f01
Skip test_browserElement_inproc_AudioChannel_nested.html for assertions; r=me,test-only
Whiteboard: [test disabled] → [test-disabled][stockwell disabled]
Priority: -- → P5
:overholt- these tests have been disabled for 5+ months, should we leave this bug open?
Flags: needinfo?(overholt)
(In reply to Joel Maher ( :jmaher) (UTC-8) from comment #40)
> :overholt- these tests have been disabled for 5+ months, should we leave
> this bug open?

I'll leave that decision up to baku.
Flags: needinfo?(overholt) → needinfo?(amarchesini)
Let's ask alwu. He is taking care of audio playback in these days.
If these tests are not useful, we can remove them.
Flags: needinfo?(amarchesini) → needinfo?(alwu)
Yes, this test is not useful anymore, we should remove it.
Assignee: nobody → alwu
Flags: needinfo?(alwu)
Comment on attachment 8887346 [details]
Bug 1332862 - remove useless test.

https://reviewboard.mozilla.org/r/158172/#review163514
Attachment #8887346 - Flags: review?(amarchesini) → review+
https://hg.mozilla.org/mozilla-central/rev/0684def62744

If we're removing the test, why is the bug being kept open?
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [test-disabled][stockwell disabled] → [stockwell fixed:obsolete]
Target Milestone: mozilla54 → mozilla56
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.