Audio not being played on Android

[filbabic]

Hello there!

I've been using your lib for WebRTC and I have one major issue which I'm not sure if it's an implementation issue or on the library side.

Audio is not playing on Android, but sending audio from Android to other sides (Web or iOS), works fine and it plays fine. I'm not sure if there are any specific settings or things I need to do to play audio - I've enabled all audio tracks that arrive through addTrack/addStream, I've set up the AudioManager to use the speakerphone and enable IN_COMMUNICATION mode.

I've also made sure that the selected device is the speakerphone whenever a track is added.

I've enabled the JavaAudioModule and added callbacks and from what I can figure out I think the tracks are never started.

Could you let me know what step I'm missing to enable audio? It woud be very much appreciated!

Thanks!

[filbabic]

@davidliu Any support on this? Could you give me an idea of what the flow for connecting Audio is and if there's anything I might be missing?

[davidliu]

@filbabic Hmm, the JavaAudioDeviceModule handles everything by itself. No action is needed at all to start playback; audio is automatically played through the current audio output whenever a track is received.

If the tracks are never started, there's likely some other underlying issue at play. Add all the callbacks and see if there are any errors emitted from the AudioTrackErrorCallback. You might also want to add a logger to PeerConnectionFactory.initialize function like so:

PeerConnectionFactory.initialize(
            PeerConnectionFactory.InitializationOptions
                .builder(appContext)
                .setInjectableLogger({ message, severity, label ->
                    Log.i("WebRTC", "$label: $message")
                }, Logging.Severity.LS_VERBOSE)
                .createInitializationOptions()
        )

[filbabic]

Hey @davidliu!

Thank you so much - I've added the callbacks to the java audio device module, but there are no triggers or logs for AudioTrackStateCallback or AudioTrackErrorCallback. So it would mean the tracks are not started at all, right?

Do I need to add a special transceiver to playback audio, do I need to add it to a stream or something? Kind of lost and I've tried lots of things, nothing really worked so far.

