interpipe + audiomixer = GST_BUFFER_FLAG_GAP

[mariannasb]

I have this pipeline doing audiomixing which works fine:

pipelines.append("autoaudiosrc is-live=true provide-clock=false ! "
                 "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3 ! "
                 "deinterleave name=d "
                 "d.src_0 ! tee name=ch0_audio "
                 "d.src_1 ! tee name=ch1_audio "
                 "interleave name=ilv ! "
                 "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3 ! "
                 "queue ! audioconvert ! autoaudiosink "
                 "audiomixer start-time-selection=zero name=leftamix sink_0::volume=0 sink_1::volume=0 ! "
                 "audio/x-raw,channels=1,channel-mask=(bitmask)0x1 ! queue ! ilv.sink_0 "
                 "audiomixer start-time-selection=zero name=rightamix sink_0::volume=1 sink_1::volume=1 ! "
                 "audio/x-raw,channels=1,channel-mask=(bitmask)0x2 ! queue ! ilv.sink_1 "
                 "ch0_audio. ! queue ! leftamix. "
                 "ch0_audio. ! queue ! rightamix. "
                 "ch1_audio. ! queue ! leftamix. "
                 "ch1_audio. ! queue ! rightamix. ")

as a gst-launch command:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=audioconvert)" gst-launch-1.0 autoaudiosrc is-live=true provide-clock=false ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! deinterleave name=d d.src_0 ! tee name=ch0_audio d.src_1 ! tee name=ch1_audio interleave name=ilv ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! queue ! audioconvert ! autoaudiosink audiomixer start-time-selection=zero name=leftamix sink_0::volume=0 sink_1::volume=0 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x1" ! queue ! ilv.sink_0 audiomixer start-time-selection=zero name=rightamix sink_0::volume=1 sink_1::volume=1 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x2" ! queue ! ilv.sink_1 ch0_audio. ! queue ! leftamix. ch0_audio. ! queue ! rightamix. ch1_audio. ! queue ! leftamix. ch1_audio. ! queue ! rightamix.

However as soon as I add interpipes in between it stops working: no sound and all buffers seem to be marked with GST_BUFFER_FLAG_GAP

GST_BUFFER_FLAG_GAP (2048) – the buffer has been created to fill a gap in the stream and contains media neutral data (elements can switch to optimized code path that ignores the buffer content).

So, it seems like the mixer is discarding the frames.

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=audioconvert)" gst-launch-1.0 autoaudiosrc is-live=true provide-clock=false ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! interpipesink name=audio_src sync=false async=false interpipesrc listen-to=audio_src is-live=true stream-sync=passthrough-ts format=time ! deinterleave name=d d.src_0 ! tee name=ch0_audio d.src_1 ! tee name=ch1_audio interleave name=ilv ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! queue ! audioconvert ! autoaudiosink audiomixer start-time-selection=zero name=leftamix sink_0::volume=0 sink_1::volume=0 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x1" ! queue ! ilv.sink_0 audiomixer start-time-selection=zero name=rightamix sink_0::volume=1 sink_1::volume=1 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x2" ! queue ! ilv.sink_1 ch0_audio. ! queue ! leftamix. ch0_audio. ! queue ! rightamix. ch1_audio. ! queue ! leftamix. ch1_audio. ! queue ! rightamix.

Adding more debug *aggregator*:6 gives me this message: 0:00:00.834373796 12456 0x563d8cfec300 DEBUG audioaggregator gstaudioaggregator.c:1755:gst_audio_aggregator_fill_buffer:<rightamix:sink_0> Buffer before segment or current position: 35721 < 35721 which comes from here: https://gitlab.freedesktop.org/gstreamer/gst-plugins-base/-/blob/master/gst-libs/gst/audio/gstaudioaggregator.c#L1934

      if (pad->priv->position >= pad->priv->size) {
        /* Empty buffer, drop */
        pad->priv->dropped += pad->priv->size;
        pad->priv->position = 0;
        pad->priv->size = 0;
        GST_DEBUG_OBJECT (pad,
            "Buffer before segment or current position: %" G_GUINT64_FORMAT
            " < %" G_GINT64_FORMAT, end_output_offset, aagg->priv->offset);
        return FALSE;
      }

So my best guess is problems with SEGMENT?

[mariannasb]

If I change interpipesrc to is-live=false the GST_BUFFER_FLAG_GAP disappears, but I still get no sound.

