Closed Bug 957691 Opened 6 years ago Closed 4 years ago

Intermittent test_getUserMedia_constraints.html | Assertion count 7 is greater than expected range 0-0 assertions. (and several more) "###!!! ASSERTION: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration'"

Categories

(Core :: Audio/Video: MediaStreamGraph, defect, P2)

defect

Tracking

()

RESOLVED FIXED
mozilla49
Tracking Status
firefox49 --- fixed

People

(Reporter: emorley, Assigned: pehrsons)

References

Details

(Keywords: assertion, intermittent-failure, Whiteboard: [disabled])

Attachments

(2 files, 1 obsolete file)

Rev5 MacOSX Mountain Lion 10.8 mozilla-inbound debug test mochitest-3 on 2014-01-08 07:18:34 PST for push 188d1e255d40

slave: talos-mtnlion-r5-023

https://tbpl.mozilla.org/php/getParsedLog.php?id=32700624&tree=Mozilla-Inbound

{
07:28:57     INFO -  24832 INFO TEST-START | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html
07:28:57     INFO -  ++DOMWINDOW == 33 (0x11e4f8018) [pid = 1189] [serial = 445] [outer = 0x11e45f9b8]
07:28:57     INFO -  [Parent 1189] WARNING: NS_ENSURE_TRUE(enabled) failed: file ../../../dom/base/Navigator.cpp, line 1869
07:28:57     INFO -  [Parent 1189] WARNING: NS_ENSURE_TRUE(enabled) failed: file ../../../dom/base/Navigator.cpp, line 1710
07:28:57     INFO -  24833 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | errcallback: NO_DEVICES_FOUND
07:28:57     INFO -  24834 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | successcallback
07:28:57     INFO -  24835 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | video overconstrained by facingMode fails
07:28:57     INFO -  24836 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | Success-path: optional video facingMode + audio ignoring facingMode
07:28:57     INFO -  24837 INFO TEST-INFO | MEMORY STAT vsize after test: 3882999808
07:28:57     INFO -  24838 INFO TEST-INFO | MEMORY STAT residentFast after test: 275685376
07:28:57     INFO -  --DOMWINDOW == 32 (0x152179508) [pid = 1189] [serial = 434] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
07:28:57     INFO -  24839 INFO TEST-END | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | finished in 199ms
07:28:57     INFO -  ++DOMWINDOW == 33 (0x15188ba18) [pid = 1189] [serial = 446] [outer = 0x11e45f9b8]
07:28:57     INFO -  [Parent 1189] ###!!! ASSERTION: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration', file ../../../content/media/MediaSegment.h, line 272
07:28:57     INFO -  JSPrincipals::dump()+0x006cf037 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x017727e7]
07:28:57     INFO -  JSPrincipals::dump()+0x006ce5e4 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x01771d94]
07:28:57     INFO -  JSPrincipals::dump()+0x006c612b [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x017698db]
07:28:57     INFO -  JSPrincipals::dump()+0x006cb8c7 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0176f077]
07:28:57     INFO -  XRE_AddJarManifestLocation+0x0000e262 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0009c132]
07:28:57     INFO -  UNKNOWN [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x00012d33]
07:28:57     INFO -  JS::CompileOptions::elementProperty() const+0x0026e1c6 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0037d1f6]
07:28:57     INFO -  JS::CompileOptions::elementProperty() const+0x0024ac06 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x00359c36]
07:28:57     INFO -  XRE_AddJarManifestLocation+0x0000cfb3 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0009ae83]
07:28:57     INFO -  _pt_root
07:28:57     INFO -  libsystem_c.dylib + 0x14782
...
...
07:28:57     INFO -  [Parent 1189] ###!!! ASSERTION: Samples missing: 'startTicks == TimeToTicksRoundUp(rate, outputStart)', file ../../../content/media/TrackUnionStream.h, line 253
07:28:57     INFO -  JSPrincipals::dump()+0x006ce5e4 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x01771d94]
07:28:57     INFO -  JSPrincipals::dump()+0x006c612b [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x017698db]
07:28:57     INFO -  JSPrincipals::dump()+0x006cb8c7 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0176f077]
07:28:57     INFO -  XRE_AddJarManifestLocation+0x0000e262 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0009c132]
07:28:57     INFO -  UNKNOWN [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x00012d33]
07:28:57     INFO -  JS::CompileOptions::elementProperty() const+0x0026e1c6 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0037d1f6]
07:28:57     INFO -  JS::CompileOptions::elementProperty() const+0x0024ac06 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x00359c36]
07:28:57     INFO -  XRE_AddJarManifestLocation+0x0000cfb3 [/builds/slave/talos-slave/test/build/application/FirefoxNightlyDebug.app/Contents/MacOS/XUL +0x0009ae83]
07:28:57     INFO -  _pt_root
07:28:57     INFO -  libsystem_c.dylib + 0x14782
}

