Flow of EOS

[Wes Miller]

This is a continuation of a previous question Change File Locations for Container Formats that Have Headers .

My pipeline has grown more complicated and I have a new quirk that needs to be solved.  So,

The Pipe:

   Reads from a live source.  Writes to a filesink and an appsink.


      souphttpsrc ->  multipartdemux ->  queue2   ->  tee  --,->  queue    -->  matroskamux  --> filesink
                                                          name=q0                |   name=q1
                                                                                        |
                                                                                        '->  queue   --> appsink
                                                                                            name=q2         :
                                                                                                                   :.... (appsink handler)

The appsink handler is essentially:

     while ( true )
          while ( appsink is not EOS )
               sip from stream
               print "tick" every 25th pass
          end while
    end while


Expected Operation:

     Every 4 seconds a timer tells the src pad of q0 to block.
     Q0Blocked callback sends EOS to sinkpads of q1 and q2.
     EOS passes down both legs of the pipe
     Either or both of filesink and appsink post EOS to bus
     bus_callback
       -  sets all elements from tee to appsink and to filesink to GST_STATE_NULL
       -  change output file location of the filesink
       -  sends unblock to src pad of q0
     Q0UnBlocked handler
       -  sets all elements from tee to appsink and to filesink to GST_STATE_PLAYING
     Operation iterates.

Well, of course, this isn't what happens

  -  Eveerything goes as expected through the first pass.
  -  Debug confirms that both sinks go to EOS
  -  The bus_callback is called.  
        -  EOS is detected.  
        -  filesink set to GST_STATE_NULL - rc = 1
        -  Unblock goes to q0:src.
  -  Q0UnBlock is called-back.  
        -  Filesink set back to GST_STATE_PLAYING
        -  Printf's show all elements are in PLAYING state,
        -  filesink is async waiting
  -  Debug output says src is getting and passing data to demux and then to q0.  
  -  Finally, At the end of the second buffer we see this:

     basesrc gstbasesrc.c:2473:gst_base_src_loop:            <my_src> pausing task, reason unexpected
    GST_PADS gstpad.c:5250:gst_pad_pause_task:           <my_src:src> pause task
        task gsttask.c:608:gst_task_set_state:<task3> Changing task 0xa2069d0 to state 2
   GST_EVENT gstevent.c:269:gst_event_new: creating new event 0xa159450 eos 86
   GST_EVENT gstpad.c:5020:gst_pad_send_event:         <my_demux:sink> have event type eos
    GST_PADS gstpad.c:3517:gst_pad_event_default:       <my_demux:sink> pausing task because of eos
    GST_PADS gstpad.c:5250:gst_pad_pause_task:          <my_demux:sink> pause task
    GST_PADS gstpad.c:5268:gst_pad_pause_task:          <my_demux:sink> pad has no task
    GST_PADS gstpad.c:3417:gst_pad_event_default_dispatch:        <my_demux:sink> Sending event 0xa159450 (eos) to all internally linked pads
    GST_PADS gstpad.c:3213:gst_pad_iterate_internal_links_default:<my_demux:sink> Making iterator
   GST_EVENT gstpad.c:5020:gst_pad_send_event:<capsfilter0:sink> have event type eos
   GST_EVENT gstpad.c:5020:gst_pad_send_event:       <my_queue0:sink> have event type eos
    GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue0:sink> sent event, result 1
    GST_PADS gstpad.c:5048:gst_pad_send_event:<capsfilter0:sink> sent event, result 1
    GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_demux:sink> sent event, result 1

Many, many of these lines:
     appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we are EOS and the queue is empty

   GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_tee:sink> have event type eos
    GST_PADS gstpad.c:3517:gst_pad_event_default:    <my_tee:sink> pausing task because of eos
    GST_PADS gstpad.c:5250:gst_pad_pause_task:       <my_tee:sink> pause task
    GST_PADS gstpad.c:5268:gst_pad_pause_task:       <my_tee:sink> pad has no task
    GST_PADS gstpad.c:3417:gst_pad_event_default_dispatch:        <my_tee:sink> Sending event 0xa159450 (eos) to all internally linked pads
    GST_PADS gstpad.c:3213:gst_pad_iterate_internal_links_default:<my_tee:sink> Making iterator
   GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_queue2:sink> have event type eos
      queue2 gstqueue2.c:1304:gst_queue2_handle_sink_event:       <my_queue2> refusing event, we are flushing
    GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue2:sink> sent event, result 0
   GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_queue1:sink> have event type eos
      queue2 gstqueue2.c:1304:gst_queue2_handle_sink_event:       <my_queue1> refusing event, we are flushing
    GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue1:sink> sent event, result 0
    GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_tee:sink> sent event, result 0
    GST_PADS gstpad.c:5250:gst_pad_pause_task:       <my_queue0:src> pause task
        task gsttask.c:608:gst_task_set_state:<task2> Changing task 0xa206948 to state 2
     appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we are EOS and the queue is empty

And THOUSANDS of these lines...
     appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we are EOS and the queue is empty
     appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we are EOS and the queue is empty


Any help greatly appreciated.

Wes


   

[Wes Miller]