I/WebRTC: JavaAudioDeviceModule: createAudioDeviceModule
I/WebRTC: audio_device_buffer.cc: (line 65): AudioDeviceBuffer::ctor
I/WebRTC: audio_track_jni.cc: (line 219): AttachAudioBuffer
I/WebRTC: audio_record_jni.cc: (line 191): AttachAudioBuffer
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {aec: 1, agc: 1, ns: 1, hf: 1, swap: 0, audio_jitter_buffer_max_packets: 200, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: peer_connection.cc: (line 1091): Adding audio transceiver in response to a call to AddTransceiver.
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: webrtc_voice_engine.cc: (line 1357): WebRtcVoiceMediaChannel::SetRecvParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[63:red:48000:0:2], AudioCodec[103:ISAC:16000:0:1], AudioCodec[104:ISAC:32000:0:1], AudioCodec[9:G722:8000:0:1], AudioCodec[102:ILBC:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1], AudioCodec[106:CN:32000:0:1], AudioCodec[105:CN:16000:0:1], AudioCodec[13:CN:8000:0:1], AudioCodec[110:telephone-event:48000:0:1], AudioCodec[112:telephone-event:32000:0:1], AudioCodec[113:telephone-event:16000:0:1], AudioCodec[126:telephone-event:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 2}, {uri: urn:ietf:params:rtp-hdrext:sdes:mid, id: 4}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}]}
I/WebRTC: audio_send_stream.cc: (line 166): AudioSendStream: 432440244
I/WebRTC: audio_send_stream.cc: (line 234): AudioSendStream::ConfigureStream: {rtp: {ssrc: 432440244, extmap-allow-mixed: true, extensions: [], c_name: 9hGWBTEBflH1TwaP}, rtcp_report_interval_ms: 5000, send_transport: (Transport), min_bitrate_bps: -1, max_bitrate_bps: -1, has audio_network_adaptor_config: false, has_dscp: false, send_codec_spec: <unset>}
I/WebRTC: channel.cc: (line 679): Add send stream ssrc: 432440244 into {mid: 0, media_type: audio}
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 0, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_send_stream.cc: (line 234): AudioSendStream::ConfigureStream: {rtp: {ssrc: 432440244, extmap-allow-mixed: true, extensions: [], c_name: 9hGWBTEBflH1TwaP}, rtcp_report_interval_ms: 5000, send_transport: (Transport), min_bitrate_bps: 32000, max_bitrate_bps: 500000, has audio_network_adaptor_config: false, has_dscp: false, send_codec_spec: <unset>}
I/WebRTC: channel.cc: (line 520): Channel enabled: {mid: 0, media_type: audio}
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 0, media_type: audio}
I/WebRTC: channel.cc: (line 920): Setting remote voice description for {mid: 0, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1311): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[9:G722:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], extmap-allow-mixed: true, max_bandwidth_bps: -1, mid: 0, options: AudioOptions {}}
I/WebRTC: audio_send_stream.cc: (line 234): AudioSendStream::ConfigureStream: {rtp: {ssrc: 432440244, extmap-allow-mixed: true, extensions: [], c_name: 9hGWBTEBflH1TwaP}, rtcp_report_interval_ms: 5000, send_transport: (Transport), min_bitrate_bps: 500000, max_bitrate_bps: 500000, has audio_network_adaptor_config: false, has_dscp: false, send_codec_spec: {nack_enabled: false, transport_cc_enabled: true, enable_non_sender_rtt: false, cng_payload_type: <unset>, red_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {minptime: 10, useinbandfec: 1}}}}
I/WebRTC: audio_send_stream.cc: (line 234): AudioSendStream::ConfigureStream: {rtp: {ssrc: 432440244, extmap-allow-mixed: true, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], c_name: 9hGWBTEBflH1TwaP}, rtcp_report_interval_ms: 5000, send_transport: (Transport), min_bitrate_bps: 500000, max_bitrate_bps: 500000, has audio_network_adaptor_config: false, has_dscp: false, send_codec_spec: {nack_enabled: false, transport_cc_enabled: true, enable_non_sender_rtt: false, cng_payload_type: <unset>, red_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {minptime: 10, useinbandfec: 1}}}}
I/WebRTC: audio_send_stream.cc: (line 234): AudioSendStream::ConfigureStream: {rtp: {ssrc: 432440244, mid: 0, extmap-allow-mixed: true, extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], c_name: 9hGWBTEBflH1TwaP}, rtcp_report_interval_ms: 5000, send_transport: (Transport), min_bitrate_bps: 500000, max_bitrate_bps: 500000, has audio_network_adaptor_config: false, has_dscp: false, send_codec_spec: {nack_enabled: false, transport_cc_enabled: true, enable_non_sender_rtt: false, cng_payload_type: <unset>, red_payload_type: <unset>, payload_type: 111, format: {name: opus, clockrate_hz: 48000, num_channels: 2, parameters: {minptime: 10, useinbandfec: 1}}}}
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 0, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1357): WebRtcVoiceMediaChannel::SetRecvParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[63:red:48000:0:2], AudioCodec[103:ISAC:16000:0:1], AudioCodec[104:ISAC:32000:0:1], AudioCodec[9:G722:8000:0:1], AudioCodec[102:ILBC:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1], AudioCodec[106:CN:32000:0:1], AudioCodec[105:CN:16000:0:1], AudioCodec[13:CN:8000:0:1], AudioCodec[110:telephone-event:48000:0:1], AudioCodec[112:telephone-event:32000:0:1], AudioCodec[113:telephone-event:16000:0:1], AudioCodec[126:telephone-event:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time, id: 2}, {uri: urn:ietf:params:rtp-hdrext:sdes:mid, id: 4}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}]}
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 0, media_type: audio}
I/WebRTC: channel.cc: (line 334): Network route changed for {mid: 0, media_type: audio}
I/WebRTC: channel.cc: (line 550): Channel writable ({mid: 0, media_type: audio}) for the first time
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: delay_based_bwe.cc: (line 88): Initialized DelayBasedBwe with separate audio overuse detectionenabled:false,packet_threshold:10,time_threshold:1 s and alr limited backoff disabled
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: WebRtcAudioRecordExternal: AudioRecord.getMinBufferSize: 3840
I/WebRTC: WebRtcAudioRecordExternal: createAudioRecordOnMOrHigher
I/WebRTC: WebRtcAudioEffectsExternal: enable(audioSession=4511833)
I/WebRTC: WebRtcAudioRecordExternal: AudioRecord: session ID: 4511833, channels: 1, sample rate: 48000
I/WebRTC: WebRtcAudioRecordExternal: AudioRecord: buffer size in frames: 3840
I/WebRTC: audio_record_jni.cc: (line 40): WebRTC.Audio.InitRecordingDurationMs: 27
I/WebRTC: WebRtcAudioRecordExternal: AudioRecordThread@[name=AudioRecordJavaThread, id=1613]
I/WebRTC: WebRtcAudioRecordExternal: doAudioRecordStateCallback: START
I/WebRTC: audio_record_jni.cc: (line 40): WebRTC.Audio.StartRecordingDurationMs: 9
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=1 for {mid: 0, media_type: audio}
I/WebRTC: WebRtcAudioRecordExternal: AudioRecordingConfigurations: 
I/WebRTC: WebRtcAudioRecordExternal:   client audio source=VOICE_COMMUNICATION, client session id=4511833 (4511833)
      Device AudioFormat: channel count=1, channel index mask=0, channel mask=IN_MONO, encoding=PCM_16BIT, sample rate=48000
      Client AudioFormat: channel count=1, channel index mask=0, channel mask=IN_MONO, encoding=PCM_16BIT, sample rate=48000
      AudioDevice: type=TYPE_BUILTIN_MIC, id=20
