Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[iOS] RtcEngine.muteAllRemoteAudioStreams(false) has 10 second delay to unmute remote audio after using Speech To Text #931

Open
ChrisMICDUP opened this issue Mar 8, 2023 · 3 comments
Open

[iOS] RtcEngine.muteAllRemoteAudioStreams(false) has 10 second delay to unmute remote audio after using Speech To Text #931

ChrisMICDUP opened this issue Mar 8, 2023 · 3 comments

Comments

@ChrisMICDUP
Copy link

Describe the bug
My app joins an Agora channel in LiveStreaming mode and listens to a Host broadcaster. It then allows you to record a message on the phone (using flutter_sound) and convert to text (using speech_to_text) these are stored int the cloud, while the recording is in progress we mute all remote audio on the channel.

After the recording is complete, we unmute the remote audio and continue to listen to the live stream. When we unmute, there is a 10 second delay before remote audio is heard. This was working prior to the upgrade to Flutter SDK v6.1.0

If I remove the calls to the STT package, there is no delay.

Expected behavior
The delay should be significantly less than 10 seconds.

It seems that the STT package is conflicting with Agora which goes into a retry period prior to restarting the audio unit - see the agorasdk.log snippet.

Is there a parameter I can try that would reduce this delay? NOTE: I have implemented the RtcEngine_setParameters params {"parameters":"{"che.audio.keep.audiosession": true}"} call with no effect.

Smartphone (please complete the following information):

  • Device: iPhone 13 mini
  • OS: iOS 16.3.1
  • agora_rtc_engine: ^6.1.0
  • flutter_sound: ^9.2.13
  • speech_to_text: ^6.1.1

Additional context

flutter console

flutter: 2023-03-08 09:58:11.037370: XXXXX RTCEngineProviderState connect, state = RTCConnectionState.DISCONNECTED
flutter: 2023-03-08 09:58:11.044259: XXXXX RTCEngineProviderState initEngine RtcEngine.create for role=ClientRoleType.clientRoleAudience
[debug] [iris_logger.cc:92] /var/mobile/Containers/Data/Application/C0F68F05-3CCA-46AC-9625-92395870B3D1/Library/Caches/agora-iris.log
[debug] [iris_logger.cc:92] /var/mobile/Containers/Data/Application/C0F68F05-3CCA-46AC-9625-92395870B3D1/Library/Caches/agora-iris.log
[debug] [iris_logger.cc:92] /var/mobile/Containers/Data/Application/C0F68F05-3CCA-46AC-9625-92395870B3D1/Library/Caches/agora-iris.log
[debug] [iris_rtc_engine_impl.cc:112] api name RtcEngine_initialize params {"context":{"appId":"1362***************52b9"}}
AudioBeautyExtensionProvider::enumerateExtensions extension_count:22 
[debug] [iris_rtc_device_manager_impl.cc:29] IrisRtcDeviceManagerImpl Initialize
[debug] [iris_rtc_media_player_impl.cc:32] IrisMediaPlayerImpl Initialize
[debug] [iris_rtc_spatial_audio_engine_impl.cc:207] IrisLocalSpatialAudioEngineImpl Initialize
[debug] [iris_rtc_media_recoder_impl.cc:19] IrisMediaRecoderImpl Initialize
[debug] [iris_rtc_music_center_impl.cc:25] IrisMusicPlayerImpl Initialize
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_setAppType params {"appType":4}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_setClientRole params {"options":null,"role":2}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_setDefaultAudioRouteToSpeakerphone params {"defaultToSpeaker":true}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_registerEventHandler params {"event":10750526192}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_enableVideo params {}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_muteLocalAudioStream params {"mute":true}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
flutter: 2023-03-08 09:58:11.253835: getToken /api/get/tokens/s21663534667550?role=2&timeout=null
flutter: 2023-03-08 09:58:11.746914 XXXXX RTCEngineProviderState setParameters
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_setParameters params {"parameters":"{\"che.audio.keep.audiosession\": true}"}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
flutter: 2023-03-08 09:58:11.749845 XXXXX RTCEngineProviderState connect channelName=s21663534667550, token=00613629663327f4d27bc13f073dc6f52b9IACoXtrzWpW/8HaYRN+sBx6ySdYlCkpailPbslouJe4XVazAlOwA2P5nEACFutEB4/YIZAEAAQCDwQdk, uid=996032720
[debug] [iris_rtc_engine_impl.cc:112] api name RtcEngine_joinChannel2 params {"channelId":"s21663534667550","options":{"channelProfile":1,"clientRoleType":2},"token":"0061***************wQdk","uid":996032720}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
flutter: 2023-03-08 09:58:11.765798 XXXXX RTCEngineProviderState Connecting
flutter: RTCEngineProviderState audienceConnectionStateChanged ConnectionStateType.connectionStateConnecting ConnectionChangedReasonType.connectionChangedConnecting
flutter: 2023-03-08 09:58:11.773769: RTCEngineProviderState connect, state = RTCConnectionState.CONNECTED
flutter: RTCEngineProviderState audioRouteChanged 3
[info] [rtc_engine_event_handler.cc:53] channel s21663534667550 uid 996032720
[info] [rtc_engine_event_handler.cc:1524] channel s21663534667550 uid 996032720 remoteUid 2596996162
flutter: XXXXX _joinChannelSuccess hostUID=996032720, _localAgoraUid=0, localUid=996032720
flutter: RTCEngineProviderState audienceConnectionStateChanged ConnectionStateType.connectionStateConnected ConnectionChangedReasonType.connectionChangedJoinSuccess
flutter: 2023-03-08 09:58:12.264451 XXXXX RTCEngineProviderState _remoteAudioStateChanged reason=RemoteAudioStateReason.remoteAudioReasonRemoteUnmuted uid=2596996162 state=RemoteAudioState.remoteAudioStateStarting
flutter: 2023-03-08 09:58:12.273703: RTCEngineProviderState connect, state = RTCConnectionState.CONNECTED
flutter: 2023-03-08 09:58:12.437920 XXXXX RTCEngineProviderState _remoteAudioStateChanged reason=RemoteAudioStateReason.remoteAudioReasonRemoteUnmuted uid=2596996162 state=RemoteAudioState.remoteAudioStateDecoding

