High initial playback delay when using audiomixer

[Ajit Warrier]

I am using the following pipeline on an x86 PC, using v1.10.1:

gst-launch-1.0 -v udpsrc caps="application/x-rtp" port=1234 multicast-group=239.0.0.190 ! rtpg722depay ! avdec_g722 ! audiomixer ! alsasink

It receives g722 coded rtp audio and plays it out. When using the audiomixer in this pipeline, if I perform the following operations:

- start pipeline

- wait for couple of minutes

- THEN send rtp audio

I experience a delay of 5-6 seconds before playback starts. This only happens if I wait for couple of minutes, in fact the playback delay gets worse the longer I wait. And it only happens with the audiomixer in the pipeline. Without the audiomixer, there is no playback delay.

I ran GST_DEBUG=6 and got the following output that looks suspicious:

Multiple repeated instances of:

0:02:52.285149489  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times start: 0:02:47.560000000, end: 0:02:47.570000000
0:02:52.285156228  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 0
0:02:52.285163242  5934 0x55dc774f8d40 LOG                 basesink gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff 0:00:00.010000000
0:02:52.285168838  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering object 0x7f3934017af0
0:02:52.285173812  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:1899:gst_audio_base_sink_render:<alsasink0> Received GAP or ignoring audio for trickplay. Dropping contents
0:02:52.285178641  5934 0x55dc774f8d40 DEBUG              GST_EVENT gstevent.c:305:gst_event_new_custom: creating new event 0x7f393c004a60 gap 40966
0:02:52.285184292  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:912:gst_audio_ring_buffer_start:<audiosinkringbuffer0> starting ringbuffer
0:02:52.285188437  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:929:gst_audio_ring_buffer_start:<audiosinkringbuffer0> was not stopped, try paused
0:02:52.285192343  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:937:gst_audio_ring_buffer_start:<audiosinkringbuffer0> was not paused, must have been started
0:02:52.285199470  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:1911:gst_base_sink_get_sync_times:<alsasink0> Got Gap time 0:02:47.560000000 duration 0:00:00.010000000
0:02:52.285206383  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 1
0:02:52.285213779  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:2523:gst_base_sink_do_sync:<alsasink0> reset rc_time to time 0:02:47.780000000
0:02:52.285219206  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:2535:gst_base_sink_do_sync:<alsasink0> possibly waiting for clock to reach 0:02:47.560000000, adjusted 0:02:47.780000000
0:02:52.285225617  5934 0x55dc774f8d40 LOG                 basesink gstbasesink.c:2117:gst_base_sink_wait_clock:<alsasink0> time 0:02:47.780000000, base_time 1349:31:49.960166366
0:02:52.285232112  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:535:gst_clock_id_wait:<GstSystemClock> waiting on clock entry 0x7f393c0048a0
0:02:52.285236787  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal time 1349:34:41.935386462
0:02:52.285242365  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time 1349:34:41.935386462
0:02:52.285247488  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstsystemclock.c:717:gst_system_clock_id_wait_jitter_unlocked: entry 0x7f393c0048a0 time 1349:34:37.740166366 now 1349:34:41.935386462 diff (time-now) -4195220096
0:02:52.285254637  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:545:gst_clock_id_wait:<GstSystemClock> done waiting entry 0x7f393c0048a0, res: 1 (early)
0:02:52.285259717  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:2542:gst_base_sink_do_sync:<alsasink0> clock returned 1, jitter  0:00:04.195220096
0:02:52.285265829  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:2858:gst_base_sink_is_too_late:<alsasink0> frame dropping disabled
0:02:52.285269802  5934 0x55dc774f8d40 LOG                GST_EVENT gstevent.c:222:_gst_event_free: freeing event 0x7f393c004a60 type gap
0:02:52.285275293  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object unref after render 0x7f3934017af0
0:02:52.285279814  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017af0
0:02:52.285284056  5934 0x55dc774f8d40 DEBUG             GST_MEMORY gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012620
0:02:52.285289468  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called chainfunction &gst_base_sink_chain with buffer 0x7f3934017af0, returned ok
0:02:52.285295407  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0> pushed outbuf, result = ok
0:02:52.285300098  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow return is ok
0:02:52.285305893  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function 0x7f39559040f0 on pad
0:02:52.285311540  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0> checking pads
0:02:52.285315809  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0> pads are ready
0:02:52.285319732  5934 0x55dc774f8d40 DEBUG             aggregator gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all pads have data
0:02:52.285324475  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function 0x7f39559040f0 on pad
0:02:52.285330484  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function sync_pad_values on pad
0:02:52.285338421  5934 0x55dc774f8d40 LOG                  default gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0> sync_values
0:02:52.285343028  5934 0x55dc774f8d40 DEBUG             GST_MEMORY gstmemory.c:138:gst_memory_init: new memory 0x7f393c012440, maxsize:327 offset:0 size:320
0:02:52.285348790  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
0:02:52.285352988  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem 0x7f393c012440
0:02:52.285357932  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of size 320 from allocator (nil)
0:02:52.285362993  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0, length -1, flags 0002
0:02:52.285368270  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0, length 1
0:02:52.285373686  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0> Starting to mix 160 samples for offset 2681120 with timestamp 0:02:47.570000000
0:02:52.285380278  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0> pushing outbuf 0x7f3934017c00, timestamp 0:02:47.570000000 offset 2681120
0:02:52.285386988  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7f3934017c00, pts 0:02:47.570000000, dts 99:
99:99.999999999, dur 0:00:00.010000000, size 320, offset 2681120, offset_end 2681280, flags 0x800

