Problem when using x264enc + mpegtsmux

[mariannasb]

Consider the following pipeline which encodes to H264, muxes to MPEG-TS and the streams over UDP

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=bla)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0

Receive with : vlc rtp://@:7000 or

gst-launch-1.0 udpsrc port=7000 caps="application/x-rtp,media=(string)video,clock-rate=(int)90000,encoding-name=(string)MP2T-ES" ! rtpbin ! rtpmp2tdepay ! decodebin name=dec ! videoconvert ! ximagesink

Works fine

Now if I add interpipesrc/sink in between:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=bla)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! interpipesink name=video_out sync=false async=false interpipesrc name=mux_V listen-to=video_out is-live=true stream-sync=passthrough-ts format=time ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0

Doesn't work and I get a lot of complains about backwards DTS:
0:00:00.729042661 192147 0x56175b8f50c0 WARN basetsmux gstbasetsmux.c:1608:gst_base_ts_mux_clip:<mux:sink_0> ignoring DTS going backward

I believe it is somehow related to problems with handling the SEGMENT, since x264enc adds an 1000 hours offset and sends a new SEGMENT event.

If I refuse events it then works:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=avenc)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! interpipesink name=video_out sync=false async=false interpipesrc name=mux_V listen-to=video_out is-live=true stream-sync=passthrough-ts format=time accept-events=false ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0

But if I try to add audio it doesn't anymore:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=bla)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! interpipesink name=video_out sync=false async=false interpipesrc name=mux_V listen-to=video_out is-live=true stream-sync=passthrough-ts format=time accept-events=false ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0 autoaudiosrc ! interpipesink name=audio_out sync=false async=false interpipesrc name=mux_A listen-to=audio_out is-live=true stream-sync=passthrough-ts format=time ! audioconvert ! avenc_aac ! mux.

gst-launch-1.0 udpsrc port=7000 caps="application/x-rtp,media=(string)video,clock-rate=(int)90000,encoding-name=(string)MP2T-ES" ! rtpbin ! rtpmp2tdepay ! decodebin name=dec ! videoconvert ! ximagesink dec. ! audioconvert ! autoaudiosink

Which I guess is because the timestamps of audio and video are 1000 hours apart...

And if I then change the video interpipesrc to restart-ts I can get it working again:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=bla)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! interpipesink name=video_out sync=false async=false interpipesrc name=mux_V listen-to=video_out is-live=true stream-sync=restart-ts format=time accept-events=false ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0 autoaudiosrc ! interpipesink name=audio_out sync=false async=false interpipesrc name=mux_A listen-to=audio_out is-live=true stream-sync=passthrough-ts format=time ! audioconvert ! avenc_aac ! mux.

Note that the same pipeline (with audio) works without the interpipesrc/sinks:

GST_DEBUG="*:3,GST_TRACER:7" GST_TRACERS="buffer(filter=bla)" gst-launch-1.0 v4l2src ! videoconvert ! x264enc key-int-max=30 speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse ! mpegtsmux name=mux ! rtpmp2tpay ! udpsink port=7000 host=127.0.0.1 sync=0 autoaudiosrc ! audioconvert ! avenc_aac ! mux.

So, here there is no problem, even though the timestamp difference also exists here.

[mariannasb]

From what I can see the problem is that in the pipeline without the interpipe the mpegtsmux only receives 1 segment event, which comes from the encoder:

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: enc_out::src
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.699365496
Start: 3599999.699365496 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: mux_out::sink_0
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.699365496
Start: 3599999.699365496 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

But when I add the interpipe it gets 2 segment events, the 1st without the x264 offset and the 2nd with:

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: enc_out::src
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.699365496
Start: 3599999.699365496 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: mux_out::sink_0
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 0.0
Start: 0.0 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: mux_out::sink_0
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.699365496
Start: 3599999.699365496 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

And then the mpegtsmux starts its execution using the 1st segment, which gives a DTS of +1000:00:00, and later when it starts calculating the DTS with the new segment it gets smaller than the initial one and therefore keeps getting ignored...

[mariannasb]

I don't know if the problem is in the interpipesrc or the mpegtsmux, so I have also created this: https://gitlab.freedesktop.org/gstreamer/gst-plugins-bad/-/issues/1637

[mariannasb]

Reply from gstreamer community:

Pretty clearly that's a bug in the interpipe source element, if it outputs data with a different segment than when it arrived at the interpipe sink element.

[michaelgruner]

Hi @mariannasb thanks for your detailed report. Indeed it a problem with interpipes. The problem, as you described, is caused because, currently, the interpipesrc does not configure the segment from the interpipesink. This will cause problems when the timestamps come in a different time base, as with your x264enc.

The reason the x264enc uses timestamps starting on 1000 is to allow the encoder to add "negative" timestamps (B-frames may, for example, have such negative timestamps). To work this out, GStreamer configures configures the segment to start on that time, so everything works as it should. It only makes sense to continue using this same segment in the interpipesink.

Allow me coordinate this fix internally and assign someone to this.

[michaelgruner]

PR #97 is a potential fix for this report.

[mariannasb]

PR #97 is a potential fix for this report.

I have found out late Friday that event though PR #97 improves this problem it is unfortunately not a completely fix, it only shifts the problem.

With the fix I can see that mpegtsmux receives the segment from x264enc before receiving the 1st buffer, as it should.

However I can see that an extra segment (with a wrong position of 0) is still being generated, and coming afterwards.

I haven't succeeded in tracking where it is coming from, who is generating it and why (since there is already a proper segment).
Though it all points to the interpipesrc I can't find who is actually calling gst_event_new_segment(), if it is the interpipesrc itself, the underlying appsrc or another base class...

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: enc_out::src
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.705140042
Start: 3599999.705140042 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: mux_out::sink_0
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 3599999.705140042
Start: 3599999.705140042 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

Inspect Event: <enum GST_EVENT_SEGMENT of type Gst.EventType> pad: mux_out::sink_0
Segment: 
Base:0.0 Duration: 18446744073.709553 Format: <enum GST_FORMAT_TIME of type Gst.Format> Offset: 0.0 Position: 0.0
Start: 0.0 Stop: 18446744073.709553 Time: 0.0
to_running_time: 0

[mariannasb]

From what I could find it seems like the segment gets created by the basesrc because there seems to be a default seek in the initialization?

https://gitlab.freedesktop.org/gstreamer/gstreamer/-/blob/master/libs/gst/base/gstbasesrc.c#L1823

0:00:00.146469458 29690 0x7fb678204930 DEBUG                 appsrc gstappsrc.c:924:gst_app_src_start:<mux_V> starting
0:00:00.146503993 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:3586:gst_base_src_start_complete:<mux_V> starting source
0:00:00.146526604 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:3607:gst_base_src_start_complete:<mux_V> format: time, have size: 0, size: 18446744073709551615, duration: -1
0:00:00.146529520 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:3613:gst_base_src_start_complete:<mux_V> is seekable: 0
0:00:00.146532516 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:3618:gst_base_src_start_complete:<mux_V> is random_access: 0
0:00:00.146536288 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:1690:gst_base_src_perform_seek:<mux_V> doing seek: (NULL)
0:00:00.146539012 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:1746:gst_base_src_perform_seek:<mux_V> seek with seqnum 62
0:00:00.146564698 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:1781:gst_base_src_perform_seek:<mux_V> segment configured from 0 to -1, position 0
0:00:00.146592988 29690 0x7fb678204930 INFO                 basesrc gstbasesrc.c:1430:gst_base_src_do_seek:<mux_V> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.146906528 29690 0x7fb678204930 DEBUG                basesrc gstbasesrc.c:3723:gst_base_src_start_wait:<mux_V> got ok

Still no idea on how to "cancel" this segment since we got the proper one from x264enc