I/WebRTC: WebRtcAudioRecordExternal: verifyAudioConfig: PASS
I/WebRTC: rtp_sender_audio.cc: (line 313): First audio RTP packet sent to pacer
I/WebRTC: channel.cc: (line 920): Setting remote voice description for {mid: 0, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1311): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[9:G722:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 3}, {uri: urn:ietf:params:rtp-hdrext:ssrc-audio-level, id: 1}], extmap-allow-mixed: true, max_bandwidth_bps: -1, mid: 0, options: AudioOptions {}}
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=1 for {mid: 0, media_type: audio}

These are the logs I get when the device module and all is set up.

I/WebRTC: webrtc_sdp.cc: (line 3458): Ignored unknown ssrc-specific attribute: a=ssrc:2367371381 mslabel:thierry:84551021-b931-444e-9737-9f56c13a30ad:audio
I/WebRTC: webrtc_sdp.cc: (line 3458): Ignored unknown ssrc-specific attribute: a=ssrc:2367371381 label:audio
I/WebRTC: sdp_offer_answer.cc: (line 3567): Adding audio transceiver for MID=1 at i=1 in response to the remote description.
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: channel.cc: (line 550): Channel writable ({mid: 1, media_type: audio}) for the first time
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}
I/WebRTC: channel.cc: (line 920): Setting remote voice description for {mid: 1, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1311): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[9:G722:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 1}], extmap-allow-mixed: true, max_bandwidth_bps: -1, mid: 1, options: AudioOptions {}}
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: webrtc_voice_engine.cc: (line 1915): AddRecvStream: {id:audio;ssrcs:[2367371381];ssrc_groups:;cname:thierry:84551021-b931-444e-9737-9f56c13a30ad:audio;stream_ids:thierry:84551021-b931-444e-9737-9f56c13a30ad:audio;}
I/WebRTC: audio_receive_stream.cc: (line 118): AudioReceiveStreamImpl: 2367371381
I/WebRTC: channel.cc: (line 742): Add remote ssrc: 2367371381 to {mid: 1, media_type: audio}
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}
I/WebRTC: delay_based_bwe.cc: (line 88): Initialized DelayBasedBwe with separate audio overuse detectionenabled:false,packet_threshold:10,time_threshold:1 s and alr limited backoff disabled
I/WebRTC: sdp_offer_answer.cc: (line 1977): Processing the MSIDs for MID=1 (streams=[thierry:84551021-b931-444e-9737-9f56c13a30ad:audio]).
I/WebRTC: webrtc_voice_engine.cc: (line 2440): WebRtcVoiceMediaChannel::SetRawAudioSink: ssrc:2367371381 (ptr)
I/WebRTC: sdp_offer_answer.cc: (line 2359): CreateAnswer: offer_to_receive_audio is not supported with Unified Plan semantics. Use the RtpTransceiver API instead.
I/WebRTC: webrtc_sdp.cc: (line 3458): Ignored unknown ssrc-specific attribute: a=ssrc:2367371381 mslabel:thierry:84551021-b931-444e-9737-9f56c13a30ad:audio
I/WebRTC: webrtc_sdp.cc: (line 3458): Ignored unknown ssrc-specific attribute: a=ssrc:2367371381 label:audio
I/WebRTC: channel.cc: (line 920): Setting remote voice description for {mid: 1, media_type: audio}
I/WebRTC: webrtc_voice_engine.cc: (line 1311): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[9:G722:8000:0:1], AudioCodec[0:PCMU:8000:0:1], AudioCodec[8:PCMA:8000:0:1]], extensions: [{uri: http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01, id: 1}], extmap-allow-mixed: true, max_bandwidth_bps: -1, mid: 1, options: AudioOptions {}}
I/WebRTC: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
I/WebRTC: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 0, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 0, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
I/WebRTC: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
I/WebRTC: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}
I/WebRTC: sdp_offer_answer.cc: (line 1977): Processing the MSIDs for MID=1 (streams=[thierry:84551021-b931-444e-9737-9f56c13a30ad:audio]).
I/WebRTC: sdp_offer_answer.cc: (line 2359): CreateAnswer: offer_to_receive_audio is not supported with Unified Plan semantics. Use the RtpTransceiver API instead.