Finally followed by the playback:

0:02:52.285535775  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called chainfunction &gst_base_sink_chain with buffer 0x7f3934017c00, returned ok
0:02:52.285541688  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0> pushed outbuf, result = ok
0:02:52.285546617  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow return is ok
0:02:52.285552504  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function 0x7f39559040f0 on pad
0:02:52.285558288  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0> checking pads
0:02:52.285562564  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0> pads are ready
0:02:52.285566505  5934 0x55dc774f8d40 DEBUG             aggregator gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all pads have data
0:02:52.285571214  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function 0x7f39559040f0 on pad
0:02:52.285577286  5934 0x55dc774f8d40 LOG               aggregator gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink_0> calling function sync_pad_values on pad
0:02:52.285582555  5934 0x55dc774f8d40 LOG                  default gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0> sync_values
0:02:52.285586893  5934 0x55dc774f8d40 DEBUG             GST_MEMORY gstmemory.c:138:gst_memory_init: new memory 0x7f393c012260, maxsize:327 offset:0 size:320
0:02:52.285592416  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
0:02:52.285596623  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem 0x7f393c012260
0:02:52.285604025  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of size 320 from allocator (nil)
0:02:52.285609397  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0, length -1, flags 0002
0:02:52.285614824  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0, length 1
0:02:52.285620362  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0> Starting to mix 160 samples for offset 2681280 with timestamp 0:02:47.580000000
0:02:52.285627060  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1277:gst_audio_aggregator_aggregate:<audiomixer0:sink_0> Mixing buffer for current offset
0:02:52.285631472  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0, length -1, flags 0003
0:02:52.285636893  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0, length 1
0:02:52.285641867  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017270, idx 0, length -1, flags 0001
0:02:52.285647069  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017270, idx 0, length 1
0:02:52.285652574  5934 0x55dc774f8d40 LOG               audiomixer gstaudiomixer.c:640:gst_audiomixer_aggregate_one_buffer:<audiomixer0:sink_0> mixing 16 bytes at offset 304 from offset 0
0:02:52.285790505  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1283:gst_audio_aggregator_aggregate:<audiomixer0:sink_0> Pad is at or after current offset: 2681440 >= 2681440
0:02:52.285798603  5934 0x55dc774f8d40 LOG          audioaggregator gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0> pushing outbuf 0x7f3934017c00, timestamp 0:02:47.580000000 offset 2681280
0:02:52.285806631  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7f3934017c00, pts 0:02:47.580000000, dts 99:99:99.999999999, dur 0:00:00.010000000, size 320, offset 2681280, offset_end 2681440, flags 0x0
0:02:52.285815505  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times start: 0:02:47.580000000, end: 0:02:47.590000000
0:02:52.285823219  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times start: 0:02:47.580000000, stop: 0:02:47.590000000, do_sync 0
0:02:52.285831300  5934 0x55dc774f8d40 LOG                 basesink gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff 0:00:00.010000000
0:02:52.285837240  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering object 0x7f3934017c00
0:02:52.285842645  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:1916:gst_audio_base_sink_render:<alsasink0> time 0:02:47.580000000, start 0:00:00.000000000, samples 160
0:02:52.285856423  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:1953:gst_audio_base_sink_render:<alsasink0> sync-offset +0:00:00.220000000, render-delay 0:00:00.000000000, ts-offset +0:00:00.000000000
0:02:52.285866566  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2015:gst_audio_base_sink_render:<alsasink0> running: start 0:02:47.580000000 - stop 0:02:47.590000000
0:02:52.285873485  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2030:gst_audio_base_sink_render:<alsasink0> compensating for sync-offset 0:00:00.220000000
0:02:52.285879252  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2037:gst_audio_base_sink_render:<alsasink0> adding base_time 1349:31:49.960166366
0:02:52.285888650  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal time 1349:34:41.936038218
0:02:52.285894620  5934 0x55dc774f8d40 DEBUG              GST_CLOCK gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time 1349:34:41.936038218
0:02:52.285905690  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:568:gst_audio_base_sink_get_time:<alsasink0> processed samples: raw 72960, delay 3100, real 69860, time 0:00:04.366250000
0:02:52.285913345  5934 0x55dc774f8d40 DEBUG             audioclock gstaudioclock.c:202:gst_audio_clock_get_time:<GstAudioSinkClock> result 0:00:04.366250000, last_time 0:00:00.000000000
0:02:52.285921064  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:1452:gst_audio_base_sink_skew_slaving:<alsasink0> internal 0:00:04.366250000 external 1349:34:41.936038218 cinternal 0:00:00.000000000 cexternal 1349:34:37.567980323
0:02:52.285930548  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:1473:gst_audio_base_sink_skew_slaving:<alsasink0> internal 0:00:04.366250000 external 0:00:04.368057895 skew -0:00:00.001807895 avg -0:00:00.001807895
0:02:52.285940773  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2057:gst_audio_base_sink_render:<alsasink0> final timestamps: start 0:00:00.192186043 - stop 0:00:00.202186043
0:02:52.285948429  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2126:gst_audio_base_sink_render:<alsasink0> no align possible: no previous sample position known
0:02:52.285952614  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2155:gst_audio_base_sink_render:<alsasink0> rendering at 3074 160/160
0:02:52.285957857  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0, length -1, flags 0001
0:02:52.285963384  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0, length 1
0:02:52.285969094  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1503:default_commit:<audiosinkringbuffer0> write 160 : 160
0:02:52.285974366  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0> pointer at 456, write to 19-68, diff -437, segtotal 20, segsize 320, base 0
0:02:52.285980927  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write @0x7f393c0078f0 seg 19, sps 160, off 68, avail 252
0:02:52.285986614  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1579:default_commit: copy 252 bytes
0:02:52.285991302  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0> pointer at 456, write to 20-0, diff -436, segtotal 20, segsize 320, base 0
0:02:52.285997607  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write @0x7f393c006130 seg 0, sps 160, off 0, avail 68
0:02:52.286003049  5934 0x55dc774f8d40 DEBUG             ringbuffer gstaudioringbuffer.c:1579:default_commit: copy 68 bytes
0:02:52.286007709  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2166:gst_audio_base_sink_render:<alsasink0> wrote 160 of 160
0:02:52.286012918  5934 0x55dc774f8d40 DEBUG          audiobasesink gstaudiobasesink.c:2198:gst_audio_base_sink_render:<alsasink0> next sample expected at 3234
0:02:52.286017810  5934 0x55dc774f8d40 DEBUG               basesink gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object unref after render 0x7f3934017c00
0:02:52.286022216  5934 0x55dc774f8d40 LOG               GST_BUFFER gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017c00
0:02:52.286026444  5934 0x55dc774f8d40 DEBUG             GST_MEMORY gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012260

