<div dir="ltr">Sebastian helped me through this on IRC earlier today. Here's the gist for anyone who might be following along from home:<div><br></div><div> * when the pipeline is reconfigured, the source initiates caps negotiation</div>
<div> * part of this negotiation involves sending an allocation query</div><div> * the query is serialized, meaning it travels through the pipeline in the same stream as buffers</div><div> * the source that initiated the query blocks until it receives a response to its allocation query, but since my app blocks buffers before the query reaches its destination (the sink?), the source blocks indefinitely</div>
<div><br></div><div>Sebastian's idea was to use a probe to catch and drop the allocation query. I found that this worked perfectly, but was surprised by the necessary location of the probe: adding the probe to drop the allocation query on the video source's srcpad prevented the videosource itself from blocking, but the video <i>encoder</i> just downstream of it (with a queue between, of course) continued to block. I found that if I moved the probe to the video encoder's source that both elements continue to run fine through the caps negotiation process even when the pipeline is blocked downstream.</div>
<div><br></div><div>I don't really understand the relationship between the caps query and the allocation query, but I'm guessing that the video encoder is generating an allocation query in response to having received the caps query. So the important part is to catch and drop the allocation query as far downstream as possible, but upstream of the place where the pipeline is blocked.</div>
<div><br></div><div>-Todd</div><div><br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Tue, Jan 7, 2014 at 2:17 PM, Todd Agulnick <span dir="ltr"><<a href="mailto:todd@agulnick.com" target="_blank">todd@agulnick.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">I'm getting a bit closer; still hoping that something I'm seeing here makes sense to somebody else.<div>
<br></div><div>I've got data flowing through my pipeline up to a blocked srcpad on a leaky queue. Then a request comes in and I:</div>
<div><br></div><div> 1. create a new bin with a mux and filesink, link it to the queue</div><div> 2. remove the blocking probe on the queue srcpad; data starts to flow into the mux and filesink</div><div> 3. meanwhile (I think) the addition of the mux and the filesink have triggered allocation strategy negotiations in the pipeline</div>
<div> 4. the mux and filesink drain some of the data from queue, then block the queue's srcpad again</div><div> 5. the mux and the filesink get eos, and are dropped</div><div> 6. the negotiation started in step (3) above hangs; both upstream threads make similar last utterances here:</div>
<div><br></div><div><div>0:00:23.211310000 31628 0x7f9ac090d400 LOG queue gstqueue.c:860:gboolean gst_queue_handle_sink_query(GstPad *, GstObject *, GstQuery *):<ringbuffer-queue> queuing query 0x7f9ac28000f0 (allocation)</div>
</div><div><div>0:00:23.223470000 31628 0x7f9ac08f2140 LOG queue gstqueue.c:860:gboolean gst_queue_handle_sink_query(GstPad *, GstObject *, GstQuery *):<upstream-queue> queuing query 0x7f9ac10018a0 (allocation)</div>
</div><div><br></div><div>Is this happening because the mux and filesink aren't around long enough for the allocation strategy negotiation to complete?</div><div><br></div><div>As always, I'd really appreciate any guidance you can offer.</div>
<span class="HOEnZb"><font color="#888888">
<div><br></div><div>-Todd</div><div><br></div><div><br></div></font></span></div><div class="HOEnZb"><div class="h5"><div class="gmail_extra"><br><br><div class="gmail_quote">On Mon, Jan 6, 2014 at 8:40 PM, Todd Agulnick <span dir="ltr"><<a href="mailto:todd@agulnick.com" target="_blank">todd@agulnick.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">Well, it looks like I was wrong again -- it's becoming a bad habit.<div><br></div><div>My new theory is that there is a race condition that is exposed by the rapid unblocking and re-blocking of the source pad on my queue. There are three threads in my pipeline: A manages the video source, B manages the x264enc, and C manages the mux and sink. The probes are inserted at the boundary between B and C but run entirely within thread C.</div>
<div><br></div><div>There are two scenarios. In the scenario that works, the blocking probe is removed, the queue is drained, but more data is needed than is available in the queue, so the whole pipeline keeps chugging along until all the data required has passed through the mux. When all the data required passes through the mux, the blocking probe is reinstated, and threads A & B continue dumping data into the queue whose sink runs in thread B.</div>
<div><br></div><div>In the other scenario, the blocking probe is removed from the queue, and the entirety of the data request is serviced by the data available in the queue. In this case, the blocking probe is re-instated essentially instantaneously. And when this happens, threads A & B seem to stall. They can be made to start up again by removing the blocking probe again. </div>
<div><br></div><div>The smoking gun here is when I run with GST_DEBUG=GST_SCHEDULING, these are the last log items I see for elements in threads A & B:</div><div><br></div><div><div>0:00:21.803462000 16032 0x7ffdfb0f2140 LOG GST_SCHEDULING gstpad.c:3762:GstFlowReturn gst_pad_chain_data_unchecked(GstPad *, GstPadProbeType, void *):<upstream-queue:sink> called chainfunction &gst_queue_chain with buffer 0x7ffdff042ea0, returned ok</div>
<div>0:00:21.803472000 16032 0x7ffdfb0f2140 LOG GST_SCHEDULING gstpad.c:3762:GstFlowReturn gst_pad_chain_data_unchecked(GstPad *, GstPadProbeType, void *):<video-convert:sink> called chainfunction &gst_base_transform_chain with buffer 0x7ffdff042ea0, returned ok</div>
<div>0:00:21.803480000 16032 0x7ffdfb0f2140 LOG GST_SCHEDULING gstpad.c:3762:GstFlowReturn gst_pad_chain_data_unchecked(GstPad *, GstPadProbeType, void *):<caps-filter:sink> called chainfunction &gst_base_transform_chain with buffer 0x7ffdff042ea0, returned ok</div>
<div>0:00:21.803502000 16032 0x7ffdfb10d400 LOG GST_SCHEDULING gstpad.c:3756:GstFlowReturn gst_pad_chain_data_unchecked(GstPad *, GstPadProbeType, void *):<video-encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7ffdff042ea0, pts 0:00:21.745581333, dts 0:00:21.745581333, dur 0:00:00.033333333, size 3110400, offset 652, offset_end 653, flags 0x0</div>
</div><div><br></div><div><br></div><div>After that, it's complete silence from these elements until I unblock my queue in thread C. The last line above, in particular, is worrisome, as it looks like we call the video encoder but it never returns!</div>
<div><br></div><div>I'd really appreciate any advice about how to go about tracking this down. I don't really understand how the activity in thread C could block threads A & B, which is what seems to be happening.</div>
<span><font color="#888888">
<div><br></div><div>-Todd</div><div><br></div><div><br></div></font></span></div><div><div><div class="gmail_extra"><br><br><div class="gmail_quote">On Mon, Jan 6, 2014 at 3:25 PM, Todd Agulnick <span dir="ltr"><<a href="mailto:todd@agulnick.com" target="_blank">todd@agulnick.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">I have this nearly working now (see below for the remaining puzzle) and wanted to send my thanks to Sebastian, Tim, and Pedro for helping to steer me in the right direction. I really appreciate your guidance.<div>
<br></div><div>Here's my setup. It's similar to Pedro's.</div><div><br></div><div>videotestsrc is-live=true ! capsfilter ! videorate ! videoconvert ! x264enc ! queue leaky=downstream max-size-bytes=500MB max-size-buffers=0 max-size-time=0 ! bin, where bin is disposed and recreated for each request and contains mp4mux ! filesink.</div>
<div><br></div><div>I've got this rigged up inside a server that listens on a socket for incoming requests which identify a desired time-based segment of the video stream. In the quiescent state, there's a blocking probe on the leaky queue's source pad, so data flows all the way into that queue and then, once the queue is full, old data is dropped.</div>
<div><br></div><div>When a request comes in, I install a new (non-blocking) probe and remove the existing blocking probe. Data starts to flow through the leaky queue, and the new probe's callback inspects the PTS on each video frame, waiting first for a keyframe that's within the requested window (at which point it stops dropping frames and instead starts passing them to the mux and sink), and then for a video frame that is beyond the requested window, at which point it sends an EOS through the bin to finalize the file; when the EOS appears on the application bus, the app removes the non-blocking probe, re-instates the blocking probe, NULLs the bin, removes the bin, and then sends the result back to the client through the socket and awaits the next request.</div>
<div><br></div><div>All of this works like a charm, EXCEPT for the following observed behavior: when I reinstate the blocking probe on the queue's source pad, if there is any data in the queue, data stops flowing into the queue. Indeed, the whole pipeline goes eerily quiet. If, however, the request ends up draining the queue completely, when I reinstate the blocking probe data continues to flow into and build up inside the queue.</div>
<div><br></div><div>I'm about to dig into the queue code to see if I can understand why that might be happening, but I thought I would ping the experts first to see if this rings a bell.</div><span><font color="#888888"><div>
<br></div><div>-Todd</div>
<div><br></div></font></span></div><div><div><div class="gmail_extra"><br><br><div class="gmail_quote">On Wed, Jan 1, 2014 at 1:39 PM, Todd Agulnick <span dir="ltr"><<a href="mailto:todd@agulnick.com" target="_blank">todd@agulnick.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><br><div class="gmail_extra"><br><br><div class="gmail_quote"><div>On Wed, Jan 1, 2014 at 4:23 AM, Sebastian Dröge <span dir="ltr"><<a href="mailto:sebastian@centricular.com" target="_blank">sebastian@centricular.com</a>></span> wrote:<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div>
<br>
</div>You should be able to drop the message from the sync bus handler of the<br>
bin too, to prevent it going up in the pipeline hierarchy.<br></blockquote><div><br></div></div><div>Just to follow up with a conversation that took place on IRC just now:</div><div><br></div><div>You can't do this because the GstBin already has a sync bus handler, and there can be only one. We talked about possible modifications to GstBin to support the desired behavior (bug filed here: <a href="https://bugzilla.gnome.org/show_bug.cgi?id=721310" target="_blank">https://bugzilla.gnome.org/show_bug.cgi?id=721310</a>), but for now as a work-around we're going to catch the EOS just upstream of the filesink to see if that works.</div>
<div> <br></div></div></div></div>
</blockquote></div><br></div>
</div></div></blockquote></div><br></div>
</div></div></blockquote></div><br></div>
</div></div></blockquote></div><br></div>