GNOME Bugzilla – Bug 635226
[PATCH] gdppay fails to sync if added to pipeline during playback
Last modified: 2010-12-13 15:45:33 UTC
Created attachment 174809 [details] Source code of test example gdppay suffers strange problems with timestamping and syncronization if it is added to the pipeline after playback was started. Here's my case to reproduce the bug. The pipeline queue -- xvimagesink / playbin -- tee \ queue -- valve -- fakesink is dynamically transformed to queue -- xvimagesink / playbin -- tee \ queue -- valve -- gdppay -- filesink on the far end there's gst-launch command: gst-launch -vv -m filesrc location=test.gdp ! queue ! gdpdepay ! decodebin ! ffmpegcolorspace ! timeoverlay valign=bottom ! ximagesink (see also source code in the attachment) Everything is OK until the pipeline was modificated to the 2nd state. The main branch (without gdp part) continues playing while the secondary branch freezes and then plays small amount of rare frames with delays etc. The following message is printed on the console: 0:00:07.134552825 19490 0x95be9c8 WARN gdppay gstgdppay.c:594:gst_gdp_pay_chain:<gdppay0> did not receive new-segment before first buffer As shown with timeoverlay clocktime of the secondary branch is very discrete. Detailed experiments of some other elements for the secondary branch (ximagesink, combination of jpegenc and avimux instead of gdppay) show that these elements don't suffer such a problem. So it seems to be some timestamping fault in gdppay/gdpdepay which leads to this strange bug.
I've worked on this problem and found that possible cause is timestamping in gdpdepay element. It actually just restores full buffer i.e. timestamp of each depayed buffer is as it was in primary pipeline. But buffers go through another pipeline (containing gdpdepay) with some "wild" timestamps and so this pipeline is stalled. I've made little patch which sets timestamps using to GstAdapter's information. But it requires that input buffers are with proper timestamps (e.g. for filesrc do-timestamps should be 'true'). According to test results it fixes the problem and even synchronization between pipelines persists.
Created attachment 175395 [details] [review] Small patch that fixes the problem
Well... any reaction? This patch works at least for me quite right
This doesn't look correct to me. The buffer should already have the timestamp from the GDP header from gst_dp_buffer_from_header() Your patch would always override the buffers from the header with some random timestamp from the adapter. The problem you have is caused by the fact that you drop every event and buffer and everything before linking in gdppay, including the newsegment events. This is the reason why everything fails and also why it works if you take the adapter timestamps (which should be -1) because then no synchronization or anything will happen. You should keep track of the segment configuration and then send a valid newsegment event into gdppay after linking before it gets any buffers.
Well, the first thing I should say is it's bug anyway because that's the exact situation which I try to solve using documented functions and it doesn't work. As to dropping events and buffers - I tried not only to drop but also to block the queue. This way no buffers and events are dropped. But nothing was changed. In my description I pointed that in order to make gdpdepay with my patch working correctly you need to switch on the do-timestamp property on filesrc. In this case adapter timestamps stop to be -1 and are the timestamps when the undepayed buffer was created. Next, let's look at gst_dp_buffer_from_header(). It's part concerning buffer timestamp is this: GST_BUFFER_TIMESTAMP (buffer) = GST_DP_HEADER_TIMESTAMP (header); And GST_DP_HEADER_TIMESTAMP marco is #define GST_DP_HEADER_TIMESTAMP(x) GST_READ_UINT64_BE (x + 10) And what is written in (x + 10) address during paying? Let's see dataprotocol.c:147 and it's: GST_WRITE_UINT64_BE (h + 10, GST_BUFFER_TIMESTAMP (buffer)); It is the remote pipeline's timestamp. So no timestamp management is done on gdpdepay's side and we have depayed buffers with some wild timestamps. I can't find any way to keep track new-segment of the pipeline and then push it to element, I tried to do it using seeking whole pipeline but I think it should be done somewhere not in user's code but somewhere inside elements which are connected during playback.
Yeah, for 0.10.31 is still there.
Well, the point is that you need to do a lot of manual work if you're dynamically changing pipelines, especially when changing sources or sinks. What you need to do here is to make sure that gdppay gets a valid newsegment event before any buffers and then the buffers have timestamps that make sense with the segment configured by the event. But this really is not bug... although it will be much simpler to do things like this in 0.11. Essentially what you need to do is to install an event probe and buffer probe before the valve element, keep track of the currently configured segment and the timestamps and at the point when you replace valve by gdppay you have to send a newsegment event to gdppay, that will map the next buffers timestamps to a running time of 0 (start and position of the newsegment event would be the timestamp of the next buffer then).
Well, it sounding like dynamic changes of pipeline is unsupported in GStreamer. Is it possible to change pipeline dynamically using documented API? If yes, why should I dive into internal GStreamer logic in my user code? Which is completely not obvious is why some of hidden logic (e.g. changing pipeline's state to PAUSED for change) is done automatically and much subtle things I should do manually. Well, I hope it's much improved in 0.11. We will see.. I agree that new segment can solve the problem, but how I can make the pipeline to generate proper new-segment event? To what element I should post this event, to gdppay alone or to the whole pipeline? I think the way you propose is as difficult to implement and debug that more right to say that this use case is impossible using GStreamer.
Alexey, some solutions are explained here: https://bugzilla.gnome.org/show_bug.cgi?id=561224 in my recorder I use a custom retimestamper plugin heavily inspered by resettime element
Thank you for this reference, Nicola. I looked through that report and found it very close to my case. Am I right that in your element, retimestamper, and in resettime element this problem is solved only using timestamps and without additional new-segment events?
Yes, that will work too in this case but only because elements assume a (0,-1,0) segment if no newsegment event was received yet. This will break in many scenarios and some elements give warnings if they get data before a newsegment event
Alexey, my retimestamper element send a newsegment event before reset the timestamp (I think resettime do this too) here is the relevant code: GstReTimeStamper *filter; filter = GST_RETIMESTAMPER(GST_OBJECT_PARENT(pad)); if (filter->silent == FALSE) { g_print("buffer timestamp: %-2.9f seconds\n", buf->timestamp / 1000000000.0); g_print("buffer offset: %ld\n", buf->offset); g_print("buffer duration: %-2.9f seconds\n", buf->duration / 1000000000.0); g_print("buffer size: %d \n", buf->size); g_print("filter offset: %-2.9f seconds\n", filter->time_offset / 1000000000.0); } if (filter->reset_timestamp == TRUE) { if (GST_CLOCK_TIME_IS_VALID(buf->timestamp)) { GstEvent *news; news = gst_event_new_new_segment(FALSE, 1.0, GST_FORMAT_TIME, 0, -1, buf->timestamp); gst_element_send_event(filter, news); filter->reset_timestamp = FALSE; filter->time_offset = buf->timestamp; filter->buf_offset = buf->offset; } else { g_print("INVALID buffer timestamp on reset: %-2.9f seconds\n", buf->timestamp / 1000000000.0); } } if (GST_CLOCK_TIME_IS_VALID(buf->timestamp)) { buf->timestamp -= filter->time_offset; if (filter->buf_offset > 0) { buf->offset -= filter->buf_offset; } if (filter->silent == FALSE) { g_print("buffer timestamp dopo reset: %-2.9f seconds\n", buf->timestamp / 1000000000.0); g_print("buffer offset dopo il reset: %ld\n", buf->offset); } } else { g_print("INVALID buffer timestamp: %-2.9f seconds\n", buf->timestamp / 1000000000.0); } return gst_pad_push(filter->srcpad, buf); hope it helps, Nicola
Yes, I saw assumption Sebastian mentioned in code and the warning was actually posted. I also tried to manually receive new-segment on the very beginning of the playback and then send it to newly connected gdppay element but without timestamp correction it seemed to have no effect. Thanks, Nicola, for this code snippet, it's becoming clearer to me. I didn't corrected the last segment parameter, new stream time, and also didn't changed timestamps on buffers so I think that's the reason why I couldn't get it work this way.