Any ideas why this delay occurs ?

Ajit.

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Nicolas Dufresne-5]

Hi,

Le mardi 29 novembre 2016 à 22:56 +0000, Ajit Warrier a écrit :

> I am using the following pipeline on an x86 PC, using v1.10.1:
>
> gst-launch-1.0 -v udpsrc caps="application/x-rtp" port=1234
> multicast-group=239.0.0.190 ! rtpg722depay ! avdec_g722 ! audiomixer
> ! alsasink
>
> It receives g722 coded rtp audio and plays it out. When using the
> audiomixer in this pipeline, if I perform the following operations:
>
> - start pipeline
> - wait for couple of minutes
> - THEN send rtp audio
>
> I experience a delay of 5-6 seconds before playback starts. This only
> happens if I wait for couple of minutes, in fact the playback delay
> gets worse the longer I wait. And it only happens with the audiomixer
> in the pipeline. Without the audiomixer, there is no playback delay.

You should be able to solve this issue using the "start-time-selection"
property. on the audio mixer. Using the method first (1).

  ... ! audiomixer start-time-selection=first ! ...

Otherwise the mixer will produce silence from 0 to the first buffer
running time received, which in most cases lead to this pause.

>
> I ran GST_DEBUG=6 and got the following output that looks suspicious:
>
> Multiple repeated instances of:
>
> 0:02:52.285149489  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times
> start: 0:02:47.560000000, end: 0:02:47.570000000
> 0:02:52.285156228  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 0
> 0:02:52.285163242  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff
> 0:00:00.010000000
> 0:02:52.285168838  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering
> object 0x7f3934017af0
> 0:02:52.285173812  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1899:gst_audio_base_sink_render:<alsasink0>
> Received GAP or ignoring audio for trickplay. Dropping contents
> 0:02:52.285178641  5934 0x55dc774f8d40 DEBUG              GST_EVENT
> gstevent.c:305:gst_event_new_custom: creating new event
> 0x7f393c004a60 gap 40966
> 0:02:52.285184292  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:912:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> starting ringbuffer
> 0:02:52.285188437  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:929:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> was not stopped, try paused
> 0:02:52.285192343  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:937:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> was not paused, must have been started
> 0:02:52.285199470  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1911:gst_base_sink_get_sync_times:<alsasink0> Got Gap
> time 0:02:47.560000000 duration 0:00:00.010000000
> 0:02:52.285206383  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 1
> 0:02:52.285213779  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2523:gst_base_sink_do_sync:<alsasink0> reset rc_time to
> time 0:02:47.780000000
> 0:02:52.285219206  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2535:gst_base_sink_do_sync:<alsasink0> possibly waiting
> for clock to reach 0:02:47.560000000, adjusted 0:02:47.780000000
> 0:02:52.285225617  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2117:gst_base_sink_wait_clock:<alsasink0> time
> 0:02:47.780000000, base_time 1349:31:49.960166366
> 0:02:52.285232112  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:535:gst_clock_id_wait:<GstSystemClock> waiting on clock
> entry 0x7f393c0048a0
> 0:02:52.285236787  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal
> time 1349:34:41.935386462
> 0:02:52.285242365  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time
> 1349:34:41.935386462
> 0:02:52.285247488  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstsystemclock.c:717:gst_system_clock_id_wait_jitter_unlocked: entry
> 0x7f393c0048a0 time 1349:34:37.740166366 now 1349:34:41.935386462
> diff (time-now) -4195220096
> 0:02:52.285254637  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:545:gst_clock_id_wait:<GstSystemClock> done waiting entry
> 0x7f393c0048a0, res: 1 (early)
> 0:02:52.285259717  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2542:gst_base_sink_do_sync:<alsasink0> clock returned
> 1, jitter  0:00:04.195220096
> 0:02:52.285265829  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2858:gst_base_sink_is_too_late:<alsasink0> frame
> dropping disabled
> 0:02:52.285269802  5934 0x55dc774f8d40 LOG                GST_EVENT
> gstevent.c:222:_gst_event_free: freeing event 0x7f393c004a60 type gap
> 0:02:52.285275293  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object
> unref after render 0x7f3934017af0
> 0:02:52.285279814  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017af0
> 0:02:52.285284056  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012620
> 0:02:52.285289468  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called
> chainfunction &gst_base_sink_chain with buffer 0x7f3934017af0,
> returned ok
> 0:02:52.285295407  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0
> > pushed outbuf, result = ok
> 0:02:52.285300098  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow
> return is ok
> 0:02:52.285305893  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285311540  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0>
> checking pads
> 0:02:52.285315809  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0>
> pads are ready
> 0:02:52.285319732  5934 0x55dc774f8d40 DEBUG             aggregator
> gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all
> pads have data
> 0:02:52.285324475  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285330484  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function sync_pad_values on pad
> 0:02:52.285338421  5934 0x55dc774f8d40 LOG                  default
> gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0>
> sync_values
> 0:02:52.285343028  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:138:gst_memory_init: new memory 0x7f393c012440,
> maxsize:327 offset:0 size:320
> 0:02:52.285348790  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
> 0:02:52.285352988  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem
> 0x7f393c012440
> 0:02:52.285357932  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of
> size 320 from allocator (nil)
> 0:02:52.285362993  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0002
> 0:02:52.285368270  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285373686  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0
> > Starting to mix 160 samples for offset 2681120 with timestamp
> 0:02:47.570000000
> 0:02:52.285380278  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0
> > pushing outbuf 0x7f3934017c00, timestamp 0:02:47.570000000 offset
> 2681120
> 0:02:52.285386988  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling
> chainfunction &gst_base_sink_chain with buffer buffer:
> 0x7f3934017c00, pts 0:02:47.570000000, dts 99:
> 99:99.999999999, dur 0:00:00.010000000, size 320, offset 2681120,
> offset_end 2681280, flags 0x800
>
>
> Finally followed by the playback:
>
> 0:02:52.285535775  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called
> chainfunction &gst_base_sink_chain with buffer 0x7f3934017c00,
> returned ok
> 0:02:52.285541688  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0
> > pushed outbuf, result = ok
> 0:02:52.285546617  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow
> return is ok
> 0:02:52.285552504  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285558288  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0>
> checking pads
> 0:02:52.285562564  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0>
> pads are ready
> 0:02:52.285566505  5934 0x55dc774f8d40 DEBUG             aggregator
> gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all
> pads have data
> 0:02:52.285571214  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285577286  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function sync_pad_values on pad
> 0:02:52.285582555  5934 0x55dc774f8d40 LOG                  default
> gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0>
> sync_values
> 0:02:52.285586893  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:138:gst_memory_init: new memory 0x7f393c012260,
> maxsize:327 offset:0 size:320
> 0:02:52.285592416  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
> 0:02:52.285596623  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem
> 0x7f393c012260
> 0:02:52.285604025  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of
> size 320 from allocator (nil)
> 0:02:52.285609397  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0002
> 0:02:52.285614824  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285620362  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0
> > Starting to mix 160 samples for offset 2681280 with timestamp
> 0:02:47.580000000
> 0:02:52.285627060  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1277:gst_audio_aggregator_aggregate:<audiomixer0
> :sink_0> Mixing buffer for current offset
> 0:02:52.285631472  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0003
> 0:02:52.285636893  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285641867  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017270, idx 0,
> length -1, flags 0001
> 0:02:52.285647069  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017270, idx 0,
> length 1
> 0:02:52.285652574  5934 0x55dc774f8d40 LOG               audiomixer
> gstaudiomixer.c:640:gst_audiomixer_aggregate_one_buffer:<audiomixer0:
> sink_0> mixing 16 bytes at offset 304 from offset 0
> 0:02:52.285790505  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1283:gst_audio_aggregator_aggregate:<audiomixer0
> :sink_0> Pad is at or after current offset: 2681440 >= 2681440
> 0:02:52.285798603  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0
> > pushing outbuf 0x7f3934017c00, timestamp 0:02:47.580000000 offset
> 2681280
> 0:02:52.285806631  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling
> chainfunction &gst_base_sink_chain with buffer buffer:
> 0x7f3934017c00, pts 0:02:47.580000000, dts 99:99:99.999999999, dur
> 0:00:00.010000000, size 320, offset 2681280, offset_end 2681440,
> flags 0x0
> 0:02:52.285815505  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times
> start: 0:02:47.580000000, end: 0:02:47.590000000
> 0:02:52.285823219  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.580000000, stop: 0:02:47.590000000, do_sync 0
> 0:02:52.285831300  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff
> 0:00:00.010000000
> 0:02:52.285837240  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering
> object 0x7f3934017c00
> 0:02:52.285842645  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1916:gst_audio_base_sink_render:<alsasink0> time
> 0:02:47.580000000, start 0:00:00.000000000, samples 160
> 0:02:52.285856423  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1953:gst_audio_base_sink_render:<alsasink0> sync-
> offset +0:00:00.220000000, render-delay 0:00:00.000000000, ts-offset
> +0:00:00.000000000
> 0:02:52.285866566  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2015:gst_audio_base_sink_render:<alsasink0>
> running: start 0:02:47.580000000 - stop 0:02:47.590000000
> 0:02:52.285873485  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2030:gst_audio_base_sink_render:<alsasink0>
> compensating for sync-offset 0:00:00.220000000
> 0:02:52.285879252  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2037:gst_audio_base_sink_render:<alsasink0> adding
> base_time 1349:31:49.960166366
> 0:02:52.285888650  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal
> time 1349:34:41.936038218
> 0:02:52.285894620  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time
> 1349:34:41.936038218
> 0:02:52.285905690  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:568:gst_audio_base_sink_get_time:<alsasink0>
> processed samples: raw 72960, delay 3100, real 69860, time
> 0:00:04.366250000
> 0:02:52.285913345  5934 0x55dc774f8d40 DEBUG             audioclock
> gstaudioclock.c:202:gst_audio_clock_get_time:<GstAudioSinkClock>
> result 0:00:04.366250000, last_time 0:00:00.000000000
> 0:02:52.285921064  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1452:gst_audio_base_sink_skew_slaving:<alsasink0>
> internal 0:00:04.366250000 external 1349:34:41.936038218 cinternal
> 0:00:00.000000000 cexternal 1349:34:37.567980323
> 0:02:52.285930548  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1473:gst_audio_base_sink_skew_slaving:<alsasink0>
> internal 0:00:04.366250000 external 0:00:04.368057895 skew
> -0:00:00.001807895 avg -0:00:00.001807895
> 0:02:52.285940773  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2057:gst_audio_base_sink_render:<alsasink0> final
> timestamps: start 0:00:00.192186043 - stop 0:00:00.202186043
> 0:02:52.285948429  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2126:gst_audio_base_sink_render:<alsasink0> no
> align possible: no previous sample position known
> 0:02:52.285952614  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2155:gst_audio_base_sink_render:<alsasink0>
> rendering at 3074 160/160
> 0:02:52.285957857  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0001
> 0:02:52.285963384  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285969094  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1503:default_commit:<audiosinkringbuffer0> write
> 160 : 160
> 0:02:52.285974366  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0>
> pointer at 456, write to 19-68, diff -437, segtotal 20, segsize 320,
> base 0
> 0:02:52.285980927  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write
> @0x7f393c0078f0 seg 19, sps 160, off 68, avail 252
> 0:02:52.285986614  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1579:default_commit: copy 252 bytes
> 0:02:52.285991302  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0>
> pointer at 456, write to 20-0, diff -436, segtotal 20, segsize 320,
> base 0
> 0:02:52.285997607  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write
> @0x7f393c006130 seg 0, sps 160, off 0, avail 68
> 0:02:52.286003049  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1579:default_commit: copy 68 bytes
> 0:02:52.286007709  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2166:gst_audio_base_sink_render:<alsasink0> wrote
> 160 of 160
> 0:02:52.286012918  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2198:gst_audio_base_sink_render:<alsasink0> next
> sample expected at 3234
> 0:02:52.286017810  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object
> unref after render 0x7f3934017c00
> 0:02:52.286022216  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017c00
> 0:02:52.286026444  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012260
>
>
> Any ideas why this delay occurs ?
> Ajit.
>
> _______________________________________________
> gstreamer-devel mailing list
> [hidden email]
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Ajit Warrier]