If I also change interpipesink to sync=true it starts working (I get sound).

[michaelgruner]

Hello @mariannasb thanks for your detailed report, as usual. I really appreciate it. I was partially able to reproduce the problem. Here are some findings

So my best guess is problems with SEGMENT?

In this case the segments will match, and indeed can be verified by checking the segments in the audio sink and the interpipesink.

0:00:00.574252000  9783 0x7ff6930539e0 DEBUG              GST_EVENT gstpad.c:5775:gst_pad_send_event_unchecked:<audio_src:sink> have event type segment event: 0x7ff691868480, time 99:99:99.999999999, seq-num 142, GstEventSegment, segment=(GstSegment)"segment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)time, base=(guint64)0, offset=(guint64)0, start=(guint64)0, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0, duration=(guint64)18446744073709551615;";
0:00:00.669610000  9783 0x7ff693053980 DEBUG              GST_EVENT gstpad.c:5775:gst_pad_send_event_unchecked:<autoaudiosink0-actual-sink-osxaudio:sink> have event type segment event: 0x7ff693094160, time 99:99:99.999999999, seq-num 185, GstEventSegment, segment=(GstSegment)"segment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)time, base=(guint64)0, offset=(guint64)0, start=(guint64)0, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0, duration=(guint64)18446744073709551615;"

So the buffer timestamps are valid in both segments.

If I change interpipesrc to is-live=false the GST_BUFFER_FLAG_GAP disappears, but I still get no sound.

This does work for me. So (one of) the difference(s) when setting is-live=true is that the src will not emit data in the PAUSED state. Said the other way around, by setting is-live=false you are allowing the interpipesrc to push data as soon as it enters the PAUSED state, which I assume works for me because the timestamps are smaller (just I wild guess as per now).

This is similar to setting stream-sync=restart-ts (which works for me). restart-ts will basically retimestamp each buffer with the current running time as soon as it is pushed downstream. This is not recommended for most applications, however. I'm just using it for debugging purposes.

My suspicion now is that it has to do with the latency reported in the pipeline. Le me investigate this a bit further tomorrow.

[mariannasb]

Hello @mariannasb thanks for your detailed report, as usual. I really appreciate it.

Well, I hope to help bringing interpipe to a nice stable state, since it is a nice plugin I can see a lot of use for. :)

And I seem to be good to hit some edge cases :P

This is similar to setting stream-sync=restart-ts (which works for me). restart-ts will basically retimestamp each buffer with the current running time as soon as it is pushed downstream.

Yes, I have also tried that afterwards, and could see that a combination of restart-ts plus is-live=true worked. (though restart-ts is not really an option in my real application)

which I assume works for me because the timestamps are smaller (just I wild guess as per now).

I haven't though about that before but it makes kind of sense. I had assumed the timestamps should be the same since the pipelines start at the same time, but I guess there will be a tiny difference.

My suspicion now is that it has to do with the latency reported in the pipeline. Le me investigate this a bit further tomorrow.

Yeah, now that you mention it I think in some of my tests I could see a latency of 0.1 secs or 0.2 secs. So maybe something about the latency not being properly transmitted between the pipelines?

Said the other way around, by setting is-live=false you are allowing the interpipesrc to push data as soon as it enters the PAUSED state,

Also this issue is kind of related to #108 As I found this problem when experimenting with the sync and is-live params on my pipelines.

So as a follow up, then how much does it actually matter for me to use the is-live=true here?

Like my intuition says that if I use sync=false in the interpipesink and is-live=false in the interpipesrc I will be getting data transfer as fast as possible? And since I have a live src upstream it can only forward the buffers as fast as the live src can produce, and the interpipesrc will only be able to produce buffers on paused if there are any queued from the live src?

[jsalas98]

Hello @mariannasb, sorry for the late response, we have been pretty busy and with many people out due to holiday's coming. I just wanted to let you know that this is still in our backlog, and we will let you know once we have found some solution.

[WeibinDai]

I have the same confusion for this issue. Can anyone help us so far? thanks.

[jsalas98]

Sorry I had to put this on hold for a bit, I'm back to debugging.

[jsalas98]

Hi @mariannasb and @WeibinDai ,