{
24840 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_getUserMedia_constraints.html | Assertion count 7 is greater than expected range 0-0 assertions.
24852 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_getUserMedia_exceptions.html | Assertion count 23 is greater than expected range 0-0 assertions.
24885 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_getUserMedia_gumWithinGum.html | Assertion count 60 is greater than expected range 0-0 assertions.
24915 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_getUserMedia_playAudioTwice.html | Assertion count 101 is greater than expected range 0-0 assertions.
24945 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_getUserMedia_playVideoAudioTwice.html | Assertion count 131 is greater than expected range 0-0 assertions.
}
roc, you last touched this assertion - could you take a look at this? :-)
Flags: needinfo?(roc)
I'm kinda swamped, so not really.
Flags: needinfo?(roc)
Component: Video/Audio → WebRTC: Audio/Video
Component: WebRTC: Audio/Video → Video/Audio
Blocks: 957876
As karlt indicates, this appears to be the same problem as bug 957876 (fallout from roc's landing)
Assignee: nobody → roc
Depends on: 939610
Blocks: 962635
We can't really annotate or disable our way to victory here given the randomness of what tests hit this and the number of asserts that fire when they do, so changing these to warnings seems like our best option given the lack of progress in fixing the underlying cause. IIUC, warnings mean that the errors will still go into the logs, just without the frequent oranges.
Attachment #8378244 - Flags: review?(roc)
Going through the logs, the 4 assertions in the patch appear to the ones we're hitting most commonly.
IIUC, NS_WARN_IF_FALSE is the one we want here, not NS_WARNING.
Attachment #8378244 - Attachment is obsolete: true
Attachment #8378244 - Flags: review?(roc)
Attachment #8379237 - Flags: review?(roc)
These really should be assertions. It's quite possible that disabling one test will stop the errors from showing up in other tests. I'm not sure how to figure out which test to disable though. Maybe try the first test that ever shows this assertion?
If you're having difficulties reproducing, maybe a loaner slave would help? I don't like papering over failures either, but I'm also not fond of whack-a-mole test disabling.
Flags: needinfo?(ryanvm)
leave-open for reverting the wallpaper in comment 61 and fixing the root cause of the asserts.
Flags: needinfo?(mreavy)
Keywords: leave-open
From comment 59:

10:40:52     INFO -  [Child 1262] ###!!! ASSERTION: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration', file /builds/slave/m-in-osx64-d-00000000000000000/build/content/media/MediaSegment.h, line 272
10:41:08     INFO -  mozilla::TrackUnionStream::CopyTrackData(mozilla::StreamBuffer::Track*, unsigned int, long long, long long, bool*) [content/media/TrackUnionStream.h:330]
10:41:08     INFO -  mozilla::TrackUnionStream::ProduceOutput(long long, long long, unsigned int) [content/media/TrackUnionStream.h:77]
10:41:08     INFO -  mozilla::MediaStreamGraphImpl::RunThread() [content/media/MediaStreamGraph.cpp:1242]
10:41:08     INFO -  mozilla::(anonymous namespace)::MediaStreamGraphInitThreadRunnable::Run() [content/media/MediaStreamGraph.cpp:1390]
10:41:08     INFO -  nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:643]
10:41:08     INFO -  NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:263]
10:41:08     INFO -  mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:303]
10:41:08     INFO -  MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:513]
10:41:08     INFO -  nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:267]
10:41:08     INFO -  _pt_root
Depends on: 937962
Paul -- I think this intermittent is completely irrelevant since your MSG refactor.  If I'm right, can I close this?
Flags: needinfo?(mreavy) → needinfo?(padenot)
I don't really know, but this code has certainly moved enough to try again. I can't fine a clear explanation of the possible cause, here to make sure it would have been fixed by the msg refactoring.
Flags: needinfo?(padenot)
I'm going to close this since we haven't seen it in a long time.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Component: Audio/Video → WebRTC
Reopening for re-enabling the assertions.
(We wouldn't know if the bug still exists as the assertions have been disabled.)
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Keywords: leave-open
Whiteboard: [disabled]
Rank: 23
Component: WebRTC → Audio/Video: MediaStreamGraph
Priority: -- → P2
This could be what I'm currently debugging with extra logging on try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=361181c1c91d

Caused by a cloning test, and the assert I see (android debug only) is always preceded by these warnings.
Duplicate of this bug: 1245805
The warning should be converted back to an assertion before we mark this as fixed.
Keywords: leave-open
Assignee: nobody → pehrsons
Status: REOPENED → ASSIGNED
Keywords: leave-open
Attachment #8745239 - Flags: review?(karlt) → review+
Comment on attachment 8745239 [details]
MozReview Request: Bug 957691 - Restore assertions. r?karlt

https://reviewboard.mozilla.org/r/48949/#review46215

Thanks!
Comment on attachment 8745239 [details]
MozReview Request: Bug 957691 - Restore assertions. r?karlt

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/48949/diff/1-2/
https://hg.mozilla.org/mozilla-central/rev/8c4cf92bea91
Status: ASSIGNED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla49
You need to log in before you can comment on or make changes to this bug.