1151060 - Repeatedly bad audio/video sync on Hello calls

Status: RESOLVED DUPLICATE of bug 1166183

(Core :: WebRTC: Audio/Video, defect, P1)

Description

[Eric Rescorla (:ekr)]

I've just had a number of Hello calls where we got extremely bad A/V sync
(audio lagging video by 1-3 seconds). This of course leads to bad AEC and
other problems.

Comment 1

[Eric Rescorla (:ekr)]

Randell, what data can I gather to help you diagnose this.

This was Aurora to Firefox 37.

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

Is this a continual drift of audio (ever-increasing delay), with video remaining low-delay?  I saw a repeatable instance of this late last week with blassey on a mac, but he didn't get me the AEC logs.  It feels strongly like the sort of drift we once (long ago) got before I added direct listeners to MediaStreams; this feels like someone broke or disabled direct listeners (most likely in MediaPipeline, perhaps in MediaEngineWebRTCAudio.cpp or MSG, or (less likely) something wrong in the output side (MediaPipeline -> <video> -> cubeb)

If this is repeatable: does it also show up in talky/apprtc/etc, or is it just Hello?  And does it show up if the person makes a call to themselves with pc_test.html (and unmutes the large receiving <video>)?  If so, does the self-image show the same drift when un-muted?

OSes on each end, including version?  blassey was Macbook Pro 2014, no headset, in Hello.

Thanks!  I want to nail this ASAP; whatever it is appears to be a recent regression.

Comment 3

[Eric Rescorla (:ekr)]