After a big debugging process we got to the conclusion that this issue is related to the handling of latency queries in the pipeline. In our test case the pipeline works without interpipes because the audiosrc reports through queries some latency (10ms) and then the mixers add some extra latency (another 10ms) on top of that to set a minimum time to wait for a buffer before marking it as GAP. However, interpipe currently does not support forwarding queries, so when we add interpipe the first 10ms that the audiosrc reported don't go across the interpipesrc branch, therefore the audiomixer does not wait enough time for the buffer to remove the GAP flag and the audiosink drops it.

This should be fixed by adding the queries forwarding support, however we don't have an estimate right now of when it will be able. In the meantime, you can make the pipeline work by compensating the latency that got lost in the interpipesink by tuning the latency property of the mixers. For example, in our case we know that the audiosrc was adding 10ms, so to compensate them we modified the pipeline audiomixers to wait 10 additional milliseconds:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=audioconvert)" gst-launch-1.0 autoaudiosrc is-live=true provide-clock=false ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! interpipesink name=audio_src sync=false async=false interpipesrc listen-to=audio_src is-live=true stream-sync=passthrough-ts format=time ! deinterleave name=d d.src_0 ! tee name=ch0_audio d.src_1 ! tee name=ch1_audio interleave name=ilv ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! queue ! audioconvert ! autoaudiosink audiomixer start-time-selection=zero name=leftamix sink_0::volume=0 sink_1::volume=0 latency=10000000 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x1" ! queue ! ilv.sink_0 audiomixer start-time-selection=zero name=rightamix sink_0::volume=1 sink_1::volume=1 latency=10000000 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x2" ! queue ! ilv.sink_1 ch0_audio. ! queue ! leftamix. ch0_audio. ! queue ! rightamix. ch1_audio. ! queue ! leftamix. ch1_audio. ! queue ! rightamix.

With that pipeline you will see that the buffers in the tracer log don't have the GAP flag anymore and there is output sound.

[mariannasb]

Thank you for the information and the temporary workaround.

But for completeness, could you also add the debugging options you used in order to measure the 10ms latency? So that it will be possible to easily adapt this to different pipelines?

[jsalas98]

@mariannasb Sure, you can check the minimum latency value that gets configured with and without interpipes by setting the aggregator debug to level 5 and filtering the output to discard other debug messages. For example:

GST_DEBUG="*:3,GST_TRACER:7,aggregator:5" GST_TRACERS="buffer(filter=audioconvert)" gst-launch-1.0 autoaudiosrc is-live=true provide-clock=false ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! interpipesink name=audio_src sync=false async=false interpipesrc listen-to=audio_src is-live=true stream-sync=passthrough-ts format=time ! deinterleave name=d d.src_0 ! tee name=ch0_audio d.src_1 ! tee name=ch1_audio interleave name=ilv ! "audio/x-raw,format=S32LE,layout=interleaved,rate=44100,channels=2,channel-mask=(bitmask)0x3" ! queue ! audioconvert ! autoaudiosink audiomixer start-time-selection=zero name=leftamix sink_0::volume=0 sink_1::volume=0 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x1" ! queue ! ilv.sink_0 audiomixer start-time-selection=zero name=rightamix sink_0::volume=1 sink_1::volume=1 ! "audio/x-raw,channels=1,channel-mask=(bitmask)0x2" ! queue ! ilv.sink_1 ch0_audio. ! queue ! leftamix. ch0_audio. ! queue ! rightamix. ch1_audio. ! queue ! leftamix. ch1_audio. ! queue ! rightamix. |& grep "configured latency"

This will show an output like this:

0:00:00.161304264 16790 0x7f4cb8003680 DEBUG             aggregator gstaggregator.c:1758:gst_aggregator_query_latency_unlocked:<leftamix> configured latency live:true min:10000000 max:1010000000
0:00:00.161366108 16790 0x7f4cb8003680 DEBUG             aggregator gstaggregator.c:1758:gst_aggregator_query_latency_unlocked:<rightamix> configured latency live:true min:10000000 max:1010000000

But if we remove the interpipes it shows this:

0:00:00.056765323 16970 0x7f4c60005540 DEBUG             aggregator gstaggregator.c:1758:gst_aggregator_query_latency_unlocked:<leftamix> configured latency live:true min:20000000 max:1210000000
0:00:00.056826212 16970 0x7f4c60005540 DEBUG             aggregator gstaggregator.c:1758:gst_aggregator_query_latency_unlocked:<rightamix> configured latency live:true min:20000000 max:1210000000

So that's where we see the difference of 10ms in the minimum latency value.