1398788 - Deadlock on webrtc call Audio+Video when plug or uplug EarPOds (3.5mm plug)

Status: RESOLVED FIXED

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

Description

[Alex Chronopoulos [:achronop]]

The problem is reproduced in gum test Audio and Video. In order to repro:
1. Go to https://mozilla.github.io/webrtc-landing/gum_test.html
2. Click Audio&Video
3. Accept the default device (build in) for audio and video.
4. Plug and unplug 3.5 mm Apple Ear Pod repeatable (on debug under debugger about 20 times on optimized build sooner).

Result: Video freeze. Refresh fix the problem. 

More Info: I could not repro when the gUM request was audio only. It is reproducible with Audio and Video.

Comment 1

[Alex Chronopoulos [:achronop]]

Attachment: bt-all-non-e10s.txt

Backtrace from non e10s debug build after the video is frozen

Comment 2

[Alex Chronopoulos [:achronop]]

It does not look like a cubeb issue. Can anyone with more general knowledge of WebRTC A/V check the backtrace?

Comment 3

[Andreas Pehrson [:pehrsons]]

The only thread that looks interesting at all to me is #118:
>   thread #118: tid = 0x3c121, 0x00007fff92ecc10a libsystem_kernel.dylib`__semwait_signal + 10
>     frame #0: 0x00007fff92ecc10a libsystem_kernel.dylib`__semwait_signal + 10
>     frame #1: 0x00007fff858f7d0f libsystem_c.dylib`nanosleep + 199
>     frame #2: 0x00007fff858f7c02 libsystem_c.dylib`usleep + 54
>     frame #3: 0x00007fff93b30ded CoreMediaIO`CMIOGraph::OneOrMoreInputUnitsAreReadyToBePulled(bool&) + 547
>     frame #4: 0x00007fff93b3163b CoreMediaIO`CMIOGraph::DoWork(unsigned int) + 119
>     frame #5: 0x00007fff93b34463 CoreMediaIO`CMIO::Thread::QueuedTWorkThread<unsigned int>::DoWork() + 125
>     frame #6: 0x00007fff93b3d3cb CoreMediaIO`CMIO::Thread::SignaledThread::ThreadLoop() + 253
>     frame #7: 0x00007fff93b3d2b1 CoreMediaIO`CMIO::Thread::SignaledThread::WorkQueuedThreadCallback(void*) + 159
>     frame #8: 0x00007fff8bc8b82e CoreMedia`figThreadMain + 616
>     frame #9: 0x00007fff8ffcb99d libsystem_pthread.dylib`_pthread_body + 131
>     frame #10: 0x00007fff8ffcb91a libsystem_pthread.dylib`_pthread_start + 168
>     frame #11: 0x00007fff8ffc9351 libsystem_pthread.dylib`thread_start + 13

I see that VideoCapture and Cameras IPC threads are live, but they're just waiting for events.

I'd suggest the MediaStreamGraph is stalled. Could thread #118 be the audio callback thread?

Comment 4

[Alex Chronopoulos [:achronop]]

> Could thread #118 be the audio callback thread?

No it must be something else. I break on audio callback and on CMIOGraph::OneOrMoreInputUnitsAreReadyToBePulled and they are 2 different threads.

Comment 5

[Alex Chronopoulos [:achronop]]

That's the MediaStreamGraph:4,cubeb:4 logs

[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "SoundflowerEngine:1"
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "SoundflowerEngine:0"
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "AppleHDAEngineInput:1B,0,1,0:1" (PREFERRED)
[Parent 7083] WARNING: Cannot query channel count on a AudioSegment with no chunks.: '!mChunks.IsEmpty()', file /Users/achronopoulos/repos/mozilla/firefox/dom/media/AudioSegment.h, line 389
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2186: (0x12db12000) Opening output side: rate 44100, channels 2, format 2, latency in frames 512.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2209: (0x12db12000) Output device sampling rate: 44100.00
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2009: (0x12db12000) No need to update output buffer size already 512 frames
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2257: (0x12db12000) Output audiounit init successfully.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2515: (0x12db12000) Cubeb stream init successful.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2604: Cubeb stream (0x12db12000) started successfully.
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x137873570 to graph 0x12d954800, count 1
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x137873570 to graph 0x12d954800, count 1
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x12d0c7bc0 to graph 0x12d954800, count 2
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x12d0c7bc0 to graph 0x12d954800, count 2
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x12d0c8700 to graph 0x12d954800, count 3
[Unnamed thread 0x1387db540]: D/MediaStreamGraph Adding media stream 0x12d0c8700 to graph 0x12d954800, count 3
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2632: Cubeb stream (0x12db12000) stopped successfully.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2575: Cubeb stream (0x12db12000) destroyed successful.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:1485: New aggregate device 210
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:1508: Add devices input 189 and output 196 into aggregate device 210
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2084: (0x12d8a2000) Opening input side: rate 44100, channels 2, format 2, latency in frames 512.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2100: (0x12d8a2000) Input device sampling rate: 44100.00
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2009: (0x12d8a2000) No need to update input buffer size already 512 frames
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2169: (0x12d8a2000) Input audiounit init successfully.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2186: (0x12d8a2000) Opening output side: rate 44100, channels 2, format 2, latency in frames 512.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2209: (0x12d8a2000) Output device sampling rate: 44100.00
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2009: (0x12d8a2000) No need to update output buffer size already 512 frames
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2257: (0x12d8a2000) Output audiounit init successfully.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2515: (0x12d8a2000) Cubeb stream init successful.
[CubebOperation #1]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb_audiounit.cpp:2604: Cubeb stream (0x12d8a2000) started successfully.
[Parent 7083] WARNING: No audio tracks, but full-duplex audio is enabled!!!!!: file /Users/achronopoulos/repos/mozilla/firefox/dom/media/MediaStreamGraph.cpp, line 533
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "SoundflowerEngine:1"
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "SoundflowerEngine:0"
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "AppleHDAEngineInput:1B,0,1,0:1" (PREFERRED)
[MediaManager]: E/cubeb /Users/achronopoulos/repos/mozilla/firefox/media/libcubeb/src/cubeb.c:565: DeviceID: "org.mozilla.CubebAggregateDevice_558eb1bbd06a3"

Comment 6

[Alex Chronopoulos [:achronop]]

Attachment: video-freeze.txt

MediaStreamGraph:4,cubeb:4 full logs

Comment 7

[Bulk Bug Changes for mreavy's org]

Mass change P1->P2 to align with new Mozilla triage process

Comment 8

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Fixed bug 1399905.

Comment 9

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

s/Fixed/Fixed by/

Comment 10

[Ryan VanderMeulen [:RyanVM]]

Given the state of bug 1399905 the fact that we've already created RC1 for Fx56, it seems highly unlikely we'll be fixing this in 56 at this point :(