Closed
Bug 1109644
Opened 9 years ago
Closed 9 years ago
Ever-increasing MediaStreamGraph video delay (and jerkiness) on 36/37
Categories
(Core :: Audio/Video, defect)
Core
Audio/Video
Tracking
()
RESOLVED
FIXED
mozilla37
People
(Reporter: jesup, Assigned: roc)
References
()
Details
(Keywords: regression)
Attachments
(6 files, 1 obsolete file)
5.69 KB,
patch
|
jesup
:
review+
|
Details | Diff | Splinter Review |
1.41 KB,
patch
|
jesup
:
review+
|
Details | Diff | Splinter Review |
1.24 KB,
patch
|
jesup
:
review+
|
Details | Diff | Splinter Review |
1.48 KB,
patch
|
jesup
:
review+
|
Details | Diff | Splinter Review |
1.42 KB,
patch
|
jesup
:
review+
|
Details | Diff | Splinter Review |
16.78 KB,
patch
|
jesup
:
review+
Sylvestre
:
approval-mozilla-aurora+
|
Details | Diff | Splinter Review |
+++ This bug was initially created as a clone of Bug #1061046 +++ On 36 and 37 in uses of gUM + MediaStreams (gum tests, or local video viewing in a call), there's ever-increasing video delay. After 40 minutes on linux, I had ~2s of video delay, but no significant audio delay. Similar results on windows, but there after 3-5 minutes the video also gets increasingly jerky (goes down from 15-30fps to ~5fps). This happens with video or video+audio gum. This can be seen in a simple gUM test https://mozilla.github.io/webrtc-landing/gum_test.html I strongly believe this is a regression from bug 1061046. The only other things to touch these paths significantly were bug 1080755 (which is in 34 - it was uplifted) and bug 1053130 (it's in 35, and 35 doesn't show this). The callback-driven MSG is also in 34, so it's not that.
Reporter | ||
Comment 1•9 years ago
|
||
roc - I think this one's yours or KarlT's
Flags: needinfo?(roc)
Summary: Ever-increasing video delay (and jerkiness) on 36/37 → Ever-increasing MediaStreamGraph video delay (and jerkiness) on 36/37
Assignee | ||
Comment 2•9 years ago
|
||
On my machine, I don't see video lag but I do see jerky video. MediaEngineWebRTCVideoSource::NotifyPull is being called on every rendered video frame (i.e. not frequently enough). But MediaStreamGraphImpl::Process is being called at a higher rate. So for some reason NotifyPull is not being called often enough.
Flags: needinfo?(roc)
Assignee | ||
Comment 3•9 years ago
|
||
It looks like mLastEndTimeVideo is incorrect (too low). It doesn't match the end of the video track in the MSG. That causes us to append too-long video segments to the track in each NotifyPull.
Assignee | ||
Comment 4•9 years ago
|
||
There's some kind of rounding error accumulating in the track length: ### MediaEngineWebRTCVideoSource::NotifyPull changed aLastEndTime from 27392 to 27904 ### Track duration changed from 27392 to 27904 ### MediaEngineWebRTCVideoSource::NotifyPull changed aLastEndTime from 27904 to 28288 ### Track duration changed from 27904 to 28289 <--- this is where we pulled the data from the SourceMediaStream's staging buffer into the track itself, right after calling NotifyPull
Assignee | ||
Comment 5•9 years ago
|
||
Ah, it's MediaEngineWebRTCVideoSource::DeliverFrame appending a one-sample frame periodically. Unfortunately that is not being added to mLastEndTimeVideo!
Assignee | ||
Comment 6•9 years ago
|
||
Assignee: nobody → roc
Attachment #8535359 -
Flags: review?(rjesup)
Reporter | ||
Comment 7•9 years ago
|
||
Comment on attachment 8535359 [details] [diff] [review] fix Review of attachment 8535359 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/media/MediaStreamGraph.cpp @@ +216,5 @@ > STREAM_LOG(PR_LOG_DEBUG+1, ("SourceMediaStream %p track %d, advancing end from %lld to %lld", > aStream, data->mID, > int64_t(dest->GetDuration()), > int64_t(dest->GetDuration() + data->mData->GetDuration()))); > + auto old = dest->GetDuration(); Why is this here? Looks like dead code.. @@ +2342,5 @@ > ResampleAudioToGraphSampleRate(track, aSegment); > > // Must notify first, since AppendFrom() will empty out aSegment > NotifyDirectConsumers(track, aRawSegment ? aRawSegment : aSegment); > + auto old = track->mData->GetDuration(); Why is this here? Looks like dead code..
Attachment #8535359 -
Flags: review?(rjesup) → review+
Reporter | ||
Comment 8•9 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/0661a1b7ec14
Comment 9•9 years ago
|
||
sorry had to back this out for M-3 Failures like https://treeherder.mozilla.org/logviewer.html#?job_id=4721281&repo=mozilla-inbound
Assignee | ||
Comment 11•9 years ago
|
||
Needless to say I can't reproduce this crash locally.
Assignee | ||
Comment 12•9 years ago
|
||
The bug was that MediaEngineWebRTCVideoSource (and I guess other sources) are used with more than one SourceMediaStream, each one with a different start time. We tried to use a single mProducedDuration value for all the streams, which doesn't make sense.
Assignee | ||
Comment 13•9 years ago
|
||
Attachment #8541960 -
Flags: review?(rjesup)
Assignee | ||
Updated•9 years ago
|
Attachment #8535359 -
Attachment is obsolete: true
Assignee | ||
Comment 14•9 years ago
|
||
Attachment #8541961 -
Flags: review?(rjesup)
Assignee | ||
Comment 15•9 years ago
|
||
Attachment #8541962 -
Flags: review?(rjesup)
Assignee | ||
Comment 16•9 years ago
|
||
Attachment #8541963 -
Flags: review?(rjesup)
Assignee | ||
Comment 17•9 years ago
|
||
Attachment #8541964 -
Flags: review?(rjesup)
Assignee | ||
Comment 18•9 years ago
|
||
Attachment #8541965 -
Flags: review?(rjesup)
Reporter | ||
Updated•9 years ago
|
Attachment #8541960 -
Flags: review?(rjesup) → review+
Reporter | ||
Updated•9 years ago
|
Attachment #8541961 -
Flags: review?(rjesup) → review+
Reporter | ||
Updated•9 years ago
|
Attachment #8541962 -
Flags: review?(rjesup) → review+
Reporter | ||
Updated•9 years ago
|
Attachment #8541963 -
Flags: review?(rjesup) → review+
Reporter | ||
Updated•9 years ago
|
Attachment #8541964 -
Flags: review?(rjesup) → review+
Reporter | ||
Comment 19•9 years ago
|
||
Comment on attachment 8541965 [details] [diff] [review] Part 6: Remove aLastEndTime parameter from NotifyPull Review of attachment 8541965 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/media/webrtc/MediaEngineWebRTCAudio.cpp @@ +402,4 @@ > { > // Ignore - we push audio data > #ifdef DEBUG > + LOG(("Audio: NotifyPull: aDesiredTime %ld", aDesiredTime)); Let's move this to a higher logging level - add a LOG_FRAMES to match MediaEngineWebRTCVideo.cpp (logs at level 6/DEBUG+1), and use that here. #define LOG_FRAMES(msg) PR_LOG(GetMediaManagerLog(), 6, msg)
Attachment #8541965 -
Flags: review?(rjesup) → review+
Assignee | ||
Comment 20•9 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/46280459abf5 https://hg.mozilla.org/integration/mozilla-inbound/rev/ca7246eb4da0 https://hg.mozilla.org/integration/mozilla-inbound/rev/2199fa1fc9cb https://hg.mozilla.org/integration/mozilla-inbound/rev/412b935dc4a8 https://hg.mozilla.org/integration/mozilla-inbound/rev/080bbd228f63 https://hg.mozilla.org/integration/mozilla-inbound/rev/69208a177ce3
Assignee | ||
Comment 21•9 years ago
|
||
Bustage fix: https://hg.mozilla.org/integration/mozilla-inbound/rev/a95386a2c7ea
https://hg.mozilla.org/mozilla-central/rev/46280459abf5 https://hg.mozilla.org/mozilla-central/rev/ca7246eb4da0 https://hg.mozilla.org/mozilla-central/rev/2199fa1fc9cb https://hg.mozilla.org/mozilla-central/rev/412b935dc4a8 https://hg.mozilla.org/mozilla-central/rev/080bbd228f63 https://hg.mozilla.org/mozilla-central/rev/69208a177ce3 https://hg.mozilla.org/mozilla-central/rev/a95386a2c7ea
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla37
Assignee | ||
Comment 23•9 years ago
|
||
[Tracking Requested - why for this release]: Regression, and quite a bad one.
tracking-firefox36:
--- → ?
Assignee | ||
Comment 24•9 years ago
|
||
Comment on attachment 8541965 [details] [diff] [review] Part 6: Remove aLastEndTime parameter from NotifyPull Approval Request Comment [Feature/regressing bug #]: 1061046 [User impact if declined]: bad regression in long-running getUserMedia sessions [Describe test coverage new/current, TBPL]: many automated tests exercise this code [Risks and why]: pretty low risk [String/UUID change made/needed]: none
Attachment #8541965 -
Flags: approval-mozilla-aurora?
Updated•9 years ago
|
Updated•9 years ago
|
Attachment #8541965 -
Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Comment 25•9 years ago
|
||
https://hg.mozilla.org/releases/mozilla-aurora/rev/781049fc09fb https://hg.mozilla.org/releases/mozilla-aurora/rev/4527a6412ae2 https://hg.mozilla.org/releases/mozilla-aurora/rev/109b4fe07cd6 https://hg.mozilla.org/releases/mozilla-aurora/rev/6af0ae87373c https://hg.mozilla.org/releases/mozilla-aurora/rev/baf0d7514c0c https://hg.mozilla.org/releases/mozilla-aurora/rev/1a2361891ac9
You need to log in
before you can comment on or make changes to this bug.
Description
•