>>>> RECORD A MESSAGE

flutter: 2023-03-08 09:58:27.160946 XXXXX startRecording muteAllRemoteAudioStreams true
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_muteAllRemoteAudioStreams params {"mute":true}
flutter: startSpeechToText1 state=0
[plugin] Has permissions continuing with setup
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
flutter: 2023-03-08 09:58:27.237163 XXXXX RTCEngineProviderState _remoteAudioStateChanged reason=RemoteAudioStateReason.remoteAudioReasonLocalMuted uid=2596996162 state=RemoteAudioState.remoteAudioStateStopped
Required assets are not available for Locale:en_NZ
[plugin] invokeFlutter notifyStatus
[plugin] Availability changed: available
[plugin] invokeFlutter notifyStatus
flutter: startSpeechToText2 state=1
flutter: startSpeechToText3 state=1
-[NSError init] called; this results in an invalid NSError instance. It will raise an exception in a future release. Please call errorWithDomain:code:userInfo: or initWithDomain:code:userInfo:. This message shown only once.
[plugin] invokeFlutter soundLevelChange
...
[plugin] invokeFlutter soundLevelChange
[plugin] HypothesizeTranscription
[plugin] Encoded JSON result: {"alternates":[{"recognizedWords":"When","confidence":1}],"finalResult":false}
...
[plugin] Error deactivation: Session deactivation failed
[plugin] invokeFlutter notifyStatus
[plugin] Finished reading audio
[plugin] invokeFlutter notifyStatus
[plugin] HypothesizeTranscription
[plugin] Encoded JSON result: {"alternates":[{"recognizedWords":"12345","confidence":1}],"finalResult":false}
[plugin] invokeFlutter textRecognition
[plugin] FinishRecognition true
[plugin] Encoded JSON result: {"alternates":[{"recognizedWords":"12345","confidence":0.961}],"finalResult":true}
[plugin] invokeFlutter textRecognition
[plugin] FinishSuccessfully
flutter: onResult lastError = null lastStatus = notListening

flutter: 2023-03-08 09:58:31.897077 XXXXX stopRecording muteAllRemoteAudioStreams false
[debug] [iris_rtc_engine_impl.cc:114] api name RtcEngine_muteAllRemoteAudioStreams params {"mute":false}
[debug] [iris_rtc_engine_impl.cc:132] ret 0 result {"result":0}
flutter: 2023-03-08 09:58:32.037600 XXXXX RTCEngineProviderState _remoteAudioStateChanged reason=RemoteAudioStateReason.remoteAudioReasonLocalUnmuted uid=2596996162 state=RemoteAudioState.remoteAudioStateStarting
[plugin] Error deactivation: Session deactivation failed
[plugin] invokeFlutter notifyStatus

>>>>> 10 second gap

flutter: 2023-03-08 09:58:43.436914 XXXXX RTCEngineProviderState _remoteAudioStateChanged reason=RemoteAudioStateReason.remoteAudioReasonLocalUnmuted uid=2596996162 state=RemoteAudioState.remoteAudioStateDecoding
flutter: 2023-03-08 09:58:48.196868: RTCEngineProviderState close

agorasdk.log

