Closed Bug 1116925 Opened 5 years ago Closed 5 years ago

Intermittent test_getUserMedia_stopVideoAudioStreamWithFollowupVideoAudio.html,test_peerConnection_offerRequiresReceiveVideoAudio.html | Assertion count 1 is greater than expected (Track not found: 'Error')

Categories

(Core :: Audio/Video, defect)

x86
Linux
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla38
Tracking Status
firefox36 --- unaffected
firefox37 --- wontfix
firefox38 --- fixed
firefox-esr31 --- unaffected
b2g-v2.2 --- wontfix
b2g-master --- fixed

People

(Reporter: philor, Assigned: jesup)

References

Details

(Keywords: assertion, intermittent-failure)

Attachments

(3 files, 1 obsolete file)

No description provided.
Blocks: 1117547
Duplicate of this bug: 1117547
Component: WebRTC: Audio/Video → Video/Audio
Summary: Intermittent test_peerConnection_offerRequiresReceiveVideoAudio.html | Assertion count 1 is greater than expected range 0-0 assertions. due to ASSERTION: Track not found: 'Error' → Intermittent test_getUserMedia_stopVideoAudioStreamWithFollowupVideoAudio.html,test_peerConnection_offerRequiresReceiveVideoAudio.html | Assertion count 1 is greater than expected (Track not found: 'Error')
I really don't love adding lock usage - we'll now end up locking mLock 2 times per NotifyPull instead of one (Audio doesn't lock mLock in NotifyPull()).  Perhaps I should 'hoist' the AutoLock into the Listener's NotifyPull and remove it from the Video NotifyPull, and get back to one call (and add an assertion that it's locked to Video NotifyPull)
Comment on attachment 8552470 [details] [diff] [review]
avoid GetEndOfAppendedData in NotifyPull() for tracks we haven't added yet

I'll take either paul or roc for review on this.  Oh, and I'll remove the blank line I added before "private:"
Attachment #8552470 - Flags: review?(roc)
Attachment #8552470 - Flags: review?(padenot)
Comment on attachment 8552470 [details] [diff] [review]
avoid GetEndOfAppendedData in NotifyPull() for tracks we haven't added yet

paul doesn't feel like he should be reviewing this, so just roc then
Attachment #8552470 - Flags: review?(padenot)
FWIW, here's a try run (with some other related bugs):

https://treeherder.mozilla.org/#/jobs?repo=try&revision=cfca214e0135

I've also verified that signaling_unittests works on linux ASAN.
Comment on attachment 8552470 [details] [diff] [review]
avoid GetEndOfAppendedData in NotifyPull() for tracks we haven't added yet

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

How about we just add an API to add multiple tracks at once to a SourceMediaStream? That seems like a cleaner solution.
Attachment #8552470 - Flags: review?(roc)
Flags: needinfo?(padenot)
This queues track additions until getUserMedia has Start()ed all the tracks to avoid race conditions in processing NotifyUpdate()
Attachment #8558133 - Flags: review?(roc)
Comment on attachment 8558133 [details] [diff] [review]
queue track adds for getUserMedia

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

::: dom/media/MediaStreamGraph.h
@@ +726,5 @@
>     * AdvanceKnownTracksTime). Takes ownership of aSegment. aSegment should
>     * contain data starting after aStart.
>     */
> +  void AddTrack(TrackID aID, StreamTime aStart, MediaSegment* aSegment,
> +                bool aQueue = false)

Please use a flags word or two-value enum instead of a boolean parameter.
Attachment #8558133 - Flags: review?(roc) → review+
Comment on attachment 8558133 [details] [diff] [review]
queue track adds for getUserMedia

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

There's another race in the WebRTC Audio/Video sources, see my inline comments. If MSG would run an iteration after the first AddTrack() but before FinishAddTracks() we'd assert like this:

[Child 55299] ###!!! ASSERTION: Track not found: 'Error', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 2474
[Child 55299] WARNING: Adding track to StreamBuffer that should have no more tracks: file /Users/pehrsons/Comoyo/gecko-dev/dom/media/StreamBuffer.h, line 213
[Child 55299] WARNING: Adding track to StreamBuffer that should have no more tracks: file /Users/pehrsons/Comoyo/gecko-dev/dom/media/StreamBuffer.h, line 213
[Child 55299] ###!!! ASSERTION: Buffer underran: 'bufferEnd >= IterationEnd()', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 477
[Child 55299] ###!!! ASSERTION: Buffer underran: 'bufferEnd >= IterationEnd()', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 477
[Child 55299] ###!!! ASSERTION: Buffer underran: 'bufferEnd >= IterationEnd()', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 477
[Child 55299] ###!!! ASSERTION: Buffer underran: 'bufferEnd >= IterationEnd()', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 477
[Child 55299] ###!!! ASSERTION: Buffer underran: 'bufferEnd >= IterationEnd()', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 477

The fix is simple with this patch, just put the call to AdvanceKnownTracksTime() after FinishAddTracks() in MediaManager.h.

I ran into this while working on bug 1129263 with this patch applied. Interestingly, mochitests seemed to work fine but appear.in triggered it fairly often.

::: dom/media/webrtc/MediaEngineWebRTCAudio.cpp
@@ +332,1 @@
>    aStream->AdvanceKnownTracksTime(STREAM_TIME_MAX);

Race contestant nr 1.

::: dom/media/webrtc/MediaEngineWebRTCVideo.cpp
@@ +412,1 @@
>    aStream->AdvanceKnownTracksTime(STREAM_TIME_MAX);

Race contestant nr 2.
It also seems like MediaManager::NotifyPull() is racing ahead of FinishAddTracks() sometimes.
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #71)
> It also seems like MediaManager::NotifyPull() is racing ahead of
> FinishAddTracks() sometimes.

I should say that it gives the same assertion as in the title, so this bug could just as well be for this race as any of the others.

Here's what I got:
> [Child 58860] ###!!! ASSERTION: Track not found: 'Error', file /Users/pehrsons/Comoyo/gecko-dev/dom/media/MediaStreamGraph.cpp, line 2474
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #71)
> It also seems like MediaManager::NotifyPull() is racing ahead of
> FinishAddTracks() sometimes.

Aaaand it's GetUserMediaCallbackMediaStreamListener::NotifyPull() that's in the race, nothing else. Too many classes :)
FWIW we can still get a NotifyPull before the tracks have been added. E.g., the linux oranges here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=978e1b1dd35d
Assignee: nobody → rjesup
Status: NEW → ASSIGNED
Attachment #8558133 - Attachment is obsolete: true
Comment on attachment 8565969 [details] [diff] [review]
queue track adds for getUserMedia and cleanup

Interdiffs against the version you r+'d are here:
https://bugzilla.mozilla.org/page.cgi?id=splinter.html&bug=1116925&attachment=8565940

a) the original patch didn't also correct the fake audio/video generator code
b) Try exposed that fixing this showed related timing holes on the (much slower than my desktop) test VMs, which are now patched too

Try link: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d4f26dcf7cd3
Attachment #8565969 - Flags: review?(roc)
Depends on: 1134857
https://hg.mozilla.org/mozilla-central/rev/3e5734d87240
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
Recognizing that bug 1134857 was a regression from this, I'd still like to see us get this fix on Gecko 37. Does that sound reasonable, Randell?
Flags: needinfo?(padenot) → needinfo?(rjesup)
Not going to make Fx37 at this point.
Flags: needinfo?(rjesup)
You need to log in before you can comment on or make changes to this bug.