Found a bit more information.


Sometime between the time I enter the callback from

     gst_pad_set_blocked_async( q0_srcpad, false, Q0UnBlocked, NULL );

and setting all the elements to GST_STATE_PLAYING,  I get these two messages:

       bin gstbin.c:894:bin_replace_message:<my_pipe> got new message 0x95acb20, async-start from my_sink
       GST_STATES gstbin.c:2746:bin_handle_async_start:<my_pipe> lost state of PLAYING, new PAUSED

I am suspecting this is important.  

I'm pretty sure the async_start is from the filesink changing back to PLAYING state.  Why should that cause my_src to loose it's playing state?


I switched over to using the blocking form of gst_pad_set_blocked_async().  It let's me go until the pipeline fails to PLAY.

Thanks for whatever help you can offer,

Wes

[Wes Miller]

One last plea for help before I just give up.

Thanks in advance,

Wes

[Robert Powell-2]

Hi Wes,

I've been dealing with a similar problem. I'll drop you a note when/if I make any progress.

Rob
Sent from my *Phone

On Jul 26, 2010, at 5:17 PM, Wes Miller <[hidden email]> wrote:

>
> One last plea for help before I just give up.
>
> Thanks in advance,
>
> Wes
> --
> View this message in context: http://gstreamer-devel.966125.n4.nabble.com/Flow-of-EOS-tp2291933p2302470.html
> Sent from the GStreamer-devel mailing list archive at Nabble.com.
>
> ------------------------------------------------------------------------------
> The Palm PDK Hot Apps Program offers developers who use the
> Plug-In Development Kit to bring their C/C++ apps to Palm for a share
> of $1 Million in cash or HP Products. Visit us here for more details:
> http://ad.doubleclick.net/clk;226879339;13503038;l?
> http://clk.atdmt.com/CRS/go/247765532/direct/01/
> _______________________________________________
> gstreamer-devel mailing list
> [hidden email]
> https://lists.sourceforge.net/lists/listinfo/gstreamer-devel

------------------------------------------------------------------------------
The Palm PDK Hot Apps Program offers developers who use the
Plug-In Development Kit to bring their C/C++ apps to Palm for a share
of $1 Million in cash or HP Products. Visit us here for more details:
http://ad.doubleclick.net/clk;226879339;13503038;l?
http://clk.atdmt.com/CRS/go/247765532/direct/01/
_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/gstreamer-devel

[Arnout Vandecappelle]

 Hoi Wes,

 I can't say I know what the problem is exactly, but wouldn't it be
safer/easier to just destroy the existing elements and create new ones?  One
particular advantage is that you can give the filesink the time to flush
while you continue streaming in a new file (this is particularly important
for large files, since the matroskamux will spend a lot of time writing the
index).  The disadvantage is that it's more work of course.

 By the way, why do you send EOS to the appsink and bring it down to NULL?  
I'd expect you could just leave it in PAUSED.  In that case, you don't need
to restart the appsink branch.

 Regards,
 Arnout


On Friday 16 July 2010 22:48:11, Wes Miller wrote:

> This is a continuation of a previous question
> http://gstreamer-devel.966125.n4.nabble.com/Change-File-Locations-for-Con
> tainer-Formats-that-Have-Headers-tp2283747p2283747.html Change File
> Locations for Container Formats that Have Headers  .
>
> My pipeline has grown more complicated and I have a new quirk that needs
> to be solved.  So,
>
> The Pipe:
>
>    Reads from a live source.  Writes to a filesink and an appsink.
>
>
>       souphttpsrc ->  multipartdemux ->  queue2   ->  tee  --,->  queue
> -->  matroskamux  --> filesink
>                                                           name=q0
>
> |   name=q1
>
> '->  queue   --> appsink
>
> name=q2         :
> :.... (appsink handler)
>
> The appsink handler is essentially:
>
>      while ( true )
>           while ( appsink is not EOS )
>                sip from stream
>                print "tick" every 25th pass
>           end while
>     end while
>
>
> Expected Operation:
>
>      Every 4 seconds a timer tells the src pad of q0 to block.
>      Q0Blocked callback sends EOS to sinkpads of q1 and q2.
>      EOS passes down both legs of the pipe
>      Either or both of filesink and appsink post EOS to bus
>      bus_callback
>        -  sets all elements from tee to appsink and to filesink to
> GST_STATE_NULL
>        -  change output file location of the filesink
>        -  sends unblock to src pad of q0
>      Q0UnBlocked handler
>        -  sets all elements from tee to appsink and to filesink to
> GST_STATE_PLAYING
>      Operation iterates.
>
> Well, of course, this isn't what happens
>
>   -  Eveerything goes as expected through the first pass.
>   -  Debug confirms that both sinks go to EOS
>   -  The bus_callback is called.
>         -  EOS is detected.
>         -  filesink set to GST_STATE_NULL - rc = 1
>         -  Unblock goes to q0:src.
>   -  Q0UnBlock is called-back.
>         -  Filesink set back to GST_STATE_PLAYING
>         -  Printf's show all elements are in PLAYING state,
>         -  filesink is async waiting
>   -  Debug output says src is getting and passing data to demux and then
> to q0.
>   -  Finally, At the end of the second buffer we see this:
>
>      basesrc gstbasesrc.c:2473:gst_base_src_loop:            <my_src>
> pausing task, reason unexpected
>     GST_PADS gstpad.c:5250:gst_pad_pause_task:           <my_src:src>
> pause task
>         task gsttask.c:608:gst_task_set_state:<task3> Changing task
> 0xa2069d0 to state 2
>    GST_EVENT gstevent.c:269:gst_event_new: creating new event 0xa159450
> eos 86
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:         <my_demux:sink>
> have event type eos
>     GST_PADS gstpad.c:3517:gst_pad_event_default:       <my_demux:sink>
> pausing task because of eos
>     GST_PADS gstpad.c:5250:gst_pad_pause_task:          <my_demux:sink>
> pause task
>     GST_PADS gstpad.c:5268:gst_pad_pause_task:          <my_demux:sink>
> pad has no task
>     GST_PADS gstpad.c:3417:gst_pad_event_default_dispatch:
> <my_demux:sink> Sending event 0xa159450 (eos) to all internally linked
> pads GST_PADS
> gstpad.c:3213:gst_pad_iterate_internal_links_default:<my_demux:sink>
> Making iterator
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:<capsfilter0:sink> have
> event type eos
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:       <my_queue0:sink>
> have event type eos
>     GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue0:sink>
> sent event, result 1
>     GST_PADS gstpad.c:5048:gst_pad_send_event:<capsfilter0:sink> sent
> event, result 1
>     GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_demux:sink> sent
> event, result 1
>
> Many, many of these lines:
>      appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we
> are EOS and the queue is empty
>
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_tee:sink> have
> event type eos
>     GST_PADS gstpad.c:3517:gst_pad_event_default:    <my_tee:sink>
> pausing task because of eos
>     GST_PADS gstpad.c:5250:gst_pad_pause_task:       <my_tee:sink> pause
> task
>     GST_PADS gstpad.c:5268:gst_pad_pause_task:       <my_tee:sink> pad
> has no task
>     GST_PADS gstpad.c:3417:gst_pad_event_default_dispatch:
> <my_tee:sink> Sending event 0xa159450 (eos) to all internally linked pads
>     GST_PADS
> gstpad.c:3213:gst_pad_iterate_internal_links_default:<my_tee:sink> Making
> iterator
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_queue2:sink> have
> event type eos
>       queue2 gstqueue2.c:1304:gst_queue2_handle_sink_event:
> <my_queue2> refusing event, we are flushing
>     GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue2:sink>
> sent event, result 0
>    GST_EVENT gstpad.c:5020:gst_pad_send_event:      <my_queue1:sink> have
> event type eos
>       queue2 gstqueue2.c:1304:gst_queue2_handle_sink_event:
> <my_queue1> refusing event, we are flushing
>     GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_queue1:sink>
> sent event, result 0
>     GST_PADS gstpad.c:5048:gst_pad_send_event:       <my_tee:sink> sent
> event, result 0
>     GST_PADS gstpad.c:5250:gst_pad_pause_task:       <my_queue0:src>
> pause task
>         task gsttask.c:608:gst_task_set_state:<task2> Changing task
> 0xa206948 to state 2
>      appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we
> are EOS and the queue is empty
>
> And THOUSANDS of these lines...
>      appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we
> are EOS and the queue is empty
>      appsink gstappsink.c:976:gst_app_sink_is_eos:      <my_appsink> we
> are EOS and the queue is empty
>
>
> Any help greatly appreciated.
>
> Wes

--
Arnout Vandecappelle                               arnout at mind be
Senior Embedded Software Architect                 [phone]
Essensium/Mind                                     http://www.mind.be
G.Geenslaan 9, 3001 Leuven, Belgium                BE 872 984 063 RPR Leuven
LinkedIn profile: http://www.linkedin.com/in/arnoutvandecappelle
GPG fingerprint:  31BB CF53 8660 6F88 345D  54CC A836 5879 20D7 CF43

------------------------------------------------------------------------------
The Palm PDK Hot Apps Program offers developers who use the
Plug-In Development Kit to bring their C/C++ apps to Palm for a share
of $1 Million in cash or HP Products. Visit us here for more details:
http://p.sf.net/sfu/dev2dev-palm
_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/gstreamer-devel

[Wes Miller]

In my real application the appsink is pulling info out of the metadata dn storing it into a sidecar file, matched by timestamp, to the recorded video.  This allows me to match the video to external events later and doesn't require any kind of embedding that could get lost or corrupted as I massage, shrink, convert and compress  the video.  I need to let appsink know to change output files as well as the filesink.

I had been tearing down and recreating the pipe for each new timeslot.  Didn't think to actually build two pipes and switch one off when the other picks up.  Might give that a try.

On the bad side, I have tried just sending the EOS to filesink by injecting it below the tee.  Somehow, I know not how, it magically gets to the appsink leg anyway.  Sigh.  I even tri3ed turning the bus message into a signal and only catching the filesink signal.  Didn't help.  Sigh, squared.

Thanks much!

Wes