[03/08/23 09:58:31:897][5905006][U]:(00000277): RtcEngine::muteAllRemoteAudioStreams(this:0x157d4ad80, mute:0)
[03/08/23 09:58:31:897][5905006][A]:(00000278):   RtcEngine::muteAllRemoteAudioStreamsEx(this:0x157d4ad80, mute:0, connection:[ channelId: localUid:0])
[03/08/23 09:58:31:897][5905011][A]:(00000279): RtcConnectionImpl::muteAllRemoteAudio(this:0x157d98f60, mute:0)
[03/08/23 09:58:31:897][5905011][A]:(00000280):   LocalUserImpl::subscribeAllAudio(this:0x158e73c00, void)
[03/08/23 09:58:31:897][5905011][I]:[LUR]: 996032720 subscribe all audio
[03/08/23 09:58:31:897][5905011][W]:[diag] Receive debug enabled 1 from config service
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter enable_hw_decoder : 
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter hardware_decoding : -1
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for enable_video_freeze_diagnose : true
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for retrans_detect_enable : false
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for use_sent_ts_enable : true
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter enable_minor_stream_intra_request : 0
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for switch_soft_decoder_threshold
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for enable_parser_reject
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for enable_hw_decoder
[03/08/23 09:58:31:897][5905011][I]:[VSM]: TDS value found for dec_mosreport : 1
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for che.hardware_decoding
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for tds_retrans_detect_enable
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for tds_use_sent_ts_enable
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for packet_buffer_size : 2048
[03/08/23 09:58:31:897][5905011][I]:[VSM]: no TDS value found for packet_buffer_size
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for enable_vpr : true
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.init_size : 1
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.max_size : 3
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.frozen_ms_thres : 200
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.frozen_rate_thres : 5
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.method : 0
[03/08/23 09:58:31:897][5905011][I]:[VSM]: user parameter value found for che.video.vpr.vpr_adaptive_thres : 50
[03/08/23 09:58:31:898][5905011][I]:on set parameters doc='{"che.audio.mute_peer":[2596996162,false]}', ret=0
[03/08/23 09:58:31:898][5905012][A]:(00000281): ChannelProxy::onAudioSubscribeStateChanged->onAudioSubscribeStateChanged(this:0x15d23b050, channel:s21663534667550, userId:-1697971134, oldState:1, newState:2, elapseSinceLastState:4735)
[03/08/23 09:58:31:898][5905011][W]:[diag] Receive debug enabled 1 from config service
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter enable_hw_decoder : 
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter hardware_decoding : -1
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for enable_video_freeze_diagnose : true
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for retrans_detect_enable : false
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for use_sent_ts_enable : true
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter enable_minor_stream_intra_request : 0
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for switch_soft_decoder_threshold
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for enable_parser_reject
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for enable_hw_decoder
[03/08/23 09:58:31:898][5905011][I]:[VSM]: TDS value found for dec_mosreport : 1
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for che.hardware_decoding
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for tds_retrans_detect_enable
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for tds_use_sent_ts_enable
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for packet_buffer_size : 2048
[03/08/23 09:58:31:898][5905011][I]:[VSM]: no TDS value found for packet_buffer_size
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for enable_vpr : true
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.init_size : 1
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.max_size : 3
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.frozen_ms_thres : 200
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.frozen_rate_thres : 5
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.method : 0
[03/08/23 09:58:31:898][5905011][I]:[VSM]: user parameter value found for che.video.vpr.vpr_adaptive_thres : 50
[03/08/23 09:58:31:899][5905011][I]:on set parameters doc='{"che.audio.mute_peers":false}', ret=0
[03/08/23 09:58:31:908][5905011][I]:[ds]: ver 5 ds '{"streamType":5,"clientRole":2}'
[03/08/23 09:58:31:908][5905011][I]:[vos-ctrl] ch0 sync (cid:235611563, uid:996032720, sync:5): 192.******.134:4058
[03/08/23 09:58:31:952][5905012][A]:(00000282): ChannelProxy::onAudioSubscribeStateChanged->onAudioSubscribeStateChanged(this:0x15d23b050, channel:s21663534667550, userId:-1697971134, oldState:2, newState:3, elapseSinceLastState:54)
[03/08/23 09:58:31:952][5905011][I]:[PEER] onTracerFirstRemoteAudio uid 2596996162 codec 122 lapse 20199
[03/08/23 09:58:31:953][5905011][W]:[ASM]: audio downlink resend 1
[03/08/23 09:58:31:953][5905011][A]:(00000283): RemoteAudioTrackImpl::setRemoteAudioTrackStatisticsHelper(this:0x159222810, helper: 0x282ad3ea0)
[03/08/23 09:58:31:953][5905011][A]:(00000284): RemoteAudioTrackImpl::attach(this:0x159222810, local_ssrc: 996032720, remote_ssrc: 2692569072, codec: 122)
[03/08/23 09:58:31:953][5905011][I]:[RAT]: Start building remote audio track,local_ssrc:0, remote_ssrc:-1602398224, codec:122, sync_group:agora_avsync_2596996162
[03/08/23 09:58:31:953][5905011][I]:audio options factoryname ==default: vector===6
[03/08/23 09:58:31:953][5905011][I]:[AOE]: set adm input params, audioSource: 0, inputSampleRate: 0, inputChannels: 1, enableEstimatedDeviceDelay: 0, enableBuiltin3a: 0
[03/08/23 09:58:31:953][5905011][I]:(audio_device_impl.cc:1171): SetRecordParameters
[03/08/23 09:58:31:953][5905011][W]:(audio_device_generic_worker_wrapper.cc:876): SetRecordParameters(0x16ea626f8)
[03/08/23 09:58:31:953][5905011][I]:(audio_device_impl.cc:1178): output: 0
[03/08/23 09:58:31:953][5905011][I]:[AOF]: Current chatModeIsEnabled: 0
[03/08/23 09:58:31:953][5905011][W]:[AOF]: enable preferred aec delay: 1
[03/08/23 09:58:31:953][5905011][I]:[AOF]: enable_aec: 0, enable_agc: 0, enable_ns: 0, enable_md: 0
[03/08/23 09:58:31:953][5905011][I]:[AOF]: mic selection: 0
[03/08/23 09:58:31:953][5905011][I]:(audio_transport_impl.cc:337): EnableMicSelection enable = 0.
[03/08/23 09:58:31:953][5905011][W]:(neteq_impl.cc:152): NetEq config: sample_rate_hz=16000, enable_post_decode_vad=true, max_packets_in_buffer=200, max_delay_ms=2000, enable_fast_accelerate=false, enable_muted_state=true, enable_rtx_handling=false, target_level_optimization=false, aqm_voice_threshold=10, max_target_delay_ms=0, limit_probability=95, lower_limit_probability=97, filter_target_loss=6, max_filter_window=0, enable_expired_peak_dector=0, max_exceed_time_ms=500, max_filter_dup_num=3, neteq_version=M78, enable_voice_volume_level=0, enable_individuality_delay=0, enable_improve_burst=0, prebuffer=0, prebuffer_max_delay=0, plc_mode=0
[03/08/23 09:58:31:953][5905011][I]:(delay_manager.cc:723): target_delay_ms 0
[03/08/23 09:58:31:953][5905011][W]:(delay_manager.cc:734): limit_probability 95
[03/08/23 09:58:31:953][5905011][W]:(delay_manager.cc:745): lower_limit_probability 97
[03/08/23 09:58:31:953][5905011][I]:(delay_manager.cc:839):  enable_improve_burst:0 low_latency_burst_control_window_ms:90000 low_latency_burst_control_platform_ms:60000 low_latency_burst_peak_num_threshold:2 low_latency_burst_trend_threshold:0.003 low_latency_burst_peak_trend_increased_threshold:0.002 low_latency_burst_overuse_limited_quantile:0.98 low_latency_burst_comb_window_second:300 low_latency_burst_max_jitter_limit_ms:2000 high_latency_burst_control_window_ms:180000 high_latency_burst_control_platform_ms:120000 high_latency_burst_peak_num_threshold:2 high_latency_burst_trend_threshold:0.003 high_latency_burst_peak_trend_increased_threshold:0.002 high_latency_burst_overuse_limited_quantile:0.98 high_latency_burst_comb_window_second:360 high_latency_burst_max_jitter_limit_ms:2000
[03/08/23 09:58:31:953][5905011][I]:(audio_coding_module.cc:478): Created
[03/08/23 09:58:31:953][5905011][I]:(audio_receive_stream.cc:132): AudioReceiveStream: 2692569072
[03/08/23 09:58:31:953][5905011][I]:(audio_receive_stream.cc:440): AudioReceiveStream::ConfigureStream: {rtp: {remote_ssrc: 2692569072, local_ssrc: 0, transport_cc: off, nack: {rtp_history_ms: 0}, extensions: []}, rtcp_send_transport: (Transport), sync_group: agora_avsync_2596996162}
[03/08/23 09:58:31:953][5905011][I]:(call.cc:1360): UpdateAggregateNetworkState: aggregate_state=up
[03/08/23 09:58:31:953][5905011][I]:(send_side_congestion_controller.cc:581): SignalNetworkState Up
[03/08/23 09:58:31:953][5905011][I]:[RAT]: receive stream 0x159224730 has been created, ssrc -1602398224, uid 2596996162, processor 0x282d25198
[03/08/23 09:58:31:953][5905053][I]:(paced_sender.cc:132): PacedSender resumed.
[03/08/23 09:58:31:953][5905011][I]:[AFC]: create extension audio filters, extensionTypeSet size:1
[03/08/23 09:58:31:953][5905053][I]:(send_side_congestion_controller.cc:335): Bitrate estimate state changed, BWE: 196599 bps.
[03/08/23 09:58:31:953][5905011][I]:[AFC]: create extension audio filter, extension type:10002 extension_list size:2
[03/08/23 09:58:31:953][5905011][I]:[AFC]: create extension audio filter, extension type:10002 internal_id:agora.builtin%%sound_position_io_agora_builtin_remote_user_playback filter:sound_position_io_agora_builtin_remote_user_playback auto_enable:0
[03/08/23 09:58:31:953][5905011][I]:[RAT]: to be added audio filter position:2, filter:sound_position_io_agora_builtin_remote_user_playback
[03/08/23 09:58:31:953][5905011][A]:(00000285):   IAudioFilterComposite::addAudioFilter(this:0x283cbd170, filter: 0x2800974e0)
[03/08/23 09:58:31:953][5905011][A]:(00000286):   RemoteAudioTrackImpl::addAudioFilter(this:0x159222810, filter: 0x2800974e0, position: 2)
[03/08/23 09:58:31:954][5905011][I]:[Extension]: SpatialAudioProvider::createAudioFilter will create filter:spatial_audio_io_agora_remote_user_playback
[03/08/23 09:58:31:954][5905011][I]:[AFC]: create extension audio filter, extension type:10002 internal_id:agora_audio_filters_spatial_audio%%spatial_audio_io_agora_remote_user_playback filter:spatial_audio_io_agora_remote_user_playback auto_enable:0
[03/08/23 09:58:31:954][5905011][I]:[RAT]: to be added audio filter position:2, filter:spatial_audio_io_agora_remote_user_playback
[03/08/23 09:58:31:954][5905011][A]:(00000287):   IAudioFilterComposite::addAudioFilter(this:0x283cbd170, filter: 0x280096fa0)
[03/08/23 09:58:31:954][5905011][A]:(00000288):   RemoteAudioTrackImpl::addAudioFilter(this:0x159222810, filter: 0x280096fa0, position: 2)
[03/08/23 09:58:31:954][5905011][I]:[audio] RemoteAudioTrackImpl::attach: remote track attached

[03/08/23 09:58:31:954][5905011][I]:[ASM]: of uid -1697971134 ssrc 2692569072 track 0x159222810 is created by local user.
[03/08/23 09:58:31:954][5905011][A]:(00000289): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:31:954][5905011][A]:(00000290):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:31:954][5905011][I]:[ASM]: configAudioMixerIfNeeded: 3, 3
[03/08/23 09:58:31:954][5905011][I]:audio options factoryname ==default: vector===6
[03/08/23 09:58:31:954][5905011][I]:[AOE]: set adm input params, audioSource: -2131416063, inputSampleRate: 1600, inputChannels: 1, enableEstimatedDeviceDelay: 1, enableBuiltin3a: 110
[03/08/23 09:58:31:954][5905011][I]:(audio_device_impl.cc:1171): SetRecordParameters
[03/08/23 09:58:31:954][5905011][W]:(audio_device_generic_worker_wrapper.cc:876): SetRecordParameters(0x16ea62638)
[03/08/23 09:58:31:954][5905011][I]:(audio_device_impl.cc:1178): output: 0
[03/08/23 09:58:31:954][5905011][I]:[AOF]: Current chatModeIsEnabled: 0
[03/08/23 09:58:31:954][5905011][W]:[AOF]: enable preferred aec delay: 1
[03/08/23 09:58:31:954][5905011][I]:[AOF]: enable_aec: 0, enable_agc: 0, enable_ns: 0, enable_md: 0
[03/08/23 09:58:31:954][5905011][I]:[AOF]: mic selection: 0
[03/08/23 09:58:31:954][5905011][I]:(audio_transport_impl.cc:337): EnableMicSelection enable = 0.
[03/08/23 09:58:31:954][5905011][A]:(00000291): AudioStreamManager::createAndAttachRemoteAudioTrack->onUserAudioTrackSubscribed(this:0x15cde9200, userId:"2596996162", track:0x159222810)
[03/08/23 09:58:31:954][5905011][I]:(audio_decoder_opus.cc:118): AudioDecoderOpus config.sample_rate 48000, config.num_channels 2, config.hw_accelerate_enabled 0
[03/08/23 09:58:32:037][5905011][A]:(00000292): AudioStreamManager::PollTrackInfoAndNotify->onUserAudioTrackStateChanged(this:0x15cde9200, userId:2596996162, track:0x159222810, state:1, reason:4, elapsed:20200)
[03/08/23 09:58:32:037][5905012][A]:(00000293): ChannelProxy::onUserAudioTrackStateChanged->onRemoteAudioStateChanged(this:0x15d23b050, userId:"2596996162", state:1, reason:4, elapsed:20200)
[03/08/23 09:58:32:053][5905011][I]:(delay_manager.cc:695): value:10 from external:1
[03/08/23 09:58:32:153][5905011][I]:(delay_manager.cc:695): value:20 from external:1
[03/08/23 09:58:32:252][5905011][I]:(delay_manager.cc:695): value:30 from external:1
[03/08/23 09:58:32:352][5905011][I]:(delay_manager.cc:695): value:40 from external:1
[03/08/23 09:58:32:437][5905011][A]:(00000294): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:32:437][5905011][A]:(00000295):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:32:437][5905011][A]:(00000296): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:32:437][5905011][A]:(00000297):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:32:437][5905011][I]:[tactics] rtt:33 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:32:452][5905011][I]:(delay_manager.cc:695): value:50 from external:1
[03/08/23 09:58:32:552][5905011][I]:(delay_manager.cc:695): value:60 from external:1
[03/08/23 09:58:32:653][5905011][I]:(delay_manager.cc:695): value:70 from external:1
[03/08/23 09:58:32:752][5905011][I]:(delay_manager.cc:695): value:80 from external:1
[03/08/23 09:58:32:853][5905011][I]:(delay_manager.cc:695): value:90 from external:1
[03/08/23 09:58:32:954][5905011][I]:(delay_manager.cc:695): value:100 from external:1
[03/08/23 09:58:32:984][5905029][W]:(audio_device_ios.mm:694): [adm] OnValidRouteChange: Ignoring sample rate change since audio parameters are intact
[03/08/23 09:58:32:985][5905029][I]:(audio_device_ios.mm:659): [adm] OnValidRouteChange: 
[03/08/23 09:58:33:004][5903653][I]:(RTEAudioSession.mm:596): [adm]-[RTEAudioSession handleRouteChangeNotification:] CategoryChange to AVAudioSessionCategoryPlayAndRecord
[03/08/23 09:58:33:004][5903653][I]:(RTEAudioSession.mm:596): [adm]-[RTEAudioSession handleRouteChangeNotification:] CategoryChange to AVAudioSessionCategoryPlayAndRecord
[03/08/23 09:58:33:011][5905029][W]:(audio_device_ios.mm:694): [adm] OnValidRouteChange: Ignoring sample rate change since audio parameters are intact
[03/08/23 09:58:33:011][5905029][I]:(audio_device_ios.mm:711): [adm] OnChangedOutputVolume: 
[03/08/23 09:58:33:011][5905029][I]:(audio_device_ios.mm:711): [adm] OnChangedOutputVolume: 
[03/08/23 09:58:33:011][5905029][I]:(audio_device_ios.mm:659): [adm] OnValidRouteChange: 
[03/08/23 09:58:33:019][5905029][W]:(audio_device_ios.mm:694): [adm] OnValidRouteChange: Ignoring sample rate change since audio parameters are intact
[03/08/23 09:58:33:020][5905029][I]:(audio_device_ios.mm:659): [adm] OnValidRouteChange: 
[03/08/23 09:58:33:026][5905029][W]:(audio_device_ios.mm:694): [adm] OnValidRouteChange: Ignoring sample rate change since audio parameters are intact
[03/08/23 09:58:33:052][5905011][I]:(delay_manager.cc:695): value:110 from external:1
[03/08/23 09:58:33:152][5905011][I]:(delay_manager.cc:695): value:120 from external:1
[03/08/23 09:58:33:253][5905011][I]:(delay_manager.cc:695): value:130 from external:1
[03/08/23 09:58:33:352][5905011][I]:(delay_manager.cc:695): value:140 from external:1
[03/08/23 09:58:33:453][5905011][I]:(delay_manager.cc:695): value:150 from external:1
[03/08/23 09:58:33:552][5905011][I]:(delay_manager.cc:695): value:160 from external:1
[03/08/23 09:58:33:652][5905011][I]:(delay_manager.cc:695): value:170 from external:1
[03/08/23 09:58:33:753][5905011][I]:(delay_manager.cc:695): value:180 from external:1
[03/08/23 09:58:33:853][5905011][I]:(delay_manager.cc:695): value:190 from external:1
[03/08/23 09:58:33:952][5905011][I]:(delay_manager.cc:695): value:200 from external:1
[03/08/23 09:58:34:052][5905011][I]:(delay_manager.cc:695): value:210 from external:1
[03/08/23 09:58:34:153][5905011][I]:(delay_manager.cc:695): value:220 from external:1
[03/08/23 09:58:34:252][5905011][I]:(delay_manager.cc:695): value:230 from external:1
[03/08/23 09:58:34:353][5905011][I]:(delay_manager.cc:695): value:240 from external:1
[03/08/23 09:58:34:437][5905011][A]:(00000298): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:34:437][5905011][A]:(00000299):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:34:437][5905011][A]:(00000300): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:34:437][5905011][A]:(00000301):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:34:437][5905011][I]:[tactics] rtt:33 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:34:452][5905011][I]:(delay_manager.cc:695): value:250 from external:1
[03/08/23 09:58:34:552][5905011][I]:(delay_manager.cc:695): value:260 from external:1
[03/08/23 09:58:34:653][5905011][I]:(delay_manager.cc:695): value:270 from external:1
[03/08/23 09:58:34:753][5905011][I]:(delay_manager.cc:695): value:280 from external:1
[03/08/23 09:58:34:853][5905011][I]:(delay_manager.cc:695): value:290 from external:1
[03/08/23 09:58:34:953][5905011][I]:(delay_manager.cc:695): value:300 from external:1
[03/08/23 09:58:35:052][5905011][I]:(delay_manager.cc:695): value:310 from external:1
[03/08/23 09:58:35:152][5905011][I]:(delay_manager.cc:695): value:320 from external:1
[03/08/23 09:58:35:226][5905029][E]:(audio_device_ios.mm:1299): [adm] AudioDeviceMalfunctionCheck: invalid cur_num_playout_callbacks_ 0
[03/08/23 09:58:35:226][5905029][W]:(audio_device_ios.mm:572): [adm] IncMalfunctionCounter: 
[03/08/23 09:58:35:252][5905011][I]:(delay_manager.cc:695): value:330 from external:1
[03/08/23 09:58:35:353][5905011][I]:(delay_manager.cc:695): value:340 from external:1
[03/08/23 09:58:35:453][5905011][I]:(delay_manager.cc:695): value:350 from external:1
[03/08/23 09:58:35:552][5905011][I]:(delay_manager.cc:695): value:360 from external:1
[03/08/23 09:58:35:652][5905011][I]:(delay_manager.cc:695): value:370 from external:1
[03/08/23 09:58:35:752][5905011][I]:(delay_manager.cc:695): value:380 from external:1
[03/08/23 09:58:35:853][5905011][I]:(delay_manager.cc:695): value:390 from external:1
[03/08/23 09:58:35:953][5905011][W]:(packet_buffer.cc:115): Packet buffer flushed
[03/08/23 09:58:35:953][5905011][I]:(delay_manager.cc:695): value:400 from external:1
[03/08/23 09:58:36:052][5905011][I]:(delay_manager.cc:695): value:410 from external:1
[03/08/23 09:58:36:153][5905011][I]:(delay_manager.cc:695): value:420 from external:1
[03/08/23 09:58:36:252][5905011][I]:(delay_manager.cc:695): value:430 from external:1
[03/08/23 09:58:36:353][5905011][I]:(delay_manager.cc:695): value:440 from external:1
[03/08/23 09:58:36:437][5905011][A]:(00000302): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:36:437][5905011][A]:(00000303):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:36:437][5905011][A]:(00000304): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:36:437][5905011][A]:(00000305):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:36:437][5905011][I]:[tactics] rtt:33 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:36:453][5905011][I]:(delay_manager.cc:695): value:450 from external:1
[03/08/23 09:58:36:552][5905011][I]:(delay_manager.cc:695): value:460 from external:1
[03/08/23 09:58:36:653][5905011][I]:(delay_manager.cc:695): value:470 from external:1
[03/08/23 09:58:36:753][5905011][I]:(delay_manager.cc:695): value:480 from external:1
[03/08/23 09:58:36:852][5905011][I]:(delay_manager.cc:695): value:490 from external:1
[03/08/23 09:58:36:898][5905011][I]:[xla] first remote audio frame timeout 25144, uid:2596996162, first:0, valid:1
[03/08/23 09:58:36:952][5905011][I]:(delay_manager.cc:695): value:500 from external:1
[03/08/23 09:58:38:437][5905011][A]:(00000306): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:38:437][5905011][A]:(00000307):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:38:437][5905011][A]:(00000308): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:38:437][5905011][A]:(00000309):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:38:437][5905011][I]:[tactics] rtt:32 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:39:070][5905011][I]:[CONN-0]on bill stats upstream width 0 height 0 local flag 1
[03/08/23 09:58:39:226][5905029][E]:(audio_device_ios.mm:1299): [adm] AudioDeviceMalfunctionCheck: invalid cur_num_playout_callbacks_ 0
[03/08/23 09:58:39:226][5905029][W]:(audio_device_ios.mm:572): [adm] IncMalfunctionCounter: 
[03/08/23 09:58:39:953][5905011][W]:(packet_buffer.cc:115): Packet buffer flushed
[03/08/23 09:58:40:436][5905011][A]:(00000310): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:40:436][5905011][A]:(00000311):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:40:436][5905011][A]:(00000312): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:40:436][5905011][A]:(00000313):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:40:436][5905011][I]:[tactics] rtt:33 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:42:437][5905011][A]:(00000314): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:42:437][5905011][A]:(00000315):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: spatial_audio_io_agora_remote_user_playback)
[03/08/23 09:58:42:437][5905011][A]:(00000316): RemoteAudioTrackImpl::getAudioFilter(this:0x159222810, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:42:437][5905011][A]:(00000317):   IAudioFilterComposite::getAudioFilter(this:0x283cbd170, name: sound_position_io_agora_builtin_remote_user_playback)
[03/08/23 09:58:42:437][5905011][I]:[tactics] rtt:33 lost frame rate:0 continus lost:0 jitter:0
[03/08/23 09:58:43:226][5905029][E]:(audio_device_ios.mm:1299): [adm] AudioDeviceMalfunctionCheck: invalid cur_num_playout_callbacks_ 0
[03/08/23 09:58:43:226][5905029][W]:(audio_device_ios.mm:572): [adm] IncMalfunctionCounter: 
[03/08/23 09:58:43:230][5905029][W]:(audio_device_ios.mm:1466): [adm] RestartADMIfNeeded: audio device restart! record_needed_ 0
[03/08/23 09:58:43:230][5905029][I]:(audio_device_ios.mm:366): [adm] StopPlayout: 
[03/08/23 09:58:43:230][5905029][I]:(audio_device_ios.mm:1216): [adm] ShutdownPlayOrRecord: 
[03/08/23 09:58:43:230][5905011][A]:(00000318): AudioDeviceEventManager::CallbackOnWarning->CallbackOnWarning(this:0x281b23940, warnCode: 1028)
[03/08/23 09:58:43:230][5905011][I]:[ASM]: CallbackOnWarning warnCode 1028
[03/08/23 09:58:43:231][5905029][I]:(voice_processing_audio_unit.mm:334): [adm][0x280f759a0] Stop: audio unit stopped
[03/08/23 09:58:43:231][5905029][I]:(voice_processing_audio_unit.mm:349): [adm][0x280f759a0] Uninitialize: audio unit started uninitialized
[03/08/23 09:58:43:231][5905029][I]:(voice_processing_audio_unit.mm:57): [adm][0x280f759a0] ~VoiceProcessingAudioUnit: 
[03/08/23 09:58:43:231][5905029][I]:(voice_processing_audio_unit.mm:458): [adm][0x280f759a0] DisposeAudioUnit: 
[03/08/23 09:58:43:232][5905029][I]:(RTEAudioSession.mm:219): [adm]-[RTEAudioSession removeDelegate:] delegate 0x280ea5380
[03/08/23 09:58:43:232][5905029][I]:(audio_device_ios.mm:1180): [adm] UnconfigureAudioSession: 
[03/08/23 09:58:43:232][5905029][W]:(RTEAudioSession.mm:854): [adm]-[RTEAudioSession unconfigureWebRTCSession:] keepAudioSession 1
[03/08/23 09:58:43:232][5905029][I]:(audio_device_ios.mm:286): [adm] InitPlayout: needRecord 0
[03/08/23 09:58:43:232][5905011][I]:audio_processing_impl.cc:2307 - reset_apm_capture_state(0x15C4B8000)
[03/08/23 09:58:43:232][5905029][I]:(audio_device_ios.mm:1194): [adm] InitPlayOrRecord: enable_record 0, playing_ 0, recording_ 0
[03/08/23 09:58:43:232][5905029][I]:(audio_device_ios.mm:1124): [adm] InitAudioConfig: RTEAudioSession isInterrupted 0, isActive 1, isMediaServicesWereLost 0
[03/08/23 09:58:43:233][5905029][I]:(audio_device_ios.mm:1161): [adm] ConfigureAudioSession: configure begin
@ChrisMICDUP
Copy link
Author

I have replaced the muteAllRemoteAudioStreams calls with enableAudio and disableAudio which works for my use case. It would be good to know however if the mute methods hang onto a audio session after completion.

@littleGnAl
Copy link
Collaborator

I think it's better to raise a ticket to Agora Support for further investigation of this issue.

@littleGnAl littleGnAl added the waiting for customer response waiting for customer response, or closed by no-reponse bot label Mar 15, 2023
@ChrisMICDUP
Copy link
Author

Thanks, I'll leave it for now - it's quite probably only relevant to my complex sound usage in my app

@github-actions github-actions bot removed the waiting for customer response waiting for customer response, or closed by no-reponse bot label Mar 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@littleGnAl @ChrisMICDUP