Ah! That was it ! Thanks! This property seems not documented either in audiomixer/aggregator. Any reason for this ?

Ajit.

On Tue, 29 Nov 2016 at 17:37 Nicolas Dufresne <[hidden email]> wrote:

Hi,

Le mardi 29 novembre 2016 à 22:56 +0000, Ajit Warrier a écrit :
> I am using the following pipeline on an x86 PC, using v1.10.1:
>
> gst-launch-1.0 -v udpsrc caps="application/x-rtp" port=1234
> multicast-group=239.0.0.190 ! rtpg722depay ! avdec_g722 ! audiomixer
> ! alsasink
>
> It receives g722 coded rtp audio and plays it out. When using the
> audiomixer in this pipeline, if I perform the following operations:
>
> - start pipeline
> - wait for couple of minutes
> - THEN send rtp audio
>
> I experience a delay of 5-6 seconds before playback starts. This only
> happens if I wait for couple of minutes, in fact the playback delay
> gets worse the longer I wait. And it only happens with the audiomixer
> in the pipeline. Without the audiomixer, there is no playback delay.

You should be able to solve this issue using the "start-time-selection"
property. on the audio mixer. Using the method first (1).

  ... ! audiomixer start-time-selection=first ! ...

Otherwise the mixer will produce silence from 0 to the first buffer
running time received, which in most cases lead to this pause.