(In reply to Randell Jesup|PTO until Apr 6 [:jesup] from comment #2)
> Is this a continual drift of audio (ever-increasing delay), with video
> remaining low-delay? 

I don't know if it's continual. I had three calls, with the first two
having progressively worse sync with the audio appearing to get worse
and the video staying the same or getting worse slower and the last
one being bad from the start, all with the same counterpary.


> If this is repeatable: does it also show up in talky/apprtc/etc, or is it
> just Hello? 

Unknown. I didn't test.

> And does it show up if the person makes a call to themselves
> with pc_test.html (and unmutes the large receiving <video>)?  If so, does
> the self-image show the same drift when un-muted?

Unknown, I didn't test.


> OSes on each end, including version?  blassey was Macbook Pro 2014, no
> headset, in Hello.

Macbook Pro on Mavericks my side. Cullen was on the other side.


Are there some measurements I can take during the call that will help you?
It sounds like AEC logs? Something else?

Comment 4

[Randell Jesup [:jesup] (needinfo me)]

(In reply to Eric Rescorla (:ekr) from comment #3)
> (In reply to Randell Jesup|PTO until Apr 6 [:jesup] from comment #2)
> > Is this a continual drift of audio (ever-increasing delay), with video
> > remaining low-delay? 
> 
> I don't know if it's continual. I had three calls, with the first two
> having progressively worse sync with the audio appearing to get worse
> and the video staying the same or getting worse slower and the last
> one being bad from the start, all with the same counterpary.

The first two certainly appear to be the same thing I saw with Brad; the last may be (given the circumstances, likely).  It also points to it being easily repeatable, which was implied with Brad.

> > If this is repeatable: does it also show up in talky/apprtc/etc, or is it
> > just Hello? 
> 
> Unknown. I didn't test.
> 
> > And does it show up if the person makes a call to themselves
> > with pc_test.html (and unmutes the large receiving <video>)?  If so, does
> > the self-image show the same drift when un-muted?
> 
> Unknown, I didn't test.

If you see it again, please do so.

> 
> > OSes on each end, including version?  blassey was Macbook Pro 2014, no
> > headset, in Hello.
> 
> Macbook Pro on Mavericks my side. Cullen was on the other side.

Thanks, useful.  So far it's all Mac at the sending side (where the problem likely is).

> Are there some measurements I can take during the call that will help you?
> It sounds like AEC logs? Something else?

AEC logs will help verify if the problem is in the OS (unlikely) or between gUM and PeerConnection (likely if it's a regression in MediaPipeline/MSG).  Brad took AEC logs, but I didn't get them.

Comment 5

[Randell Jesup [:jesup] (needinfo me)]

A survey of recent (last few months) changes to MediaPipeline and MediaStreamGraph don't show any obvious sources of changes to AddDirectListener.  Still, this is something to check carefully, as it would cause issues like this if there's a drift between the output and input rates.

Some of the tests I mention above would be helpful to run (such as checking (with selectively unmutes) of https://mozilla.github.io/webrtc-landing/pc_test.html).

Who was hearing the drift?  Cullen, Ekr, or both?  What version was cullen running? (and what OS version)?  Headsets or built-in mics? (Brad was built-in). Have you heard this before/after, or was the a one-off case for this conversation?

Cullen - if ekr was hearing drift, it would be useful for you to run these tests.  (also, AEC logs are started from about:webrtc and dump them in /tmp on the mac; turns off automatically after ~3 min.  Note that they don't work reliably if you're testing e10s until pkerr lands a patch.)

Thanks!

Comment 6

[Eric Rescorla (:ekr)]

We were both seeing it. I was on headphones and built-in microphone.
I believe Cullen was on speakers.

As I said, it happened with three separate calls with Cullen.

Previously in the day I had a complaint from someone else that they
were getting choppy audio from me that was fixed with a restart.
Choppy audio was also the first symptom Cullen noticed that cause
him to suspect delay issues causing problems with the AEC.

Comment 7

[Randell Jesup [:jesup] (needinfo me)]

Local testing with Nightly on a 2013 MBP running 10.9.x, with and without e10s.

In Hello calls to my Nightly very-late-39 Win7 (same system/browser-instance that I used for calls with Brad where I heard delay), I had no audio delay or a/v sync issues.  Let calls run 10-20 minutes each time.   Mac mic was internal, as were speakers.

Comment 8

[Cullen Jennings]

I was on a mac, speaker phone, and latest production version of FF. I will try and grab logs if I see it again. It was clear from a clap test that the audio lagged the video my multiple seconds. To me, the artifacts we were hearing sounded like it might be a RTP over TCP problem but that is just a vague hunch with nothing to back it up.

Comment 9

[Eric Rescorla (:ekr)]

Repeat of this with EKR/RBarnes, with Barnes seeing me as bad. He will provide his logs.

Comment 11

[Adam Roach [:abr]]

The theory here had been that this problem was fixed with Bug 1151060, which was uplifted to Aurora, Beta, Release, and ESR. However, Bug 1172970 was filed today with a symptom that sounds exactly like this problem again (A/V sync drift that increases constantly over the course of a call).

Jesup: can you touch base with Margret ([e-mail]) and Sebastian ([e-mail]) to see if you can figure out what is causing their issue?

Comment 12

[Adam Roach [:abr]]

(In reply to Adam Roach [:abr] from comment #11)
> The theory here had been that this problem was fixed with Bug 1151060

Sorry, that should have said "Bug 1166183"

Comment 13

[Maire Reavy [:mreavy]]

Sebastian - Were you using Fx38 or Fx38.0.5 when you and Margaret had the problem?  The other bug (which is marked as a dup of this one) says Fx38.  Fx38 didn't have the fix from Bug 1166183, whereas Fx38.0.5 does.

Comment 14

[Sebastian Kaspari (:sebastian; :pocmo)]

(In reply to Maire Reavy [:mreavy] (Plz needinfo me) from comment #13)
> Sebastian - Were you using Fx38 or Fx38.0.5 when you and Margaret had the
> problem?  The other bug (which is marked as a dup of this one) says Fx38. 
> Fx38 didn't have the fix from Bug 1166183, whereas Fx38.0.5 does.

The about dialog (help) shows 38.0. navigator.userAgent says: "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0".

Comment 15

[Maire Reavy [:mreavy]]

(In reply to :Sebastian Kaspari from comment #14)
> The about dialog (help) shows 38.0. navigator.userAgent says: "Mozilla/5.0
> (X11; Ubuntu; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0".

This says you were running a version that didn't have the fix.  Can you update to Fx38.0.5 or later and let us know if this happens again?  All of our testing thus far indicates that Bug 1166183 caused this; so I am going to close this as a dup of Bug 1166183.

Sebastian -- if this does happen again after you update to 38.0.5, please reopen this.  Thanks!