1605134 - Changing drivers of a bluetooth headset during a webrtc call can still cause video delays remotely

Status: RESOLVED FIXED

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

Description

[Andreas Pehrson [:pehrsons]]

Attachment: 4s freeze when switching drivers with a bluetooth headset

After bug 1586370 this was meant to be fixed. It appears to still occur.

I think bug 1586370 laid out the groundwork, and something silly remains.

STR:

1. On a different machine, start a webrtc call (I used whereby.com with 4 remote peers on the same machine, 1 might work too).
2. MOZ_LOG=raw,AudioCallbackTracing:5 MOZ_LOG_FILE=$SOMEFILE ./mach run
3. Join the webrtc call.
4. Change device in the application's UI if it provides one (this should be fine from bug 1601034). Change to a bluetooth mic (on mac) for full effect.
5. Mute the mic, and ensure that the mic is turned off per the permissions UI in the address bar.
6. Unmute the mic. Mute. Unmute. Mute. Unmute.
7. Close the tab, the browser, the browser on the other machine.
8. Load the relevant log file (with content) with $SOMEFILE prefix in Chrome's chrome://tracing.

Expected: Graph is iterated continuously throughout the call.

Actual: See attachment (4s freeze).

Comment 1

[Dan Minor [:dminor]]

I ended up disabling test_mediarecorder_pause_resume_video.html for debug OS X in Bug 1605150, please have a look at re-enabling it as part of this bug.

Comment 2

[Paul Adenot (:padenot)]

I've talked with alex he will have a quick look on this.

Comment 3

[Alex Chronopoulos [:achronop]]

I have been trying reproducing it in Linux with no success. I am using a bluetooth handsfree and I am able to see in the logs the ThreadedDriver thread starting and stopping as expected. Also, I don't experience any A/V lag. I have tested with a debug build and an opt build. Thus, I believe it is something specific to OSX. Next, I will try reproducing in OSX.

Comment 4

[Alex Chronopoulos [:achronop]]

In OSX this error can be reproduced easily. It happens in every unmute when the AudioCallbackDriver is switching from output only to duplex. Even if the delay is not as much as 4 secs, which reported in the description, it is about 1.5 secs, which is long enough for real-time communication.

Looking at the code, AudioStreamState is set to pending when the driver starts and becomes Running in StateChangeCallback when the state is CUBEB_STREAM_STARTED. The device is supposed to start right after that callback. However, a Bluetooth device in OSX must not start immediately and thus the delay occurs.

I am working on a patch that will keep the value of AudioStreamState to pending till the first audio callback. That seems to overcome the issue. Initial testing looks promising.

Comment 5

[Alex Chronopoulos [:achronop]]

Attachment: Bug 1605134 - Stop Fallback driver after the first audio callback. r?pehrsons

On an AudioCallback driver switch, a Fallback driver operates to run the graph during the switch. The fallback driver is stopped when the AudioCallbackDriver::StateCallback reports the started state. A device is supposed to start right after the start callback but in OSX, bluetooth devices can take several hundred milliseconds until the first audio callback arrives.

With this change, the fallback driver is kept alive until the first audio callback. On first audio callback the Fallback driver is being requested to stop and silence is returned. Fallback driver, in the next iteration, will run the graph for last time and stop itself.

Comment 6

[Alex Chronopoulos [:achronop]]

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

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

There's a r+ patch which didn't land and no activity in this bug for 2 weeks.
:pehrsons, could you have a look please?
For more information, please visit auto_nag documentation.

Comment 8

[Andreas Pehrson [:pehrsons]]

There is more work to be done here.

Comment 9

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Ensure there are no callbacks between CUBEB_STATE_STARTED and CUBEB_STATE_STOPPED in MockCubeb. r?padenot!

Depends on D97309

Comment 10

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Add more casting helpers to MockCubeb and MockCubebStream. r?padenot!

Comment 11

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Add a wrapper around MockCubebStream that supports ref-counting and WeakPtr. r?padenot!

Comment 12

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Rename StateComputedEnd to StateComputedTime. r?padenot!

StateComputedEnd was likely a typo back in the day. The member in the graph is
mStateComputedTime, so let's center around that.

Comment 13

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Break out WaitFor helpers to a dedicated file. r?padenot!

This allows re-using them in TestAudioCallbackDriver.cpp.

Comment 14

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Assert that the output buffer was filled during the callback. r?padenot!

Filling the output buffer, even if only with silence, is needed for the audio
driver to iterate with the right number of frames. This patch makes sure the
graph always does this.

Comment 15

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Assert that the callback buffer is indeed filled fully. r?padenot!

Comment 16

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Feed the mixer from the MockGraphInterface in TestAudioCallbackDriver.cpp. r?padenot!

Feeding the mixer is needed for AudioCallbackDriver to properly bookkeep how far
to iterate the graph, relative to how many frames are fed from the data
callback.