These are the logs from the PeerConnectionFactory logger - the only "issue" I see here is the offer_to_receive_audio thing, but that should be fine, since we're using unified plan and the audio tracks do arrive in addTrack/stream.

So the question is do I have to set anything up from the point of "receiving tracks" to "playing audio"?

Appreciate all the help

[davidliu]

Again, no. There's nothing to do between receiving tracks and playing audio. Audio on Android is basically self-contained and should automatically playout if all the underlying sdp negotiation with offer and answer is done correctly. Reference the example app for implementation details.

There's not really enough logs for me to tell here, but it seems like your underlying receive channel never changes the voice state to recv=1?

Here's an example of logs from a successful playout:

09-23 22:17:57.953 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 3567): Adding audio transceiver for MID=1 at i=1 in response to the remote description.
09-23 22:17:57.953 11650 11968 V RTCModule: webrtc_voice_engine.cc: (line 1288): WebRtcVoiceMediaChannel::WebRtcVoiceMediaChannel
09-23 22:17:57.953 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
09-23 22:17:57.954 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
09-23 22:17:57.955 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 531): NetEq capacity is 50
09-23 22:17:57.955 11650 11967 V RTCModule: p2p_transport_channel.cc: (line 438): Channel[0|1|RW]: Ice not completed yet for this channel as Net[wlan0:192.168.11.x/24:Wifi:id=4] has more than 1 connection.
09-23 22:17:57.955 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 537): NetEq fast mode? 0
09-23 22:17:57.955 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 543): NetEq minimum delay is 0
09-23 22:17:57.955 11650 11968 I RTCModule: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 1, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 1, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
09-23 22:17:57.955 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
09-23 22:17:57.955 11650 11967 V RTCModule: webrtc_voice_engine.cc: (line 2283): OnReadyToSend: Not ready.
09-23 22:17:57.956 11650 11968 V RTCModule: call.cc: (line 1374): UpdateAggregateNetworkState: aggregate_state remains at down
09-23 22:17:57.956 11650 11968 V RTCModule: rtp_transport_controller_send.cc: (line 350): SignalNetworkState Down
09-23 22:17:57.956 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 2693): Session: 1502668119431306840 Old state: stable New state: have-remote-offer
09-23 22:17:57.956 11650 11968 I RTCModule: channel.cc: (line 920): Setting remote voice description for {mid: 1, media_type: audio}
09-23 22:17:57.956 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1311): WebRtcVoiceMediaChannel::SetSendParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[63:red:48000:0:2]], extensions: [], extmap-allow-mixed: true, max_bandwidth_bps: -1, mid: 1, options: AudioOptions {}}
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 2270): WebRtcVoiceMediaChannel::SetMaxSendBitrate.
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1497): Setting voice channel options: AudioOptions {}
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 425): WebRtcVoiceEngine::ApplyOptions: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 531): NetEq capacity is 50
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 537): NetEq fast mode? 0
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 543): NetEq minimum delay is 0
09-23 22:17:57.957 11650 11968 I RTCModule: audio_processing_impl.cc: (line 506): AudioProcessing::ApplyConfig: AudioProcessing::Config{ pipeline: { maximum_internal_processing_rate: 48000, multi_channel_render: 0, multi_channel_capture: 0 }, pre_amplifier: { enabled: 0, fixed_gain_factor: 1 },capture_level_adjustment: { enabled: 0, pre_gain_factor: 1, post_gain_factor: 1, analog_mic_gain_emulation: { enabled: 0, initial_level: 255 }}, high_pass_filter: { enabled: 1 }, echo_canceller: { enabled: 1, mobile_mode: 1, enforce_high_pass_filtering: 1 }, noise_suppression: { enabled: 1, level: High }, transient_suppression: { enabled: 0 }, gain_controller1: { enabled: 1, mode: FixedDigital, target_level_dbfs: 3, compression_gain_db: 9, enable_limiter: 1, analog_gain_controller { enabled: 1, startup_min_volume: 0, clipped_level_min: 70, enable_digital_adaptive: 1, clipped_level_step: 15, clipped_ratio_threshold: 0.1, clipped_wait_frames: 300, clipping_predictor:  { enabled: 0, mode: 0, window_length: 5, reference_window_length: 5, reference_window_delay: 5, clipping_threshold: -1, crest_factor_margin: 3, use_predicted_step: 1 }}}, gain_controller2: { enabled: 0, fixed_digital: { gain_db: 0 }, adaptive_digital: { enabled: 0, dry_run: 0, headroom_db: 6, max_gain_db: 30, initial_gain_db: 8, vad_reset_period_ms: 1500, adjacent_speech_frames_threshold: 12, max_gain_change_db_per_second: 3, max_output_noise_level_dbfs: -50}}
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1515): Set voice channel options. Current options: AudioOptions {audio_jitter_buffer_max_packets: 50, audio_jitter_buffer_fast_accelerate: 0, audio_jitter_buffer_min_delay_ms: 0, }
09-23 22:17:57.957 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1915): AddRecvStream: {id:TR_AMBcFTwbJBen7d;ssrcs:[713306349];ssrc_groups:;cname:PA_icJRke3hA5SV|TR_AMBcFTwbJBen7d;stream_ids:PA_icJRke3hA5SV|TR_AMBcFTwbJBen7d;}
09-23 22:17:57.957 11650 11968 I RTCModule: delay_manager.cc: (line 62): Delay manager config: quantile=0.95 forget_factor=0.983 start_forget_weight=2 resample_interval_ms=500 use_reorder_optimizer=1 reorder_forget_factor=0.9993 ms_per_loss_percent=20
09-23 22:17:57.957 11650 11968 I RTCModule: decision_logic.cc: (line 78): NetEq decision logic config: enable_stable_playout_delay=0 reinit_after_expands=100 packet_history_size_ms=2000 deceleration_target_level_offset_ms=85
09-23 22:17:57.958 11650 11968 I RTCModule: neteq_impl.cc: (line 139): NetEq config: sample_rate_hz=16000, enable_post_decode_vad=true, max_packets_in_buffer=50, min_delay_ms=0, enable_fast_accelerate=false, enable_muted_state=true, enable_rtx_handling=false
09-23 22:17:57.958 11650 11968 V RTCModule: neteq_impl.cc: (line 2058): SetSampleRateAndChannels 16000 1
09-23 22:17:57.958 11650 11968 V RTCModule: neteq_impl.cc: (line 443): FlushBuffers
09-23 22:17:57.958 11650 11968 I RTCModule: audio_receive_stream.cc: (line 118): AudioReceiveStreamImpl: 713306349
09-23 22:17:57.958 11650 11968 V RTCModule: call.cc: (line 1374): UpdateAggregateNetworkState: aggregate_state remains at down
09-23 22:17:57.958 11650 11968 V RTCModule: rtp_transport_controller_send.cc: (line 350): SignalNetworkState Down
09-23 22:17:57.958 11650 11968 I RTCModule: channel.cc: (line 742): Add remote ssrc: 713306349 to {mid: 1, media_type: audio}
09-23 22:17:57.958 11650 11968 I RTCModule: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}
09-23 22:17:57.958 11650 11967 I RTCModule: dcsctp_transport.cc: (line 169): DcSctpTransport6->Start(local=5000, remote=5000, max_message_size=65536)
09-23 22:17:57.963 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 1977): Processing the MSIDs for MID=1 (streams=[PA_icJRke3hA5SV|TR_AMBcFTwbJBen7d]).
09-23 22:17:57.963 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 1987): Processing the addition of a remote track for MID=1.
09-23 22:17:57.963 11650 11968 V RTCModule: webrtc_voice_engine.cc: (line 2440): WebRtcVoiceMediaChannel::SetRawAudioSink: ssrc:713306349 (ptr)
09-23 22:17:57.963 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 2074): SetBaseMinimumPlayoutDelayMs() to 0 for recv stream with ssrc 713306349
09-23 22:17:57.963 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 2025): WRVMC::SetOutputVolume({ssrc=713306349}, {volume=1.00})
09-23 22:17:57.964 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 2035): WRVMC::SetOutputVolume => (stream with SSRC 713306349 now uses volume 1.00)
09-23 22:17:57.964 11650 11969 V SubscriberTransportObserver: peerconn started receiving audio
09-23 22:17:57.964 11650 11969 V SubscriberTransportObserver: onAddTrack: audio, TR_AMBcFTwbJBen7d, , [PA_icJRke3hA5SV|TR_AMBcFTwbJBen7d:A=1:V=0]
09-23 22:17:57.969 11650 11967 I RTCModule: dtls_srtp_transport.cc: (line 64): Setting RTCP Transport on 0 transport 0
09-23 22:17:57.969 11650 11967 I RTCModule: dtls_srtp_transport.cc: (line 69): Setting RTP Transport on 0 transport 62187e00
09-23 22:17:57.969 11650 11967 I RTCModule: p2p_transport_channel.cc: (line 488): Set ICE ufrag: lXA6 pwd: h/1GRhD+R3g01akQlBUZf/+k on transport 0
09-23 22:17:57.969 11650 11967 I RTCModule: dtls_transport.cc: (line 239): DtlsTransport[0|1|__]: Ignoring identical remote DTLS fingerprint
09-23 22:17:57.970 11650 11969 I RTCModule: rtp_transceiver.cc: (line 452): Changing transceiver (MID=1) current direction from <not set> to kRecvOnly.
09-23 22:17:57.970 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 2693): Session: 1502668119431306840 Old state: have-remote-offer New state: stable
09-23 22:17:57.970 11650 11968 I RTCModule: channel.cc: (line 520): Channel enabled: {mid: 1, media_type: audio}
09-23 22:17:57.970 11650 11968 I RTCModule: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}
09-23 22:17:57.970 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1357): WebRtcVoiceMediaChannel::SetRecvParameters: {codecs: [AudioCodec[111:opus:48000:0:2], AudioCodec[63:red:48000:0:2]], extensions: []}
09-23 22:17:57.970 11650 11968 I RTCModule: webrtc_voice_engine.cc: (line 1525): Setting receive voice codecs.
09-23 22:17:57.970 11650 11968 I RTCModule: audio_track_jni.cc: (line 78): InitPlayout
09-23 22:17:57.971 11650 11968 I RTCModule: WebRtcAudioTrackExternal: initPlayout(sampleRate=48000, channels=1, bufferSizeFactor=1.0)
09-23 22:17:57.971 11650 11968 I RTCModule: WebRtcAudioTrackExternal: byteBuffer.capacity: 960
09-23 22:17:57.971 11650 11968 I RTCModule: audio_track_jni.cc: (line 233): OnCacheDirectBufferAddress
09-23 22:17:57.971 11650 11968 I RTCModule: audio_track_jni.cc: (line 238): direct buffer capacity: 960
09-23 22:17:57.971 11650 11968 I RTCModule: audio_track_jni.cc: (line 242): frames_per_buffer: 480
09-23 22:17:57.972 11650 11968 I RTCModule: WebRtcAudioTrackExternal: minBufferSizeInBytes: 3848
09-23 22:17:57.972 11650 11968 I RTCModule: WebRtcAudioTrackExternal: createAudioTrackBeforeOreo
09-23 22:17:57.972 11650 11968 I RTCModule: WebRtcAudioTrackExternal: nativeOutputSampleRate: 48000
09-23 22:17:57.973   841  2633 D AudioFlinger: Client defaulted notificationFrames to 962 for frameCount 1924
09-23 22:17:57.975 11650 11968 I RTCModule: WebRtcAudioTrackExternal: AudioTrack: session ID: 241, channels: 1, sample rate: 48000, max gain: 1.0
09-23 22:17:57.976 11650 11968 I RTCModule: WebRtcAudioTrackExternal: AudioTrack: buffer size in frames: 1924
09-23 22:17:57.976 11650 11968 I RTCModule: WebRtcAudioTrackExternal: AudioTrack: buffer capacity in frames: 1924
09-23 22:17:57.976 11650 11968 I RTCModule: audio_track_jni.cc: (line 128): StartPlayout
09-23 22:17:57.976 11650 11968 I RTCModule: VolumeLogger: start@[name=worker_thread - 11968, id=1741]
09-23 22:17:57.976 11650 11968 I RTCModule: VolumeLogger: audio mode is: MODE_IN_COMMUNICATION
09-23 22:17:57.977 11650 11968 I RTCModule: WebRtcAudioTrackExternal: startPlayout
09-23 22:17:57.978 11650 11985 I RTCModule: VolumeLogger: VOICE_CALL stream volume: 6 (max=7)
09-23 22:17:57.979   744   744 W AshmemAllocator: ashmem_create_region(7680) returning hidl_memory(0x725122c100, 7680)
09-23 22:17:57.980   744   744 W AshmemAllocator: ashmem_create_region(7680) returning hidl_memory(0x725122c100, 7680)
09-23 22:17:57.981 11650 11968 I RTCModule: channel.cc: (line 852): Changing voice state, recv=1 send=0 for {mid: 1, media_type: audio}

The one thing I'm not seeing in the logs is this particular line:

09-23 22:17:57.970 11650 11969 I RTCModule: sdp_offer_answer.cc: (line 2693): Session: 1502668119431306840 Old state: have-remote-offer New state: stable
09-23 22:17:57.970 11650 11968 I RTCModule: channel.cc: (line 520): Channel enabled: {mid: 1, media_type: audio}
09-23 22:17:57.970 11650 11968 I RTCModule: channel.cc: (line 852): Changing voice state, recv=0 send=0 for {mid: 1, media_type: audio}

Don't know if it's just omitted, but something might be at issue during the sdp negotation.

[davidliu]

Stumbled back onto this issue a couple years later:

sdp_offer_answer.cc: (line 2359): CreateAnswer: offer_to_receive_audio is not supported with Unified Plan semantics. Use the RtpTransceiver API instead.

This was probably the issue, as I think offer_to_receive_audio was a Plan B sdp thing. WebRTC has long since moved onto Unified Plan semantics. Closing as obsolete.