Closed
Bug 1109405
Opened 10 years ago
Closed 10 years ago
Assertion failure: outputTrack->GetEnd() == GraphTimeToStreamTime(interval.mStart) (Samples missing), at dom/media/TrackUnionStream.cpp:279
Categories
(Core :: WebRTC: Audio/Video, defect)
Core
WebRTC: Audio/Video
Tracking
()
People
(Reporter: pehrsons, Assigned: pehrsons)
References
Details
Attachments
(2 files, 2 obsolete files)
(deleted),
patch
|
jesup
:
review+
Sylvestre
:
approval-mozilla-aurora+
Sylvestre
:
approval-mozilla-beta+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
pehrsons
:
review+
bajaj
:
approval-mozilla-b2g34+
|
Details | Diff | Splinter Review |
A patch on bug 1073406 makes us hit this assertion a lot. Will have to be resolved before bug 1073406 can land.
Some cases to show frequency, platforms, etc:
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=e1e1feb3f9d0
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=90ae4824baa8
Assignee | ||
Updated•10 years ago
|
Assignee: nobody → pehrsons
Status: NEW → ASSIGNED
Assignee | ||
Comment 1•10 years ago
|
||
Looking at the logs from when this fails, I always see "WARNING: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration', file /builds/slave/try-lx-d-000000000000000000000/build/src/media/webrtc/signaling/../../../dom/media/MediaSegment.h, line 317"
Bug 991273 turned an assert into this warning. We might be looking at the same issue for this bug, as was the origin of that bug.
See for instance this try run, with some extra logs: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=3ba38bca2e90
Log file: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/pehrsons@gmail.com-3ba38bca2e90/try-linux-debug/try_ubuntu32_vm-debug_test-mochitest-3-bm01-tests1-linux32-build1613.txt.gz
Depends on: MediaSegmentBase
Assignee | ||
Comment 2•10 years ago
|
||
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #1)
> See for instance this try run, with some extra logs:
> https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=3ba38bca2e90
> Log file:
> http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/pehrsons@gmail.com-
> 3ba38bca2e90/try-linux-debug/try_ubuntu32_vm-debug_test-mochitest-3-bm01-
> tests1-linux32-build1613.txt.gz
And here's the relevant snippet:
05:06:39 INFO - ##### 0xaa37f100 outputTrack->GetEnd()=675328, interval.mStart=675328
05:06:39 INFO - ##### 0x83449d00 outputTrack->GetEnd()=682227, interval.mStart=682227
05:06:39 INFO - [1814] WARNING: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration', file /builds/slave/try-lx-d-000000000000000000000/build/src/media/webrtc/signaling/../../../dom/media/MediaSegment.h, line 317
05:06:39 INFO - ##### 0x83449d00 outputTrack->GetEnd()=683566, interval.mStart=682995
05:06:39 INFO - Assertion failure: outputTrack->GetEnd() == GraphTimeToStreamTime(interval.mStart) (Samples missing), at /builds/slave/try-lx-d-000000000000000000000/build/src/dom/media/TrackUnionStream.cpp:283
05:07:01 INFO - #01: mozilla::TrackUnionStream::CopyTrackData(mozilla::StreamBuffer::Track*, unsigned int, long long, long long, bool*) [dom/media/TrackUnionStream.cpp:245]
05:07:01 INFO - #02: mozilla::TrackUnionStream::ProcessInput(long long, long long, unsigned int) [dom/media/TrackUnionStream.cpp:108]
05:07:01 INFO - #03: mozilla::MediaStreamGraphImpl::Process(long long, long long) [dom/media/MediaStreamGraph.cpp:1328]
05:07:01 INFO - #04: mozilla::MediaStreamGraphImpl::OneIteration(long long, long long, long long, long long) [xpcom/glue/Monitor.h:78]
05:07:01 INFO - #05: mozilla::AudioCallbackDriver::DataCallback(float*, long) [dom/media/GraphDriver.cpp:918]
05:07:01 INFO - #06: stream_request_callback [media/libcubeb/src/cubeb_pulse.c:199]
05:07:02 INFO - TEST-INFO | Main app process: killed by out-of-range signal, number 117
05:07:02 INFO - 562 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/identity/test_getIdentityAssertion.html | application terminated with exit code -11
Assignee | ||
Comment 3•10 years ago
|
||
I haven't been able to figure out why it only happens on try yet.
I've ruled out cpu load by running the test a couple of iterations on my linux machine with one real-time scheduled `yes` process per core. Firefox was left with maybe 5% of one of the cores but still passed the tests successfully.
Assignee | ||
Comment 4•10 years ago
|
||
I see a pattern in that one TrackUnionStream ends just before AppendSlice hits its assertion. Though it's always different from the TrackUnionStream that hits the assertion itself.
It can be seen in all logs here:
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=ce9640b9f4d5
Typically like this:
22:26:52 INFO - ##### 0x8840ee00 outputTrack->GetEnd()=663168, interval.mStart=663168 @@@ interval.mEnd=664064, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=0
22:26:52 INFO - ##### 0xa2180c00 outputTrack->GetEnd()=666752, interval.mStart=666752 @@@ interval.mEnd=667648, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=1
22:26:52 INFO - ##### 0x8840ee00 outputTrack->GetEnd()=664064, interval.mStart=664064 @@@ interval.mEnd=664960, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=1
22:26:52 INFO - ##### 0xa1e5b800 outputTrack->GetEnd()=672966, interval.mStart=672966 @@@ interval.mEnd=673862, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=0
22:26:52 INFO - Assertion failure: aStart >= 0 && aEnd <= aSource.mDuration (Slice out of range), at /builds/slave/try-lx-d-000000000000000000000/build/src/media/webrtc/signaling/../../../dom/media/MediaSegment.h:317
22:27:15 INFO - #01: mozilla::MediaSegmentBase<mozilla::AudioSegment, mozilla::AudioChunk>::AppendSliceInternal(mozilla::MediaSegmentBase<mozilla::AudioSegment, mozilla::AudioChunk> const&, long long, long long) [dom/media/MediaSegment.h:317]
22:27:15 INFO - #02: mozilla::TrackUnionStream::CopyTrackData(mozilla::StreamBuffer::Track*, unsigned int, long long, long long, bool*) [dom/media/TrackUnionStream.cpp:290]
22:27:15 INFO - #03: mozilla::TrackUnionStream::ProcessInput(long long, long long, unsigned int) [dom/media/TrackUnionStream.cpp:108]
22:27:15 INFO - #04: mozilla::MediaStreamGraphImpl::Process(long long, long long) [dom/media/MediaStreamGraph.cpp:1328]
22:27:15 INFO - #05: mozilla::MediaStreamGraphImpl::OneIteration(long long, long long, long long, long long) [xpcom/glue/Monitor.h:78]
22:27:15 INFO - #06: mozilla::AudioCallbackDriver::DataCallback(float*, long) [dom/media/GraphDriver.cpp:918]
22:27:15 INFO - #07: stream_request_callback [media/libcubeb/src/cubeb_pulse.c:199]
Assignee | ||
Comment 5•10 years ago
|
||
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=2636d72e33a2
We're sometimes copying too much data into outputTrack?
23:23:13 INFO - ##### 0x92a8fc00 outputTrack->GetEnd()=660148, interval.mStart=660148 @@@ interval.mEnd=660660, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=0
23:23:13 INFO - [1788] WARNING: Slice out of range: 'aStart >= 0 && aEnd <= aSource.mDuration', file /builds/slave/try-lx-d-000000000000000000000/build/src/media/webrtc/signaling/../../../dom/media/MediaSegment.h, line 317
23:23:13 INFO - ##### 0x92a8fc00 outputTrack->GetEnd()=663214, interval.mStart=660660 @@@ interval.mEnd=661172, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=0
23:23:13 INFO - Assertion failure: outputTrack->GetEnd() == GraphTimeToStreamTime(interval.mStart) (Samples missing), at /builds/slave/try-lx-d-000000000000000000000/build/src/dom/media/TrackUnionStream.cpp:286
Assignee | ||
Comment 6•10 years ago
|
||
So now I have something interesting.
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=c93d4e141b40
From the log:
00:45:52 INFO - ##### 0xa2218b00 outputTrack->GetEnd()=194481, interval.mStart=194481 @@@ interval.mEnd=194993, aInputTrack->GetType()=Audio, aInputTrack->IsEnded()=0, aInputTrack->GetSegment()->GetDuration()=194481
00:45:52 INFO - Assertion failure: aStart >= 0 && aEnd <= aSource.mDuration (Slice out of range), at /builds/slave/try-lx-d-000000000000000000000/build/src/media/webrtc/signaling/../../../dom/media/MediaSegment.h:317
The interval which we want to append to the track is (194481, 194993). But the segment we want to copy from ends at 194481. I have another try run underways that takes the segment's duration/end point into account. Let's see what that gives, here: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=3ee290e0d924
Assignee | ||
Comment 7•10 years ago
|
||
That didn't do it. My bad, too naive - probably fails when the input track is blocked.
Assignee | ||
Comment 8•10 years ago
|
||
Sneaky sneaky, but I finally managed to reproduce this issue on linux. You need to use the real test media devices on the system, instead of having fake media streams in gecko.
Set it up by checking the code for using them here: http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#996
Then to run with them do `./mach mochitest <test> --use-test-media-devices`.
Comment 9•10 years ago
|
||
All mochitests are run on Try server with this option on?
Assignee | ||
Comment 10•10 years ago
|
||
(In reply to JW Wang [:jwwang] from comment #9)
> All mochitests are run on Try server with this option on?
Yep, see this log from try on linux: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/pehrsons@gmail.com-94c07a8ee18d/try-linux-debug/try_ubuntu32_vm-debug_test-mochitest-3-bm06-tests1-linux32-build2623.txt.gz
Search for "TEST DEVICES" and you'll find:
> 21:06:11 INFO - TEST DEVICES: Using media devices:
> 21:06:11 INFO - audio: Sine source at 440 Hz
> 21:06:11 INFO - video: Dummy video device
Search dxr for "Sine source at 440Hz" and you can see it only comes from that option being on:
http://dxr.mozilla.org/mozilla-central/search?q=%22Sine+source+at+440+Hz%22&case=true&redirect=true
Comment 11•10 years ago
|
||
Since this option is default off when we run mochitests locally, it makes the test environment different between our local computer and the Try server and make some problems harder to reproduce locally...
Assignee | ||
Comment 12•10 years ago
|
||
Found it. Works on my linux vm.
We're calling Shutdown() which calls Stop() (which my patch edits) for two different sources. The first one is removed from mSources but it's track aID is not ended. The second one is removed and ended properly.
The patch fixes this to always end the track if the source stream was successfully removed from the audio source.
try: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=a3b5f148d92a
Comment 13•10 years ago
|
||
This assert is showing up in bug 1104086 as well.
Assignee | ||
Comment 14•10 years ago
|
||
The try still shows some oranges, but they're for the same issue on video sources - so an easy fix. Seems like this fixed the issue with mismatching stream final times as well, sweet!
Component: Video/Audio → WebRTC: Audio/Video
Assignee | ||
Comment 15•10 years ago
|
||
Now fixed for both MediaEngineWebRTCAudio and -Video.
Bug 1073406 before patch:https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=e1e1feb3f9d0
Bug 1073406 after patch: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=4117ba3f1936
On m-c: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=7648dad43281
Attachment #8534912 -
Attachment is obsolete: true
Attachment #8535436 -
Flags: review?(rjesup)
Assignee | ||
Comment 16•10 years ago
|
||
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #13)
> This assert is showing up in bug 1104086 as well.
The tests failing on bug 1104086 seem to all be involving getUserMedia so we're most likely looking at the same cause.
Blocks: 1104086
Assignee | ||
Comment 17•10 years ago
|
||
I also take it as likely that this was causing the failures on bug 991273. We could try to revert it.
Blocks: MediaSegmentBase
No longer depends on: MediaSegmentBase
Assignee | ||
Comment 18•10 years ago
|
||
Assignee | ||
Comment 19•10 years ago
|
||
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #14)
> Seems like this fixed the issue with mismatching
> stream final times as well, sweet!
Hmm, not quite. They're still there to some extent. Different issue caused by bug 1073406 though.
Assignee | ||
Comment 20•10 years ago
|
||
Comment on attachment 8535449 [details] [diff] [review]
Revert bug 991273
Looks good so far.
Paul, you think we should restore the assert with my fix?
Attachment #8535449 -
Flags: review?(padenot)
Assignee | ||
Comment 21•10 years ago
|
||
Uhm, so bug 991273 showed up mostly on android and mac so we should definitely test on those as well.
Oh, doesn't seem to be debug builds for android on try?
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=d69226d7bf91
Comment 22•10 years ago
|
||
try: -b d -p android -u none -t none ?
Comment 23•10 years ago
|
||
Hrm, that's really weird.
Assignee | ||
Comment 24•10 years ago
|
||
Stuff is happening in bug 1073772 apparently. Let's see what they say over there.
Updated•10 years ago
|
Attachment #8535436 -
Flags: review?(rjesup) → review+
Assignee | ||
Comment 25•10 years ago
|
||
Comment on attachment 8535449 [details] [diff] [review]
Revert bug 991273
Nope, there's still something going on.
From https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=d69226d7bf91
Attachment #8535449 -
Attachment is obsolete: true
Attachment #8535449 -
Flags: review?(padenot)
Assignee | ||
Comment 26•10 years ago
|
||
Repasting the try since we've had quite some spam in between :)
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=7648dad43281
Keywords: checkin-needed
Comment 27•10 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/9fa6f8d6c5f3
Does this affect any older releases? i.e. should we consider backporting?
Keywords: checkin-needed
Assignee | ||
Comment 28•10 years ago
|
||
Comment on attachment 8535436 [details] [diff] [review]
Fix shutdown of MediaEngineWebRTC sources with multiple attached streams
Yeah, the bug is around in both aurora and beta. Note that in beta, the patch still applies cleanly but the file is in a different location (content/media instead of dom/media)
Approval Request Comment
[Feature/regressing bug #]:
[User impact if declined]: When playing one webrtc stream in two (or more) media elements, only one of the streams' tracks will be properly shut down. Unclear how or if this propagates to users. It's been around since Firefox 20 (bug 811757) so it's at least nothing major.
[Describe test coverage new/current, TBPL]: Tested in CI on m-c with bug 1073406 (yet to land), which exposed it.
[Risks and why]: Low risk. Simple logic fix.
[String/UUID change made/needed]: None
Attachment #8535436 -
Flags: approval-mozilla-beta?
Attachment #8535436 -
Flags: approval-mozilla-aurora?
Comment 29•10 years ago
|
||
https://hg.mozilla.org/mozilla-central/rev/9fa6f8d6c5f3
Do we want this on b2g34 (v2.1) as well?
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla37
Assignee | ||
Comment 30•10 years ago
|
||
B2G 34 needed a slight touch.
Attachment #8536742 -
Flags: review+
Updated•10 years ago
|
status-b2g-v2.1:
--- → affected
status-b2g-v2.2:
--- → fixed
status-firefox34:
--- → wontfix
status-firefox35:
--- → affected
status-firefox36:
--- → affected
status-firefox37:
--- → fixed
Comment 31•10 years ago
|
||
Comment on attachment 8536742 [details] [diff] [review]
[B2G 34] Fix shutdown of MediaEngineWebRTC sources with multiple attached streams (carries r=jesup)
See comment 28.
Attachment #8536742 -
Flags: approval-mozilla-b2g34?
Assignee | ||
Comment 32•10 years ago
|
||
I was trying to find if we're actually hit by this in any cases except shutdown on 34 (and beyond, or on trunk for that matter..). We are. It could happen if there are two gUM streams using the same hardware and MediaStreamTrack::Stop is called for a track hooked up to that hardware. The track will not end in this case, but the MediaStreamGraph will keep copying data to it. Still unclear if this hits the user in any way though.
This applies to 30 and 32 as well (and the last patch applies cleanly there). Any reason to not request approval for those?
Flags: needinfo?(ryanvm)
Comment 33•10 years ago
|
||
30 and 32 are only accepting fixes for partner blockers or critical security issues at this point. So unless there's strong proof that this is severely affecting people, it's not likely to meet that bar for approval.
status-b2g-v1.4:
--- → wontfix
status-b2g-v2.0:
--- → wontfix
status-b2g-v2.0M:
--- → wontfix
Flags: needinfo?(ryanvm)
Updated•10 years ago
|
Attachment #8535436 -
Flags: approval-mozilla-beta?
Attachment #8535436 -
Flags: approval-mozilla-beta+
Attachment #8535436 -
Flags: approval-mozilla-aurora?
Attachment #8535436 -
Flags: approval-mozilla-aurora+
Comment 34•10 years ago
|
||
Updated•10 years ago
|
Attachment #8536742 -
Flags: approval-mozilla-b2g34? → approval-mozilla-b2g34+
Comment 35•10 years ago
|
||
You need to log in
before you can comment on or make changes to this bug.
Description
•