timestamp issues when using interpipe together with x264enc

See http://gstreamer-devel.966125.n4.nabble.com/1000-hours-offset-in-timestamp-of-h264-stream-td4697530.html

I have the following pipeline:

gst-launch-1.0 videotestsrc is-live=true pattern=ball !
video/x-raw,framerate=30/1,format=NV12 ! timeoverlay ! tee name=t ! queue !
videoconvert ! ximagesink sync=0 t. ! queue ! x264enc key-int-max=30
speed-preset=1 tune=zerolatency ! video/x-h264,profile=high ! h264parse !
queue ! interpipesink name=vtest1 sync=true async=false interpipesrc
listen-to=vtest1 name=vselect is-live=true stream-sync=passthrough-ts !
queue ! fakesink dump=1 sync=1  --gst-debug=*:3,*interpipe*:5

When sync=1 in the fakesink it doesn't dump any data, if I change to sync=0 it does.

If I remove the encoder (use RAW data) it dumps data for both cases. The same is true if I remove the interpipesrc/sink and just plug the fakesink directly into the x264enc.

Also if I use recorded h264 data from a multifilesrc, instead of having an encoder, it dumps data for both cases.

gst-launch-1.0 multifilesrc loop=1 name=replay location=/home/msb/test.ts !
identity sync=true ! tsdemux : identity sync=true ! h264parse ! queue !
interpipesink name=vreplay sync=false async=false interpipesrc
listen-to=vreplay is-live=true stream-sync=passthrough-ts ! fakesink dump=1
sync=1 --gst-debug=*:3,*interpipe*:5

The debug information from the interpipe elements reports timestamps with 1000 hours offset which I think is the cause of the problem:

0:00:01.714147464 1339403 0x55b0aa657520 INFO           interpipesink gstinterpipesink.c:542:gst_inter_pipe_sink_forward_event:<vtest1> Incoming serialized event tag
0:00:01.714232382 1339403 0x55b0aa657520 INFO           interpipesink gstinterpipesink.c:547:gst_inter_pipe_sink_forward_event:<vtest1> Event timestamp 1000:00:01.633333333
0:00:01.714275617 1339403 0x55b0aa657520 DEBUG           interpipesrc gstinterpipesrc.c:729:gst_inter_pipe_src_push_event:<vselect> Event tag with calculated timestamp 1000:00:01.633333333 enqueued on serial pending events
0:00:02.030453992 1339403 0x55b0aa657700 INFO           interpipesink gstinterpipesink.c:389:gst_inter_pipe_sink_intersect_listener_caps:<vtest1> Listener vselect caps: ANY
0:00:02.030554449 1339403 0x55b0aa657700 INFO           interpipesink gstinterpipesink.c:443:gst_inter_pipe_sink_get_caps:<vtest1> Caps negotiated: video/x-h264, profile=(string)high, framerate=(fraction)[ 0/1, 2147483647/1 ], width=(int)[ 1, 2147483647 ], height=(int)[ 1, 2147483647 ], parsed=(boolean)true, stream-format=(string){ avc, avc3, byte-stream },
alignment=(string){ au, nal }
0:00:02.047439856 1339403 0x55b0aa657520 INFO           interpipesink gstinterpipesink.c:542:gst_inter_pipe_sink_forward_event:<vtest1> Incoming serialized event tag
0:00:02.047497306 1339403 0x55b0aa657520 INFO           interpipesink gstinterpipesink.c:547:gst_inter_pipe_sink_forward_event:<vtest1> Event timestamp 1000:00:01.966666666
0:00:02.047530207 1339403 0x55b0aa657520 DEBUG           interpipesrc gstinterpipesrc.c:729:gst_inter_pipe_src_push_event:<vselect> Event tag with calculated timestamp 1000:00:01.966666666 enqueued on serial pending events

If I use RAW data the offset is not present, and if I use h264 encoded data coming from the multifilesrc the offset is not present either:

0:00:01.911863974 1339557 0x559c28433d20 DEBUG           interpipesrc gstinterpipesrc.c:481:gst_inter_pipe_src_create:<interpipesrc0> Got event with timestamp 0:00:01.258333333
0:00:01.911912193 1339557 0x559c28433d20 DEBUG           interpipesrc gstinterpipesrc.c:489:gst_inter_pipe_src_create:<interpipesrc0> Sending Serial Event tag
0:00:02.111425433 1339557 0x559c28433d80 INFO           interpipesink gstinterpipesink.c:542:gst_inter_pipe_sink_forward_event:<vreplay> Incoming serialized event tag
0:00:02.111489516 1339557 0x559c28433d80 INFO           interpipesink gstinterpipesink.c:547:gst_inter_pipe_sink_forward_event:<vreplay> Event timestamp 0:00:01.458333333
0:00:02.111523291 1339557 0x559c28433d80 DEBUG           interpipesrc gstinterpipesrc.c:729:gst_inter_pipe_src_push_event:<interpipesrc0> Event tag with calculated timestamp 0:00:01.458333333 enqueued on serial pending
events

The problem seems to be that the interpipe elements are not handling properly the timestamp offset caused by the encoder.

I can also see that if I add mpegtsmux ! tsdemux to the pipeline after the h264parse the offset seems to be removed by the mux and things then work as expected.

And this is how mpegtsmux does it:

0:00:03.550340073 600306 0x564a3d45b990 LOG                basetsmux gstbasetsmux.c:1578:gst_base_ts_mux_clip:<mpegtsmux0:sink_0> buffer pts 1000:00:02.633333333 ->  0:00:02.647277730 running time
0:00:03.550395376 600306 0x564a3d45b990 LOG                basetsmux gstbasetsmux.c:1602:gst_base_ts_mux_clip:<mpegtsmux0:sink_0> buffer dts 1000:00:02.633333333 -> +0:00:02.647277730 running time
0:00:03.550425254 600306 0x564a3d45b990 DEBUG              basetsmux gstbasetsmux.c:1676:gst_base_ts_mux_find_best_pad:<mpegtsmux0> Best pad found with 0:00:02.647277730: <mpegtsmux0:sink_0>
0:00:03.550450924 600306 0x564a3d45b990 DEBUG              basetsmux gstbasetsmux.c:1094:gst_base_ts_mux_aggregate_buffer:<mpegtsmux0> Pads collected
0:00:03.550471499 600306 0x564a3d45b990 DEBUG              basetsmux gstbasetsmux.c:1187:gst_base_ts_mux_aggregate_buffer:<mpegtsmux0:sink_0> Chose stream for output (PID: 0x0041)
0:00:03.550498231 600306 0x564a3d45b990 DEBUG              basetsmux gstbasetsmux.c:1201:gst_base_ts_mux_aggregate_buffer:<mpegtsmux0> Buffer has PTS  0:00:02.647277730 pts 238254

https://gitlab.freedesktop.org/gstreamer/gst-plugins-bad/-/blob/master/gst/mpegtsmux/gstbasetsmux.c#L1618

time = gst_segment_to_running_time (&agg_pad->segment, GST_FORMAT_TIME, time);

And the answer I got from Gstreamer:

I'm guessing that interpipesink element, from RidgeRun do not handle the GstSegment properly. It's been over 4 years now that x264enc add 1 day to the timestamp in order to support negative DTS. The offset is balanced through the GstSegment. Ignoring the segment is a bug, timestamp have no meaning without their segment.

Please report to RidgeRun github.

RidgeRun / gst-interpipe

timestamp issues when using interpipe together with x264enc #89