Comment 17

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Give MockCubeb users the ability to control when to start a MockCubebStream. r?padenot!

Comment 18

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Add a FramesGeneratedEvent to MockCubeb. r?padenot!

The existing FramesProcessedEvent will only be notified if there is an
AudioVerifier attached. FramesGeneratedEvent can be used to see how much audio
a MockCubebStream has generated without the verifier.

Comment 19

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Add gtest for slow starting devices. r?padenot!

Comment 20

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Fix review comments. r?padenot!

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/841eedd33424
Ensure there are no callbacks between CUBEB_STATE_STARTED and CUBEB_STATE_STOPPED in MockCubeb. r=padenot
https://hg.mozilla.org/integration/autoland/rev/56ead9091c47
Add more casting helpers to MockCubeb and MockCubebStream. r=padenot
https://hg.mozilla.org/integration/autoland/rev/0736167ed294
Add a wrapper around MockCubebStream that supports ref-counting and WeakPtr. r=padenot
https://hg.mozilla.org/integration/autoland/rev/0ba16e1f73ae
Rename StateComputedEnd to StateComputedTime. r=padenot
https://hg.mozilla.org/integration/autoland/rev/f8612b562aa7
Break out WaitFor helpers to a dedicated file. r=padenot
https://hg.mozilla.org/integration/autoland/rev/c24bff49f331
Assert that the output buffer was filled during the callback. r=padenot
https://hg.mozilla.org/integration/autoland/rev/3ef7199a547a
Assert that the callback buffer is indeed filled fully. r=padenot
https://hg.mozilla.org/integration/autoland/rev/e5fb448bbadf
Feed the mixer from the MockGraphInterface in TestAudioCallbackDriver.cpp. r=padenot
https://hg.mozilla.org/integration/autoland/rev/9859d35abce6
Simulate slow starting devices in MockCubeb. r=padenot
https://hg.mozilla.org/integration/autoland/rev/6fed7e4730c5
Add gtest for slow starting devices. r=padenot
https://hg.mozilla.org/integration/autoland/rev/dda7d98d3da7
Stop Fallback driver after the first audio callback. r=pehrsons
https://hg.mozilla.org/integration/autoland/rev/f65dbe0c4c64
Fix review comments. r=padenot

Comment 22

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Fix bustage.

D97403 got overtaken the gtest for AudioInputTrackDisabling. This fixes the
bustage that combination resulted in.

Comment 23

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/867bffcbc35a
Fix bustage.

Comment 24

[Narcis Beleuzu [:NarcisB]]

Backed out for GTest failures on TestAudioTrackGraph

Backout link: https://hg.mozilla.org/integration/autoland/rev/c1966d168b33b8ea005418d5564e2b414bb535a9
Log link: https://treeherder.mozilla.org/logviewer?job_id=322336552&repo=autoland&lineNumber=29579

Comment 25

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5b690fe1945c
Backed out changeset 867bffcbc35a for causing bustages on backout. CLOSED TREE

Comment 26

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Add a FramesIteratedEvent to the mock graph so we can track fallback driver progress. r?padenot!

Comment 27

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Remove assert that catches a graph iterating 0 ticks. r?padenot

0 ticks is fine, and happens often for graphs with a low sample rate because in
such cases the minimum 128-frame AudioBlock is rather large and spans multiple
iterations.

Comment 28

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Switch the CrossGraphPort's log module to MediaTrackGraph. r?padenot!

These MediaTrack used to subclass ForwardedInputTrack and that module is
legacy from that time. MediaTrackGraph makes more sense. We should reduce the
number of log modules around the graph and converge on the MTG one.

Comment 29

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1605134 - Simplify some input member access in CrossGraphTransmitter. r?padenot!

