After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 755623 - audiomixer: Using absolute clock times results in 0..now buffers to be rendered at once, stalling the pipeline
audiomixer: Using absolute clock times results in 0..now buffers to be render...
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
git master
Other Linux
: Normal normal
: 1.6.1
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2015-09-25 13:13 UTC by Heinrich Fink
Modified: 2015-10-07 10:20 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Reproducing test case (3.21 KB, text/x-csrc)
2015-09-25 13:13 UTC, Heinrich Fink
Details

Description Heinrich Fink 2015-09-25 13:13:28 UTC
Created attachment 312142 [details]
Reproducing test case

Consider the following test pipeline:

audiotestsrc is-live=TRUE wave=4 ! \
audio/x-raw,format=S16LE,rate=48000,channels=2 ! \
audiomixer start-time-selection=1 !\
queue max-size-time=%u  max-size-buffers=0 max-size-bytes=0 !\
fakesink async=FALSE"

When using absolute clock times (i.e. gst_element_set_base_time=0 and gst_element_set_start_time=none on the pipeline) this will result in a lot of buffers from the past to be rendered. I.e. look at the following log output: 

0:00:00.058614157 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1170:gst_audio_aggregator_aggregate:<audiomixer0> Starting to mix 480 samples for offset 0 with timestamp 4:21:04.348533174
0:00:00.058656691 20696      0x2069850 DEBUG        audioaggregator gstaudioaggregator.c:938:gst_audio_aggregator_fill_buffer:<audiomixer0:sink_0> Buffer resynced: Pad offset 751888729, current audio aggregator offset 0
0:00:00.058670729 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:945:gst_audio_aggregator_fill_buffer:<audiomixer0:sink_0> Queued new buffer at offset 751888729
0:00:00.058680856 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1341:gst_audio_aggregator_aggregate:<audiomixer0> pushing outbuf 0x7f96a4007700, timestamp 4:21:04.348533174 offset 0
0:00:00.058711097 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1348:gst_audio_aggregator_aggregate:<audiomixer0> pushed outbuf, result = ok
0:00:00.058759009 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1170:gst_audio_aggregator_aggregate:<audiomixer0> Starting to mix 480 samples for offset 480 with timestamp 0:00:00.010000000
0:00:00.058777028 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1341:gst_audio_aggregator_aggregate:<audiomixer0> pushing outbuf 0x7f96a4007810, timestamp 0:00:00.010000000 offset 480
0:00:00.058797562 20696      0x2069850 LOG          audioaggregator gstaudioaggregator.c:1348:gst_audio_aggregator_aggregate:<audiomixer0> pushed outbuf, result = ok
0

It looks like the first rendered sample(s) use the correct timestamps (4:21:04.348533174), but then something happens, and the mixer starts at zero (0.01) again.

I have attached a simple test program to reproduce this issue. You can get the above log output using GST_DEBUG=audioaggregator:6. This program simply launches the above pipeline, and sets element_base_time=0 and start_time=none. In the example code you can also optionally set USE_PTP_CLOCK=1 to use a ptp clock with the domain PTP_DOMAIN. Because of the high absolute timestamps with the PTP clock, using a PTP clock will result in constant stalling of the pipeline, because audiomixer is not able to catch up with rendering 0...PTP_ABSOLUTE_TIME. When using system clock, the absolute times are not that high, and the pipeline will eventually stop stalling, when 0..SYS_CLOCK_ABSOLUTE_TIME
Comment 1 Sebastian Dröge (slomo) 2015-09-25 14:35:40 UTC
Confirmed here, the pad's output offset calculation in gst_audio_aggregator_fill_buffer() calls apart here.
Comment 2 Sebastian Dröge (slomo) 2015-09-26 16:48:46 UTC
The problem here is the start-time-selection=first. It confuses running-time and segment positions, and as it is now does not work if running time does not start at 0.
Comment 3 Sebastian Dröge (slomo) 2015-10-01 09:35:06 UTC
I have a fix BTW, will push later
Comment 4 Sebastian Dröge (slomo) 2015-10-01 15:41:48 UTC
Will backport to 1.6.1 in a bit

commit ced0aa800a3aa54b2f42641e611a75652f18b516
Author: Sebastian Dröge <sebastian@centricular.com>
Date:   Wed Sep 30 19:05:35 2015 +0200

    aggregator: Convert GST_ERROR_OBJECT() for seek events to GST_DEBUG_OBJECT()

commit bec6d61e42c48d3e91a47bd7e740efc056cf8fee
Author: Sebastian Dröge <sebastian@centricular.com>
Date:   Wed Sep 30 19:03:05 2015 +0200

    aggregator: For the start time selection, only set the segment position
    
    segment.time and segment.start can stay the same, and were always the same
    before anyway because of a mistake.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=755623

commit 40a908b1d968f7aa3f265c03af2aff93380ec274
Author: Sebastian Dröge <sebastian@centricular.com>
Date:   Wed Sep 30 19:01:21 2015 +0200

    audioaggregator: Select the initial offset based on the start segment position
    
    instead of always using 0. Otherwise we might output a lot of silence in the
    beginning instead of outputting from the relevant position.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=755623
Comment 5 Florin Apostol 2015-10-07 10:15:33 UTC
commit 40a908b1d968f7aa3f265c03af2aff93380ec274 fails to build on 32bit platforms:

make[4]: Entering directory '/home/florin/gst/master/gst-plugins-bad/gst/audiomixer'
  CC       libgstaudiomixer_la-gstaudiomixer.lo
  CC       libgstaudiomixer_la-gstaudioaggregator.lo
gstaudioaggregator.c: In function 'gst_audio_aggregator_aggregate':
gstaudioaggregator.c:1142:5: error: format '%lu' expects argument of type 'long unsigned int', but argument 8 has type 'gint64' [-Werror=format=]
     GST_DEBUG_OBJECT (aagg, "Starting at offset %lu", aagg->priv->offset);
     ^
cc1: all warnings being treated as errors
Makefile:938: recipe for target 'libgstaudiomixer_la-gstaudioaggregator.lo' failed
Comment 6 Sebastian Dröge (slomo) 2015-10-07 10:20:17 UTC
See bug #756065