Audio input device may be overridden by null audio device if joining meeting too quickly

[rixiang-dev]

What happened and what did you expect to happen?

When joining demo app (e.g. navigating device selection page fast (<1s) or quick-join which skips device selection), a race condition might happen between open audio device(getUserMedia()) and creating empty device during ReceiveAudioInputTask() during signaling. If former one, which is triggered asynchronous when joining a meeting, was still pending when ReceiveAudioInputTask() being executed during connection, SDK would create a null audio device. Compared with actual selected audio device still being read, this null audio device was added later into audioInputTaskQueue, meaning when consuming this queue it would be proceeded after actual audio input device was loaded and overrode it. Audio will not be working until user manually select audio device again later.

cd94ece5-7bba-4477-beff-8bc4987e0706 is a call between iPhone w/o Web Audio(iOS) and Macbook (left and right).

Notes (chat message) during test

iOS Cannot hear left "attendeeId":"4df2cc19-bcc7-a179-1d58-5096fcea7632","mediaType":"VIDEO","externalUserId":"7eeed60e#iOS" left's audio could heard by right ([DEMO] 57228eb4-ddf7-1fa3-e726-ab7c1cdc04e4 present = true (3e86a7ba#right)) left can hear audio from right ([DEMO] 57228eb4-ddf7-1fa3-e726-ab7c1cdc04e4 present = true (3e86a7ba#right)) after selected mic in demo app, iOS's audio works fine

Have you reviewed our existing documentation?

• [X] GitHub issues
• [X] FAQs page
• [X] README page
• [X] Feature-specific guides

Reproduction steps

1. in any demo app, when joining a meeting, either quick-join to skip device selection page, or navigate device selection page fast (<1s)
2. audio is not working (as created empty audio device overrode real audio device)
3. attendee has to manually select real audio device to remediate

Amazon Chime SDK for JavaScript version

3.9.0

What browsers are you seeing the problem on?

Chrome on iPhone w/ iOS 16.1

Browser version

108.0.5359.112

Meeting and Attendee ID Information.

MeetingID: cd94ece5-7bba-4477-beff-8bc4987e0706 AttendeeID: 4df2cc19-bcc7-a179-1d58-5096fcea7632

Browser console logs

Full JS SDK demo log: cd94ece5-7bba-4477-beff-8bc4987e0706-IOS.txt

Selected logs with annotation :

// A. before joining
// from openAudioInputFromSelection() -> this.audioInputSelectionToDevice(audioInput.value);
// const device = await this.audioInputSelectionToDevice(audioInput.value);
LOG[DEMO] VF supported: false
LOG[DEMO] VF enabled: false
LOG[DEMO] Selecting audio input E3D18C6D23E8EE2BEB37B811475B266D72513E3F
INFO2022-12-22T21:42:44.632Z [INFO] SDK - API/DefaultAudioVideoFacade/cd94ece5-7bba-4477-beff-8bc4987e0706/4df2cc19-bcc7-a179-1d58-5096fcea7632/startAudioInput "E3D18C6D23E8EE2BEB37B811475B266D72513E3F"
INFO2022-12-22T21:42:44.632Z [INFO] SDK - Choosing intrinsic audio input device E3D18C6D23E8EE2BEB37B811475B266D72513E3F
INFO2022-12-22T21:42:44.633Z [INFO] SDK - requesting new audio device with constraint {"audio":{"echoCancellation":true,"googEchoCancellation":true,"googEchoCancellation2":true,"googAutoGainControl":true,"googAutoGainControl2":true,"googNoiseSuppression":true,"googNoiseSuppression2":true,"googHighpassFilter":true,"deviceId":{"exact":"E3D18C6D23E8EE2BEB37B811475B266D72513E3F"}}}
// sync api (newDevice.stream = await navigator.mediaDevices.getUserMedia(proposedConstraints);)
INFO2022-12-22T21:42:44.678Z [INFO] SDK - Device change event callback is triggered
DEBUG2022-12-22T21:42:44.704Z [DEBUG] SDK - Update device info cache with devices: [{"deviceId":"E3D18C6D23E8EE2BEB37B811475B266D72513E3F","kind":"audioinput","label":"iPhone Microphone","groupId":""},{"deviceId":"6DD90409F496C5D8BB106E0217521E42DEB7B1CF","kind":"videoinput","label":"Front Camera","groupId":""},{"deviceId":"12CA7B11B9AE0D7516EEA2191E176782D87DB90D","kind":"videoinput","label":"Back Camera","groupId":""}]
// this.log(`Switching to: ${this.selectedVideoInput}`);
LOG[DEMO] Switching to: null
// joined meeting after 0.7s
INFO2022-12-22T21:42:45.396Z [INFO] SDK - API/DefaultAudioVideoFacade/cd94ece5-7bba-4477-beff-8bc4987e0706/4df2cc19-bcc7-a179-1d58-5096fcea7632/stopVideoInput
LOG[DEMO] no video device selected

// B. after audiovideo.start() called and during singaling
INFO2022-12-22T21:42:45.398Z [INFO] SDK - transitioning from NotConnected to Connecting with Connect
...
INFO2022-12-22T21:42:45.399Z [INFO] SDK - Needs to wait for attendee presence? false
INFO2022-12-22T21:42:45.400Z [INFO] SDK - running task AudioVideoStart/cd94ece5-7bba-4477-beff-8bc4987e0706/4df2cc19-bcc7-a179-1d58-5096fcea7632
...
INFO2022-12-22T21:42:45.401Z [INFO] SDK - ReceiveAudioInputTask waiting for dependencies: 
...
INFO2022-12-22T21:42:45.402Z [INFO] SDK - running task ReceiveAudioInputTask
INFO2022-12-22T21:42:45.402Z [INFO] SDK - No audio device chosen, creating empty audio device
...
// A. getUserMedia() took 1.6s 
INFO2022-12-22T21:42:46.241Z [INFO] SDK - got audio device for constraints {"audio":{"echoCancellation":true,"googEchoCancellation":true,"googEchoCancellation2":true,"googAutoGainControl":true,"googAutoGainControl2":true,"googNoiseSuppression":true,"googNoiseSuppression2":true,"googHighpassFilter":true,"deviceId":{"exact":"E3D18C6D23E8EE2BEB37B811475B266D72513E3F"}}}
DEBUG2022-12-22T21:42:46.241Z [DEBUG] SDK - GroupId of deviceId E3D18C6D23E8EE2BEB37B811475B266D72513E3F found in cache is empty
DEBUG2022-12-22T21:42:46.241Z [DEBUG] SDK - Set activeDevice to {"groupId":"","stream":{},"constraints":{"audio":{"echoCancellation":true,"googEchoCancellation":true,"googEchoCancellation2":true,"googAutoGainControl":true,"googAutoGainControl2":true,"googNoiseSuppression":true,"googNoiseSuppression2":true,"googHighpassFilter":true,"deviceId":{"exact":"E3D18C6D23E8EE2BEB37B811475B266D72513E3F"}}}}
DEBUG2022-12-22T21:42:46.241Z [DEBUG] SDK - Notifying mute state after selection
INFO2022-12-22T21:42:46.241Z [INFO] SDK - API/DefaultDeviceController/startAudioInputDevice "E3D18C6D23E8EE2BEB37B811475B266D72513E3F" -> "success"
// B. another startAudioInputTask(), should be added into audioInputTaskQueue previously
// This was not triggered by demo app through DefaultAudioVideoFacade as no tracing log
INFO2022-12-22T21:42:46.242Z [INFO] SDK - Choosing intrinsic audio input device null
DEBUG2022-12-22T21:42:46.242Z [DEBUG] SDK - Compare current device constraint {"audio":{"echoCancellation":true,"googEchoCancellation":true,"googEchoCancellation2":true,"googAutoGainControl":true,"googAutoGainControl2":true,"googNoiseSuppression":true,"googNoiseSuppression2":true,"googHighpassFilter":true,"deviceId":{"exact":"E3D18C6D23E8EE2BEB37B811475B266D72513E3F"}}} to proposed constraints null
INFO2022-12-22T21:42:46.242Z [INFO] SDK - requesting new audio device with constraint null
INFO2022-12-22T21:42:46.243Z [INFO] SDK - got audio device for constraints null
DEBUG2022-12-22T21:42:46.243Z [DEBUG] SDK - Set activeDevice to {"groupId":"","stream":{},"constraints":null}
DEBUG2022-12-22T21:42:46.243Z [DEBUG] SDK - Notifying mute state after selection
LOG[DEMO] Updating Amazon Voice Focus display state: false
INFO2022-12-22T21:42:46.243Z [INFO] SDK - API/DefaultDeviceController/startAudioInputDevice null → "success"
LOG[DEMO] Starting audio preview.
...
LOG[DEMO] Switching to: 6DD90409F496C5D8BB106E0217521E42DEB7B1CF
...
INFO2022-12-22T21:42:46.244Z [INFO] SDK - ReceiveAudioInputTask took 842 ms
...
LOG[DEMO] Mute state: device E3D18C6D23E8EE2BEB37B811475B266D72513E3F is not muted
LOG[DEMO] Received an event: {"name":"audioInputSelected","attributes":{"attendeeId":"4df2cc19-bcc7-a179-1d58-5096fcea7632","browserMajorVersion":"108","browserName":"Chrome","browserVersion":"108.0.5359.112","deviceName":"Apple iPhone","externalMeetingId":"m2","externalUserId":"7eeed60e#iOS","meetingHistory":[{"name":"videoInputUnselected","timestampMs":1671745365397},{"name":"meetingStartRequested","timestampMs":1671745365399},{"name":"audioInputSelected","timestampMs":1671745366242},{"name":"audioInputSelected","timestampMs":1671745366243}],"meetingId":"cd94ece5-7bba-4477-beff-8bc4987e0706","osName":"iOS","osVersion":"16.1","sdkVersion":"3.9.0","sdkName":"amazon-chime-sdk-js","timestampMs":1671745366242}}
LOG[DEMO] Mute state: device [object MediaStream] is not muted
LOG[DEMO] Received an event: {"name":"audioInputSelected","attributes":{"attendeeId":"4df2cc19-bcc7-a179-1d58-5096fcea7632","browserMajorVersion":"108","browserName":"Chrome","browserVersion":"108.0.5359.112","deviceName":"Apple iPhone","externalMeetingId":"m2","externalUserId":"7eeed60e#iOS","meetingHistory":[{"name":"videoInputUnselected","timestampMs":1671745365397},{"name":"meetingStartRequested","timestampMs":1671745365399},{"name":"audioInputSelected","timestampMs":1671745366242},{"name":"audioInputSelected","timestampMs":1671745366243}],"meetingId":"cd94ece5-7bba-4477-beff-8bc4987e0706","osName":"iOS","osVersion":"16.1","sdkVersion":"3.9.0","sdkName":"amazon-chime-sdk-js","timestampMs":1671745366243}}