aws / amazon-chime-sdk-js

A JavaScript client library for integrating multi-party communications powered by the Amazon Chime service.
Apache License 2.0
704 stars 475 forks source link

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

Open rixiang-dev opened 1 year ago

rixiang-dev commented 1 year ago

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?

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}}
ltrung commented 1 year ago

To workaround for now, please make sure that startAudioInput finished before start connecting.

dbish commented 10 months ago

One more customer here who hit this issue using the chime sdk. We used the workaround but adding a +1 to this coming up as an issue and being a little tricky to discover what's going wrong so would be great to fix in the library.

brycepj commented 9 months ago

Just wanted to share that we discovered that this was the cause of numerous long-standing reports that "other people can't hear me" or "I can't hear other people" when joining a meeting. While enforcing that device setup occurs first does solve the race condition, doing that also slows join time significantly (for me, on my machine, adds at least 2500ms), as compared to letting device setup and peer connection happen somewhat in parallel. Which is quite a tradeoff for us.