>
> I ran GST_DEBUG=6 and got the following output that looks suspicious:
>
> Multiple repeated instances of:
>
> 0:02:52.285149489  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times
> start: 0:02:47.560000000, end: 0:02:47.570000000
> 0:02:52.285156228  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 0
> 0:02:52.285163242  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff
> 0:00:00.010000000
> 0:02:52.285168838  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering
> object 0x7f3934017af0
> 0:02:52.285173812  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1899:gst_audio_base_sink_render:<alsasink0>
> Received GAP or ignoring audio for trickplay. Dropping contents
> 0:02:52.285178641  5934 0x55dc774f8d40 DEBUG              GST_EVENT
> gstevent.c:305:gst_event_new_custom: creating new event
> 0x7f393c004a60 gap 40966
> 0:02:52.285184292  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:912:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> starting ringbuffer
> 0:02:52.285188437  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:929:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> was not stopped, try paused
> 0:02:52.285192343  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:937:gst_audio_ring_buffer_start:<audiosinkringbu
> ffer0> was not paused, must have been started
> 0:02:52.285199470  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1911:gst_base_sink_get_sync_times:<alsasink0> Got Gap
> time 0:02:47.560000000 duration 0:00:00.010000000
> 0:02:52.285206383  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.560000000, stop: 0:02:47.570000000, do_sync 1
> 0:02:52.285213779  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2523:gst_base_sink_do_sync:<alsasink0> reset rc_time to
> time 0:02:47.780000000
> 0:02:52.285219206  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2535:gst_base_sink_do_sync:<alsasink0> possibly waiting
> for clock to reach 0:02:47.560000000, adjusted 0:02:47.780000000
> 0:02:52.285225617  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2117:gst_base_sink_wait_clock:<alsasink0> time
> 0:02:47.780000000, base_time 1349:31:49.960166366
> 0:02:52.285232112  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:535:gst_clock_id_wait:<GstSystemClock> waiting on clock
> entry 0x7f393c0048a0
> 0:02:52.285236787  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal
> time 1349:34:41.935386462
> 0:02:52.285242365  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time
> 1349:34:41.935386462
> 0:02:52.285247488  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstsystemclock.c:717:gst_system_clock_id_wait_jitter_unlocked: entry
> 0x7f393c0048a0 time 1349:34:37.740166366 now 1349:34:41.935386462
> diff (time-now) -<a href="tel:(419)%20522-0096" value="[phone]" class="gmail_msg" target="_blank">4195220096
> 0:02:52.285254637  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:545:gst_clock_id_wait:<GstSystemClock> done waiting entry
> 0x7f393c0048a0, res: 1 (early)
> 0:02:52.285259717  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2542:gst_base_sink_do_sync:<alsasink0> clock returned
> 1, jitter  0:00:04.195220096
> 0:02:52.285265829  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:2858:gst_base_sink_is_too_late:<alsasink0> frame
> dropping disabled
> 0:02:52.285269802  5934 0x55dc774f8d40 LOG                GST_EVENT
> gstevent.c:222:_gst_event_free: freeing event 0x7f393c004a60 type gap
> 0:02:52.285275293  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object
> unref after render 0x7f3934017af0
> 0:02:52.285279814  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017af0
> 0:02:52.285284056  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012620
> 0:02:52.285289468  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called
> chainfunction &gst_base_sink_chain with buffer 0x7f3934017af0,
> returned ok
> 0:02:52.285295407  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0
> > pushed outbuf, result = ok
> 0:02:52.285300098  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow
> return is ok
> 0:02:52.285305893  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285311540  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0>
> checking pads
> 0:02:52.285315809  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0>
> pads are ready
> 0:02:52.285319732  5934 0x55dc774f8d40 DEBUG             aggregator
> gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all
> pads have data
> 0:02:52.285324475  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285330484  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function sync_pad_values on pad
> 0:02:52.285338421  5934 0x55dc774f8d40 LOG                  default
> gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0>
> sync_values
> 0:02:52.285343028  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:138:gst_memory_init: new memory 0x7f393c012440,
> maxsize:327 offset:0 size:320
> 0:02:52.285348790  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
> 0:02:52.285352988  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem
> 0x7f393c012440
> 0:02:52.285357932  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of
> size 320 from allocator (nil)
> 0:02:52.285362993  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0002
> 0:02:52.285368270  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285373686  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0
> > Starting to mix 160 samples for offset 2681120 with timestamp
> 0:02:47.570000000
> 0:02:52.285380278  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0
> > pushing outbuf 0x7f3934017c00, timestamp 0:02:47.570000000 offset
> 2681120
> 0:02:52.285386988  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling
> chainfunction &gst_base_sink_chain with buffer buffer:
> 0x7f3934017c00, pts 0:02:47.570000000, dts 99:
> 99:99.999999999, dur 0:00:00.010000000, size 320, offset 2681120,
> offset_end 2681280, flags 0x800
>
>
> Finally followed by the playback:
>
> 0:02:52.285535775  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4209:gst_pad_chain_data_unchecked:<alsasink0:sink> called
> chainfunction &gst_base_sink_chain with buffer 0x7f3934017c00,
> returned ok
> 0:02:52.285541688  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1372:gst_audio_aggregator_aggregate:<audiomixer0
> > pushed outbuf, result = ok
> 0:02:52.285546617  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:831:gst_aggregator_aggregate_func:<audiomixer0> flow
> return is ok
> 0:02:52.285552504  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285558288  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:428:gst_aggregator_check_pads_ready:<audiomixer0>
> checking pads
> 0:02:52.285562564  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:460:gst_aggregator_check_pads_ready:<audiomixer0>
> pads are ready
> 0:02:52.285566505  5934 0x55dc774f8d40 DEBUG             aggregator
> gstaggregator.c:630:gst_aggregator_wait_and_check:<audiomixer0> all
> pads have data
> 0:02:52.285571214  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function 0x7f39559040f0 on pad
> 0:02:52.285577286  5934 0x55dc774f8d40 LOG               aggregator
> gstaggregator.c:378:gst_aggregator_iterate_sinkpads:<audiomixer0:sink
> _0> calling function sync_pad_values on pad
> 0:02:52.285582555  5934 0x55dc774f8d40 LOG                  default
> gstobject.c:1120:gst_object_sync_values:<audiomixer0:sink_0>
> sync_values
> 0:02:52.285586893  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:138:gst_memory_init: new memory 0x7f393c012260,
> maxsize:327 offset:0 size:320
> 0:02:52.285592416  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:798:gst_buffer_new: new 0x7f3934017c00
> 0:02:52.285596623  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:413:_memory_add: buffer 0x7f3934017c00, idx -1, mem
> 0x7f393c012260
> 0:02:52.285604025  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:854:gst_buffer_new_allocate: new buffer 0x7f3934017c00 of
> size 320 from allocator (nil)
> 0:02:52.285609397  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0002
> 0:02:52.285614824  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285620362  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1194:gst_audio_aggregator_aggregate:<audiomixer0
> > Starting to mix 160 samples for offset 2681280 with timestamp
> 0:02:47.580000000
> 0:02:52.285627060  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1277:gst_audio_aggregator_aggregate:<audiomixer0
> :sink_0> Mixing buffer for current offset
> 0:02:52.285631472  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0003
> 0:02:52.285636893  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285641867  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017270, idx 0,
> length -1, flags 0001
> 0:02:52.285647069  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017270, idx 0,
> length 1
> 0:02:52.285652574  5934 0x55dc774f8d40 LOG               audiomixer
> gstaudiomixer.c:640:gst_audiomixer_aggregate_one_buffer:<audiomixer0:
> sink_0> mixing 16 bytes at offset 304 from offset 0
> 0:02:52.285790505  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1283:gst_audio_aggregator_aggregate:<audiomixer0
> :sink_0> Pad is at or after current offset: 2681440 >= 2681440
> 0:02:52.285798603  5934 0x55dc774f8d40 LOG          audioaggregator
> gstaudioaggregator.c:1365:gst_audio_aggregator_aggregate:<audiomixer0
> > pushing outbuf 0x7f3934017c00, timestamp 0:02:47.580000000 offset
> 2681280
> 0:02:52.285806631  5934 0x55dc774f8d40 DEBUG         GST_SCHEDULING
> gstpad.c:4203:gst_pad_chain_data_unchecked:<alsasink0:sink> calling
> chainfunction &gst_base_sink_chain with buffer buffer:
> 0x7f3934017c00, pts 0:02:47.580000000, dts 99:99:99.999999999, dur
> 0:00:00.010000000, size 320, offset 2681280, offset_end 2681440,
> flags 0x0
> 0:02:52.285815505  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3360:gst_base_sink_chain_unlocked:<alsasink0> got times
> start: 0:02:47.580000000, end: 0:02:47.590000000
> 0:02:52.285823219  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:1946:gst_base_sink_get_sync_times:<alsasink0> got times
> start: 0:02:47.580000000, stop: 0:02:47.590000000, do_sync 0
> 0:02:52.285831300  5934 0x55dc774f8d40 LOG                 basesink
> gstbasesink.c:2483:gst_base_sink_do_sync:<alsasink0> avg frame diff
> 0:00:00.010000000
> 0:02:52.285837240  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3468:gst_base_sink_chain_unlocked:<alsasink0> rendering
> object 0x7f3934017c00
> 0:02:52.285842645  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1916:gst_audio_base_sink_render:<alsasink0> time
> 0:02:47.580000000, start 0:00:00.000000000, samples 160
> 0:02:52.285856423  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1953:gst_audio_base_sink_render:<alsasink0> sync-
> offset +0:00:00.220000000, render-delay 0:00:00.000000000, ts-offset
> +0:00:00.000000000
> 0:02:52.285866566  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2015:gst_audio_base_sink_render:<alsasink0>
> running: start 0:02:47.580000000 - stop 0:02:47.590000000
> 0:02:52.285873485  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2030:gst_audio_base_sink_render:<alsasink0>
> compensating for sync-offset 0:00:00.220000000
> 0:02:52.285879252  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2037:gst_audio_base_sink_render:<alsasink0> adding
> base_time 1349:31:49.960166366
> 0:02:52.285888650  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1045:gst_clock_get_internal_time:<GstSystemClock> internal
> time 1349:34:41.936038218
> 0:02:52.285894620  5934 0x55dc774f8d40 DEBUG              GST_CLOCK
> gstclock.c:1090:gst_clock_get_time:<GstSystemClock> adjusted time
> 1349:34:41.936038218
> 0:02:52.285905690  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:568:gst_audio_base_sink_get_time:<alsasink0>
> processed samples: raw 72960, delay 3100, real 69860, time
> 0:00:04.366250000
> 0:02:52.285913345  5934 0x55dc774f8d40 DEBUG             audioclock
> gstaudioclock.c:202:gst_audio_clock_get_time:<GstAudioSinkClock>
> result 0:00:04.366250000, last_time 0:00:00.000000000
> 0:02:52.285921064  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1452:gst_audio_base_sink_skew_slaving:<alsasink0>
> internal 0:00:04.366250000 external 1349:34:41.936038218 cinternal
> 0:00:00.000000000 cexternal 1349:34:37.567980323
> 0:02:52.285930548  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:1473:gst_audio_base_sink_skew_slaving:<alsasink0>
> internal 0:00:04.366250000 external 0:00:04.368057895 skew
> -0:00:00.001807895 avg -0:00:00.001807895
> 0:02:52.285940773  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2057:gst_audio_base_sink_render:<alsasink0> final
> timestamps: start 0:00:00.192186043 - stop 0:00:00.202186043
> 0:02:52.285948429  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2126:gst_audio_base_sink_render:<alsasink0> no
> align possible: no previous sample position known
> 0:02:52.285952614  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2155:gst_audio_base_sink_render:<alsasink0>
> rendering at 3074 160/160
> 0:02:52.285957857  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:1720:gst_buffer_map_range: buffer 0x7f3934017c00, idx 0,
> length -1, flags 0001
> 0:02:52.285963384  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:212:_get_merged_memory: buffer 0x7f3934017c00, idx 0,
> length 1
> 0:02:52.285969094  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1503:default_commit:<audiosinkringbuffer0> write
> 160 : 160
> 0:02:52.285974366  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0>
> pointer at 456, write to 19-68, diff -437, segtotal 20, segsize 320,
> base 0
> 0:02:52.285980927  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write
> @0x7f393c0078f0 seg 19, sps 160, off 68, avail 252
> 0:02:52.285986614  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1579:default_commit: copy 252 bytes
> 0:02:52.285991302  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1523:default_commit:<audiosinkringbuffer0>
> pointer at 456, write to 20-0, diff -436, segtotal 20, segsize 320,
> base 0
> 0:02:52.285997607  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1553:default_commit:<audiosinkringbuffer0> write
> @0x7f393c006130 seg 0, sps 160, off 0, avail 68
> 0:02:52.286003049  5934 0x55dc774f8d40 DEBUG             ringbuffer
> gstaudioringbuffer.c:1579:default_commit: copy 68 bytes
> 0:02:52.286007709  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2166:gst_audio_base_sink_render:<alsasink0> wrote
> 160 of 160
> 0:02:52.286012918  5934 0x55dc774f8d40 DEBUG          audiobasesink
> gstaudiobasesink.c:2198:gst_audio_base_sink_render:<alsasink0> next
> sample expected at 3234
> 0:02:52.286017810  5934 0x55dc774f8d40 DEBUG               basesink
> gstbasesink.c:3507:gst_base_sink_chain_unlocked:<alsasink0> object
> unref after render 0x7f3934017c00
> 0:02:52.286022216  5934 0x55dc774f8d40 LOG               GST_BUFFER
> gstbuffer.c:724:_gst_buffer_free: finalize 0x7f3934017c00
> 0:02:52.286026444  5934 0x55dc774f8d40 DEBUG             GST_MEMORY
> gstmemory.c:87:_gst_memory_free: free memory 0x7f393c012260
>
>
> Any ideas why this delay occurs ?
> Ajit.
>
> _______________________________________________
> gstreamer-devel mailing list
> [hidden email]
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Nicolas Dufresne-4]

