Webrtc plugin for AEC support
be999
brigitte.schuster at electropix.com
Fri Sep 15 16:15:48 UTC 2017
Here is a logical view of the pipeline I am using now:
alsasrc -> audioconvert -> audioresample -> webrtcdsp -> opusenc ->
rtpopuspay -> udpsink
appsrc -> rtpjitterbuffer -> rtpopusdepay -> opusdec -> webrtcprobe ->
audioresample -> audioconvert -> alsasink
The pipeline runs on a RasperryPi with a usb audio device capturing and
rendering at 48KHz.
When I set alsasink property sync=false, I hear audio on the output but
AEC does not work (as mentioned earlier because sync=false)
When I set alsasink property sync=true, no audio can be heard on the
output :(
I guess that the problem is a wrong buffer pts value (although appsrc has
do-timestamp = true) but I would expect alsasink to mention that the frame
has been dropped.
How can I solve this problem, what else should I be looking for?
I traced some debug messages using
GST_DEBUG=*rtpbasedepay*:6,*audiodecoder*:6,*audiobasesink*:6,*webrtc*:6
audioapplication
Here is a set of traces when webrtc gets configured:
0:00:00.280952746 2763 0x6080c580 LOG audiodecoder
gstaudiodecoder.c:2704:gst_audio_decoder_src_query_default:<audio_decoder>
handling query: latency query: 0x6070a2f0, GstQueryLatency,
live=(boolean)false, min-latency=(guint64)0,
max-latency=(guint64)18446744073709551615;
0:00:00.281128109 2763 0x6080c580 DEBUG audiodecoder
gstaudiodecoder.c:2804:gst_audio_decoder_src_query_default:<audio_decoder>
Peer latency: live 1, min 0:00:00.010000000 max 99:99:99.999999999
0:00:00.281239463 2763 0x6080c580 DEBUG webrtcdsp
gstwebrtcechoprobe.cpp:145:gst_webrtc_echo_probe_src_event:<webrtcechoprobe0>
We have a latency of 0:00:00.000000000 and delay of 130ms
0:00:00.281327692 2763 0x6080c580 DEBUG audiodecoder
gstaudiodecoder.c:2483:gst_audio_decoder_src_event:<audio_decoder> received
event 56321, latency
0:00:00.281774252 2763 0x6080c580 DEBUG audiobasesink
gstaudiobasesink.c:2437:gst_audio_base_sink_change_state:<audio_sink>
ringbuffer may start now
0:00:00.282608570 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:2338:gst_audio_decoder_sink_event:<audio_decoder> received
event 10254, stream-start
0:00:00.282837267 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:1613:gst_audio_decoder_flush:<audio_decoder> flush hard 0
0:00:00.283223931 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:468:gst_audio_decoder_reset:<audio_decoder>
gst_audio_decoder_reset
0:00:00.283472003 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:2152:gst_audio_decoder_sink_eventfunc:<audio_decoder>
received STREAM_START. Clearing taglist
0:00:00.299353792 2763 0x60844950 LOG webrtcdsp
gstwebrtcdsp.cpp:543:gst_webrtc_dsp_setup:<audio_aec> setting format to
16-bit signed PCM audio with 48000 Hz and 1 channels
0:00:00.302514400 2763 0x60844950 DEBUG webrtcdsp
gstwebrtcdsp.cpp:587:gst_webrtc_dsp_setup:<audio_aec> Enabling High Pass
filter
0:00:00.302592264 2763 0x60844950 DEBUG webrtcdsp
gstwebrtcdsp.cpp:592:gst_webrtc_dsp_setup:<audio_aec> Enabling Echo
Cancellation
0:00:00.304783346 2763 0x60844950 DEBUG webrtcdsp
gstwebrtcdsp.cpp:600:gst_webrtc_dsp_setup:<audio_aec> Enabling Noise
Suppression
0:00:00.305094229 2763 0x60844950 DEBUG webrtcdsp
gstwebrtcdsp.cpp:613:gst_webrtc_dsp_setup:<audio_aec> Enabling Digital Gain
Control, target level dBFS 3, compression gain dB 9, limiter enabled, mode:
Adaptive Digital
0:00:00.376973319 2763 0x60844950 DEBUG webrtcdsp
gstwebrtcdsp.cpp:469:gst_webrtc_dsp_submit_input_buffer:<audio_aec> Received
discont, clearing adapter.
0:00:00.649903244 2763 0x61403ef0 DEBUG audiobasesink
gstaudiobasesink.c:429:gst_audio_base_sink_query:<audio_sink> latency query
0:00:00.650615427 2763 0x61403ef0 DEBUG audiodecoder
gstaudiodecoder.c:2837:gst_audio_decoder_src_query:<audio_decoder:src>
received query latency query: 0x6095f780, GstQueryLatency,
live=(boolean)false, min-latency=(guint64)0,
max-latency=(guint64)18446744073709551615;
0:00:00.650811312 2763 0x61403ef0 LOG audiodecoder
gstaudiodecoder.c:2704:gst_audio_decoder_src_query_default:<audio_decoder>
handling query: latency query: 0x6095f780, GstQueryLatency,
live=(boolean)false, min-latency=(guint64)0,
max-latency=(guint64)18446744073709551615;
0:00:00.651334277 2763 0x61403ef0 DEBUG audiodecoder
gstaudiodecoder.c:2804:gst_audio_decoder_src_query_default:<audio_decoder>
Peer latency: live 1, min 0:00:00.010000000 max 99:99:99.999999999
0:00:00.651596776 2763 0x61403ef0 DEBUG audiobasesink
gstaudiobasesink.c:446:gst_audio_base_sink_query:<audio_sink> we are not
negotiated, can't report latency yet
0:00:00.652297606 2763 0x61403ef0 DEBUG audiodecoder
gstaudiodecoder.c:2837:gst_audio_decoder_src_query:<audio_decoder:src>
received query latency query: 0x6095f830, GstQueryLatency,
live=(boolean)false, min-latency=(guint64)0,
max-latency=(guint64)18446744073709551615;
0:00:00.652408178 2763 0x61403ef0 LOG audiodecoder
gstaudiodecoder.c:2704:gst_audio_decoder_src_query_default:<audio_decoder>
handling query: latency query: 0x6095f830, GstQueryLatency,
live=(boolean)false, min-latency=(guint64)0,
max-latency=(guint64)18446744073709551615;
0:00:00.652950362 2763 0x61403ef0 DEBUG audiodecoder
gstaudiodecoder.c:2804:gst_audio_decoder_src_query_default:<audio_decoder>
Peer latency: live 1, min 0:00:00.010000000 max 99:99:99.999999999
0:00:00.653220465 2763 0x61403ef0 DEBUG webrtcdsp
gstwebrtcechoprobe.cpp:145:gst_webrtc_echo_probe_src_event:<webrtcechoprobe0>
We have a latency of 0:00:00.028000000 and delay of 130ms
0:00:00.653480516 2763 0x61403ef0 DEBUG audiodecoder
gstaudiodecoder.c:2483:gst_audio_decoder_src_event:<audio_decoder> received
event 56321, latency
This is during a audio session:
0:03:48.069266549 2763 0x60844a30 LOG rtpbasedepayload
gstrtpbasedepayload.c:359:gst_rtp_base_depayload_handle_buffer:<audio_depacketizer>
discont 0, seqnum 841, rtptime 403680, pts 0:03:47.343881225, dts
0:03:47.301000000
0:03:48.069403215 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:1878:gst_audio_decoder_chain:<audio_decoder> received
buffer of size 80 with ts 0:03:47.343881225, duration 99:99:99.999999999
0:03:48.069511756 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:1464:gst_audio_decoder_push_buffers:<audio_decoder>
available: 80
0:03:48.069642381 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:1430:gst_audio_decoder_handle_frame:<audio_decoder>
tracking frame size 80, ts 0:03:47.343881225
0:03:48.069767745 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:3525:gst_audio_decoder_allocate_output_buffer: alloc src
buffer
0:03:48.070108107 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:1228:gst_audio_decoder_finish_frame:<audio_decoder>
accepting 640 bytes == 160 samples for 1 frames
0:03:48.070235971 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:1274:gst_audio_decoder_finish_frame:<audio_decoder>
leading frame ts 0:03:47.333923456
0:03:48.070353262 2763 0x60844a30 DEBUG audiodecoder
gstaudiodecoder.c:1321:gst_audio_decoder_finish_frame:<audio_decoder>
base_ts resync
0:03:48.070460918 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:983:gst_audio_decoder_output:<audio_decoder> output buffer
of size 640 with ts 0:03:47.333923456, duration 0:00:00.010000000
0:03:48.070683052 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:905:gst_audio_decoder_push_forward:<audio_decoder>
clipping buffer of size 640 with ts 0:03:47.333923456, duration
0:00:00.010000000
0:03:48.070826853 2763 0x60844a30 LOG audiodecoder
gstaudiodecoder.c:956:gst_audio_decoder_push_forward:<audio_decoder> pushing
buffer of size 640 with ts 0:03:47.333923456, duration 0:00:00.010000000
0:03:48.071748671 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1896:gst_audio_base_sink_render:<audio_sink> time
0:03:47.325937500, start 0:00:00.000000000, samples 480
0:03:48.071936535 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1933:gst_audio_base_sink_render:<audio_sink> sync-offset
+0:00:00.028000000, render-delay 0:00:00.000000000, ts-offset
+0:00:00.000000000
0:03:48.072084451 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1995:gst_audio_base_sink_render:<audio_sink> running:
start 0:03:47.325937500 - stop 0:03:47.335937500
0:03:48.072210960 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:2010:gst_audio_base_sink_render:<audio_sink> compensating
for sync-offset 0:00:00.028000000
0:03:48.072385178 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:545:gst_audio_base_sink_get_time:<audio_sink> processed
samples: raw 422400, delay 9600, real 412800, time 0:00:08.600000000
0:03:48.072524344 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1431:gst_audio_base_sink_skew_slaving:<audio_sink>
internal 0:00:08.600000000 external 0:03:47.711000000 cinternal
0:00:00.000000000 cexternal 0:03:39.105000000
0:03:48.072682572 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1452:gst_audio_base_sink_skew_slaving:<audio_sink>
internal 0:00:08.600000000 external 0:00:08.606000000 skew
-0:00:00.006000000 avg -0:00:00.006461042
0:03:48.072838509 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:2037:gst_audio_base_sink_render:<audio_sink> final
timestamps: start 0:00:08.248937500 - stop 0:00:08.258937500
0:03:48.072964810 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:1775:gst_audio_base_sink_get_alignment:<audio_sink> align
with prev sample, ABS (0) < 1920
0:03:48.073066789 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:2135:gst_audio_base_sink_render:<audio_sink> rendering at
395949 480/480
0:03:48.073188090 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:2146:gst_audio_base_sink_render:<audio_sink> wrote 480 of
480
0:03:48.073292413 2763 0x60844a30 DEBUG audiobasesink
gstaudiobasesink.c:2178:gst_audio_base_sink_render:<audio_sink> next sample
expected at 396429
--
Sent from: http://gstreamer-devel.966125.n4.nabble.com/
More information about the gstreamer-devel
mailing list