Comment 30

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3714fa7460ce
Ensure there are no callbacks between CUBEB_STATE_STARTED and CUBEB_STATE_STOPPED in MockCubeb. r=padenot
https://hg.mozilla.org/integration/autoland/rev/9bce7dcae91c
Add more casting helpers to MockCubeb and MockCubebStream. r=padenot
https://hg.mozilla.org/integration/autoland/rev/7dfb915d51ef
Add a wrapper around MockCubebStream that supports ref-counting and WeakPtr. r=padenot
https://hg.mozilla.org/integration/autoland/rev/c8143eab62d2
Rename StateComputedEnd to StateComputedTime. r=padenot
https://hg.mozilla.org/integration/autoland/rev/bffa738ccb6f
Break out WaitFor helpers to a dedicated file. r=padenot
https://hg.mozilla.org/integration/autoland/rev/3c5d3f8baf28
Assert that the output buffer was filled during the callback. r=padenot
https://hg.mozilla.org/integration/autoland/rev/efa10675b86d
Assert that the callback buffer is indeed filled fully. r=padenot
https://hg.mozilla.org/integration/autoland/rev/e88bb30c3221
Feed the mixer from the MockGraphInterface in TestAudioCallbackDriver.cpp. r=padenot
https://hg.mozilla.org/integration/autoland/rev/ce6924b1f900
Add a FramesIteratedEvent to the mock graph so we can track fallback driver progress. r=padenot
https://hg.mozilla.org/integration/autoland/rev/c010356d4a48
Give MockCubeb users the ability to control when to start a MockCubebStream. r=padenot
https://hg.mozilla.org/integration/autoland/rev/ac23d3b40f2d
Add gtest for slow starting devices. r=padenot
https://hg.mozilla.org/integration/autoland/rev/2747068f6397
Stop Fallback driver after the first audio callback. r=pehrsons
https://hg.mozilla.org/integration/autoland/rev/c3cf634bffb3
Fix review comments. r=padenot
https://hg.mozilla.org/integration/autoland/rev/addf9298c4fe
Remove assert that catches a graph iterating 0 ticks. r=padenot
https://hg.mozilla.org/integration/autoland/rev/18ca27b07da3
Switch the CrossGraphPort's log module to MediaTrackGraph. r=padenot
https://hg.mozilla.org/integration/autoland/rev/81d82ce7eecd
Simplify some input member access in CrossGraphTransmitter. r=padenot

Comment 31

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/4dedf07fafcf
Ensure there are no callbacks between CUBEB_STATE_STARTED and CUBEB_STATE_STOPPED in MockCubeb. r=padenot
https://hg.mozilla.org/integration/autoland/rev/29edda566e71
Add more casting helpers to MockCubeb and MockCubebStream. r=padenot
https://hg.mozilla.org/integration/autoland/rev/357b00e7a051
Add a wrapper around MockCubebStream that supports ref-counting and WeakPtr. r=padenot
https://hg.mozilla.org/integration/autoland/rev/f8b9c0181a32
Rename StateComputedEnd to StateComputedTime. r=padenot
https://hg.mozilla.org/integration/autoland/rev/74a6757be69d
Break out WaitFor helpers to a dedicated file. r=padenot
https://hg.mozilla.org/integration/autoland/rev/949487b6a742
Assert that the output buffer was filled during the callback. r=padenot
https://hg.mozilla.org/integration/autoland/rev/2e5dd044dfd2
Assert that the callback buffer is indeed filled fully. r=padenot
https://hg.mozilla.org/integration/autoland/rev/cfc115ee98c2
Feed the mixer from the MockGraphInterface in TestAudioCallbackDriver.cpp. r=padenot
https://hg.mozilla.org/integration/autoland/rev/af228160e8ea
Add a FramesIteratedEvent to the mock graph so we can track fallback driver progress. r=padenot
https://hg.mozilla.org/integration/autoland/rev/863b74ef8e70
Give MockCubeb users the ability to control when to start a MockCubebStream. r=padenot
https://hg.mozilla.org/integration/autoland/rev/91a6ec380d44
Add gtest for slow starting devices. r=padenot
https://hg.mozilla.org/integration/autoland/rev/8c14bf385506
Stop Fallback driver after the first audio callback. r=pehrsons
https://hg.mozilla.org/integration/autoland/rev/852e2eac194a
Fix review comments. r=padenot
https://hg.mozilla.org/integration/autoland/rev/7b0249b51e04
Remove assert that catches a graph iterating 0 ticks. r=padenot
https://hg.mozilla.org/integration/autoland/rev/763abca071e0
Switch the CrossGraphPort's log module to MediaTrackGraph. r=padenot
https://hg.mozilla.org/integration/autoland/rev/fcd809baf4c6
Simplify some input member access in CrossGraphTransmitter. r=padenot

Comment 32

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/4dedf07fafcf
https://hg.mozilla.org/mozilla-central/rev/29edda566e71
https://hg.mozilla.org/mozilla-central/rev/357b00e7a051
https://hg.mozilla.org/mozilla-central/rev/f8b9c0181a32
https://hg.mozilla.org/mozilla-central/rev/74a6757be69d
https://hg.mozilla.org/mozilla-central/rev/949487b6a742
https://hg.mozilla.org/mozilla-central/rev/2e5dd044dfd2
https://hg.mozilla.org/mozilla-central/rev/cfc115ee98c2
https://hg.mozilla.org/mozilla-central/rev/af228160e8ea
https://hg.mozilla.org/mozilla-central/rev/863b74ef8e70
https://hg.mozilla.org/mozilla-central/rev/91a6ec380d44
https://hg.mozilla.org/mozilla-central/rev/8c14bf385506
https://hg.mozilla.org/mozilla-central/rev/852e2eac194a
https://hg.mozilla.org/mozilla-central/rev/7b0249b51e04
https://hg.mozilla.org/mozilla-central/rev/763abca071e0
https://hg.mozilla.org/mozilla-central/rev/fcd809baf4c6