1480856 - getUserMedia with processing causes assertion in MediaEngineWebRTCAudio.cpp

Status: RESOLVED FIXED

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

Description

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Attachment: Log of issue with MediaManager:5

After the changes in bug 1404977 I reliably hit an assertion[0] after calling getUserMedia with if any one or more of echoCancellation, autoGainControl, and noiseSuppression are enabled.

STR:
- Navigate to https://codepen.io/SingingTree/pen/yjaRzv
- Check 1 or more of the AEC, AGC, NC check boxes.
- Click the New gUM Request button and accept the gUM prompt
- The assert is immediately hit

The issue occurs in a VMWare VM, and happen if I select microphone or monitor of sound-card in gUM. Both these devices are being exposed to the VM by VMWare from the host computer (A Lenovo P51). If I select the 'Monitor of Null Output' device used by our tests the assertion is not hit.

If I enable logging it appear that I'm getting double appends of packetized audio, e.g. I see the following in the log:
>> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
>> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
>> V/MediaManager NotifyPull, desired = 2176
>> V/MediaManager Pulling 270 frames of silence for allocation 0x7fb0f0954c00

This seems odd, but I'm not so familiar with this area to be sure if this is related. Please see attached log for a more complete example.

[0]: https://searchfox.org/mozilla-central/rev/e52cd92858800a69b74cb97d26d9bdb960d611ca/dom/media/webrtc/MediaEngineWebRTCAudio.cpp#835

Comment 1

[Nils Ohlmeier [:drno]]

jib do you have any idea if what bryce sees here is harmless or a serious issue?

Comment 2

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

Hard to say. Andreas last touched this code, so lateraling the ni? to him.

Comment 3

[Andreas Pehrson [:pehrsons]]

When hitting it that early it's usually harmless and more of a flaw in the logic building up the assert than in the logic the assert is checking.

It has proven hard to get this assert stable, but it can detect serious buffering issues so we don't want to get rid of it either. As long as I can catch it in rr I can at least improve stability.


(In reply to Bryce Seager van Dyk (:bryce) from comment #0)
> If I enable logging it appear that I'm getting double appends of packetized
> audio, e.g. I see the following in the log:
> >> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
> >> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
> >> V/MediaManager NotifyPull, desired = 2176
> >> V/MediaManager Pulling 270 frames of silence for allocation 0x7fb0f0954c00
> 
> This seems odd, but I'm not so familiar with this area to be sure if this is
> related. Please see attached log for a more complete example.

The two pushes of packetized audio are most likely from two different callbacks. That wouldn't be odd.

Comment 4

[Andreas Pehrson [:pehrsons]]

I wasn't able to repro with any of my mics as input device, but I was able to repro using a monitor for input. Under rr too, so let me dig into it.

Comment 5

[Andreas Pehrson [:pehrsons]]

Ok so the logic accounting for an initial block of 128 frames is working, but we fail the assert once we've put more than 128 frames in the input packetizer. We need to allow for another 10ms of silence as that's how much the input packetizer can sit on before passing data on to processing and ultimately our input track to avoid another pull of silence.

Comment 6

[Andreas Pehrson [:pehrsons]]

(In reply to Andreas Pehrson [:pehrsons] from comment #3)
> When hitting it that early it's usually harmless and more of a flaw in the
> logic building up the assert than in the logic the assert is checking.
> 
> It has proven hard to get this assert stable, but it can detect serious
> buffering issues so we don't want to get rid of it either. As long as I can
> catch it in rr I can at least improve stability.
> 
> 
> (In reply to Bryce Seager van Dyk (:bryce) from comment #0)
> > If I enable logging it appear that I'm getting double appends of packetized
> > audio, e.g. I see the following in the log:
> > >> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
> > >> V/MediaManager Appending 441 frames of packetized audio for allocation 0x7fb0f0954c00
> > >> V/MediaManager NotifyPull, desired = 2176
> > >> V/MediaManager Pulling 270 frames of silence for allocation 0x7fb0f0954c00
> > 
> > This seems odd, but I'm not so familiar with this area to be sure if this is
> > related. Please see attached log for a more complete example.
> 
> The two pushes of packetized audio are most likely from two different
> callbacks. That wouldn't be odd.

When I was hitting this I got the same double-appends, and they turned out to be from the same callback. This was because I was getting callbacks of 896 frames at 44100Hz and processing happens in packets of 10ms. 896 frames is more than 20ms so we iterated over the PacketizeAndProcess code twice per callback until we came around with a full packet from all the spillover parts (every ~32 callbacks). Then we'd process three packets and before iterating the graph. Rinse and repeat..

Comment 7

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1480856 - Allow for another 10ms of silence when processing audio input. r?achronop

Comment 8

[Phabricator Automation]

Comment on attachment 8997893 [details]
Bug 1480856 - Allow for another 10ms of silence when processing audio input. r?achronop

Alex Chronopoulos [:achronop] has approved the revision.

https://phabricator.services.mozilla.com/D2786

Comment 9

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Tested applying the patch and am no longer hitting the assert.

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b118b720b2c7
Allow for another 10ms of silence when processing audio input. r=achronop

Comment 11

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/b118b720b2c7