Le mercredi 30 novembre 2016 à 01:57 +0000, Ajit Warrier a écrit :
> Ah! That was it ! Thanks! This property seems not documented either
> in audiomixer/aggregator. Any reason for this ?

Sorry I didn't notice as I often look at the gst-inspect-1.0 output
instead. The property should show up in the html doc of GstAggregator,
but is indeed missing. This is a documentation bug, I will file.

Nicolas
_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Ajit Warrier]

Unfortunately, I will need to re-visit this issue. I found that the start-time-selection=1 works as expected (no playback delay) if:

1. Pipeline has just started - audiomixer has no sink pads and a new sink pad is created.

2. Audiomixer has at least one (inactive) sink pad, and audio is played on a new sink pad.

In the scenario that all sink pads on audiomixer are removed, the next new sink pad will incur the high delay as before. The delay gets longer proportional to the time between "no sink pads" to "audio arrives on the new sink pad".

Does this make sense ? Does the start-time-selection property (or its implied behavior) get reset when all sink pads are removed ?

Thanks,

Ajit.

On Tue, 29 Nov 2016 at 19:13 Nicolas Dufresne <[hidden email]> wrote:

Le mercredi 30 novembre 2016 à 01:57 +0000, Ajit Warrier a écrit :
> Ah! That was it ! Thanks! This property seems not documented either
> in audiomixer/aggregator. Any reason for this ?

Sorry I didn't notice as I often look at the gst-inspect-1.0 output
instead. The property should show up in the html doc of GstAggregator,
but is indeed missing. This is a documentation bug, I will file.

Nicolas_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel