Over 3s A/V sync delay when Firefox is the sender.

VERIFIED FIXED in Firefox 65

Status

()

P1
normal
Rank:
7
VERIFIED FIXED
2 months ago
18 days ago

People

(Reporter: jya, Assigned: pehrsons)

Tracking

({regression})

unspecified
mozilla67
regression
Points:
---

Firefox Tracking Flags

(relnote-firefox 65+, firefox-esr60 unaffected, firefox65+ fixed, firefox66+ fixed, firefox67+ verified)

Details

Attachments

(1 attachment)

(Reporter)

Description

2 months ago

Made few calls with :cpearce using appear.in

Whenever he's using Firefox on his end, there's close to 3s delay between audio and video.

On my end, using Chrome or Firefox led to the same outcome.
If he used Chrome it was good.

Tried with and without IPv6, made no difference.

(Reporter)

Comment 1

2 months ago

Similar to bug 1521577, but obviously not the same

See Also: → bug 1521577
(Assignee)

Comment 2

2 months ago

Was the delay observed on his or your side? Which revision of Nightly did he use? Which platform and what cam/mic did he use? If linux, is it the same with "media.cubeb.sandbox" set to false?

If the delay was observed on your side, it sounds like bug 1521577 to me -- If so, Chris, can you try https://mozilla.github.io/webrtc-landing/gum_test.html and compare "Audio" to "Audio & Video"? Also with latest Nightly to confirm. Thanks!

Flags: needinfo?(jyavenard)
Flags: needinfo?(cpearce)
(Reporter)

Comment 3

2 months ago

I was on mac, he was on Windows.
Both running latest nightly.

the delay was observed on my side only, for him it was okay.

Flags: needinfo?(jyavenard)
(Assignee)

Comment 4

2 months ago

What we've concluded so far is that this is indeed another failure mode remaining after bug 1521577 was fixed. Like that bug it also seems to be triggered mainly by the camera device in a video+audio gUM request. It isn't related to sending, just capturing. It isn't reliably reproducing either, something makes it go away, unclear what.

A regression window could be useful just to confirm that it has the same source as bug 1521577 and isn't a regression from bug 1521577 itself. Alex, if you figure out how to reliably reproduce, could you attempt getting a window too?

Assignee: nobody → apehrson
Status: NEW → ASSIGNED
Rank: 7
Flags: needinfo?(cpearce) → needinfo?(achronop)
Keywords: regression
Priority: -- → P1
(Assignee)

Comment 5

2 months ago

[Tracking Requested - why for this release]:

Hopefully the last audio delay regression now. For sure the trickiest to figure out, but probably the simplest to solve.

We have a few reports of audio latency on Windows. This is not in theory bound to Windows however, but seems to be where it manifests. If I can read anything from the root of the issue, machine load would have the biggest say on whether you get a delay and how long that delay will be. The Windows-relatedness could also be because we can get the audio backend started faster there, but I don't know whether that's the case.

In detail this bug occurs when there's some delay between creating the MediaStream in the MSG [1] and adding the tracks to that MediaStream. In a case that Alex reproduced, the tracks are added at StreamTime ~25000 (rate 44100 so ~0.6s), and on the first iteration we pull in the same amount of samples as silence, and these are causing the delay.

Bug 1509548 caused this because it removed the known-tracks-time concept. For a gUM stream the known tracks time was 0 until tracks were added, causing the MediaStream's StreamTime to be kept at 0 too. When tracks were added we advanced the known tracks time to STREAM_TIME_MAX and the StreamTime started advancing.

The fact that we pull in ~25000 samples on the first iteration is a latent bug that is causing this delay. Why it happens intermittently is unclear but it's probably related to the fact that we create the stream (this being the first stream in the graph) with an AudioCallbackDriver and immediately switch to a SystemClockDriver (because there was no audio track yet). I haven't gone into depth on this, as it will be irrelevant to the fix required here.

If this audio was pulled like other audio we could perhaps have compensated this, but once the input callbacks from cubeb start coming in this audio is pushed into the graph, meaning we push the delay ahead of us as well. The video track is only pulled with as much as is needed for the current iteration, meaning that once we have consumed the initial silence/blank-frame we start seeing up-to-date video, as expected.

[1] https://searchfox.org/mozilla-central/rev/78cd247b5d7a08832f87d786541d3e2204842e8e/dom/media/MediaManager.cpp#1323
[2] https://searchfox.org/mozilla-central/rev/78cd247b5d7a08832f87d786541d3e2204842e8e/dom/media/MediaManager.cpp#4132,4136

Blocks: 1509548
status-firefox65: --- → affected
status-firefox66: --- → affected
status-firefox67: --- → affected
tracking-firefox65: --- → ?
tracking-firefox66: --- → ?
tracking-firefox67: --- → ?
Flags: needinfo?(achronop)

Once you have a fix let's ask QA to verify. Seems possibly good for beta uplift.

tracking-firefox66: ? → +
tracking-firefox67: ? → +
Flags: qe-verify+

Comment 9

2 months ago
Pushed by padenot@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4fc0ae495571
Fix tracks that start at StreamTime t > 0. r=padenot

Comment 10

2 months ago
bugherder
Status: ASSIGNED → RESOLVED
Last Resolved: 2 months ago
status-firefox67: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla67

Comment on attachment 9040625 [details]
Bug 1523817 - Fix tracks that start at StreamTime t > 0. r?padenot

Beta/Release Uplift Approval Request

Feature/Bug causing the regression

Bug 1523817

User impact if declined

Long audio input latency when opening a microphone device under load, on Windows. This is possibly device-specific: devices that use a built-in driver don't seem to have this issue, but, say, webcam (that sometimes have microphones, like all flagship Logitechs) and some USB headsets that bring along their own driver seem to be sensitive to this problem a bit more.

In short, this makes having a conversation using WebRTC with such a configuration borderline impossible.

Is this code covered by automated tests?

No

Has the fix been verified in Nightly?

Yes

Needs manual test from QE?

Yes

If yes, steps to reproduce

Load the machine, try to make a call to another computer using for example appear.in. Observe that the latency is low.

List of other uplifts needed

none

Risk to taking this patch

Medium

Why is the change risky/not risky? (and alternatives if risky)

Not too risky in the sense that we've been able to find the reason and it makes sense, and we were able to reproduce reliably, and we can't anymore.

However this is device specific so it's a bit harder than usual to test. We can offer recommendations of devices and configurations to test, but we've been doing some testing ourselves on this one as it's a bit easier to characterize.

We have lots of test covering this code in general, but we don't have the required hardware on treeherder for those tests to be able to detect an issue like this, so I said "No" above on the test question.

String changes made/needed

Attachment #9040625 - Flags: approval-mozilla-release?
Attachment #9040625 - Flags: approval-mozilla-beta?

Adrian, can we get someone to verify this fix on Nightly before we do the Beta/Release approvals? Thanks!

Flags: needinfo?(adrian.florinescu)

Alex, would you mind writing here the configuration on which you could repro ?

Flags: needinfo?(achronop)

In order to repro I use an external camera with microphone, Logitech c920 in my case. I go to gUM test page in [1] and I use "Video&Audio" option. In gUM request I am choosing, for the camera the built-in device and for the microphone the one from the external device. When it reproduces (it's sporadic), the audio is behind the video by 1-2 secs.

[1] https://mozilla.github.io/webrtc-landing/gum_test.html

Flags: needinfo?(achronop)
status-firefox-esr60: --- → unaffected
tracking-firefox65: ? → +
Flags: needinfo?(adrian.florinescu) → needinfo?(hani.yacoub)
Whiteboard: [qa-triaged]
(Reporter)

Comment 15

2 months ago

I have verified with a call to :cpearce and it was now working okay, no more A/V sync delay

Status: RESOLVED → VERIFIED

Comment 16

2 months ago

I couldn't reproduce this issue using appear.in on Firefox Nightly 67.0a1 (2019-01-29) using Windows 10 x64 and Mac OS X 10.14, I also used 2 external camera with microphone (Logitech HD pro Webcam C920 and Microsoft LifeCam HD-3000).

I tried by accessing gUM test page but I couldn't reproduce the issue also.

Based on comment 15 I'll change "status-firefox67" flag to verified.

status-firefox67: fixed → verified
Flags: needinfo?(hani.yacoub)

I have also verified the fix, in my case I had 1 sec delay, which I haven't reproduced it again since the fix was landed.

Comment on attachment 9040625 [details]
Bug 1523817 - Fix tracks that start at StreamTime t > 0. r?padenot

Fix for a common WebRTC/ microphone configuration on Windows, verified in Nightly.
Let's uplift for beta 6.

Attachment #9040625 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

Comment 19

a month ago
bugherderuplift
status-firefox66: affected → fixed

Comment on attachment 9040625 [details]
Bug 1523817 - Fix tracks that start at StreamTime t > 0. r?padenot

[Triage Comment]
Fixes lag over WebRTC calls in some circumstances. Approved for 65.0.1.

Attachment #9040625 - Flags: approval-mozilla-release? → approval-mozilla-release+

Comment 21

a month ago
bugherderuplift
status-firefox65: affected → fixed
relnote-firefox: --- → 65+

We couldn't reproduce the issue. We tried different combinations between Windows 10 , macOS 10.12 and Ubuntu 18.04, using hotspot, vpn connections, net limiter on Firefox Nightly (2019-01-29). Jean, can you look over Firefox 65 and 66 too, please?

Flags: qe-verify+ → needinfo?(jyavenard)
(Reporter)

Comment 23

a month ago

(In reply to Catalin Sasca, QA [:csasca] from comment #22)

We couldn't reproduce the issue. We tried different combinations between Windows 10 , macOS 10.12 and Ubuntu 18.04, using hotspot, vpn connections, net limiter on Firefox Nightly (2019-01-29). Jean, can you look over Firefox 65 and 66 too, please?

you need to use windows and have the right hardware.

Flags: needinfo?(jyavenard)

We tried again with the Logitech C920 HD camera, both external and internal microphone, on the appear.in and the gum test page, and still couldn't reproduce it. We tested on Firefox Nightly (2019-01-29).

(Assignee)

Comment 25

a month ago

If I am to make a generic comment about the hardware needed to reproduce this, it would be to use an external USB microphone (in reported cases in the form of a camera or USB headset) and a camera from another device (internal or other external USB).

If that really doesn't work, achronop or cpearce can probably assist in verifying as they have both been able to reproduce in the past.

We tried all of the above, without success. If achronop or cpearce could verify it would be great.

Flags: needinfo?(cpearce)
Flags: needinfo?(achronop)

I have verified the issue already, mentioned in comment 17.

Flags: needinfo?(achronop)

jya and I tested, and the bug appeared fixed in Nightly.

Flags: needinfo?(cpearce)
QA Whiteboard: [qa-triaged]
Whiteboard: [qa-triaged]
You need to log in before you can comment on or make changes to this bug.