Pipeline freezing/hanging in "live source waiting for running state"

[jcazarin]

Hello!

We are writing a library that uses Gstreamer for a client

Our client wrote a test program to stress our library, and a bug was found,
which I am able to reproduce

The test program uses signal handlers to kill and restart the pipeline many
times in a loop

This works fine for a while, but at some point, after the pipeline is
killed, when the test program tries to start it again, it freezes. I've
enabled GST logs and I can see that the last message that is printed is:

*DEBUG basesrc gstbasesrc.c:513:gst_base_src_wait_playing_unlocked:<mysrc>
live source waiting for running state*

And by looking at the gstreamer source code this is a called in a function
that is indeed blocking until the state changes to PLAYING
(gst_base_src_wait_playing, on line 549 of 
https://github.com/GStreamer/gstreamer/blob/master/libs/gst/base/gstbasesrc.c
<https://github.com/GStreamer/gstreamer/blob/master/libs/gst/base/gstbasesrc.c> 
)

Does anyone have any ideia on what could be causing this?

I've quadruple checked the library code and there's nothing in it that could
hang. Also I was able to tell from the logs that this hanging happens
outside of any function in our library, so it happens sometime in between
calls to any code that is in our library

A snippet of the log with prints the "live source waiting for running state"
a couple times:

/0:00:35.618602753 12688 0xaaaae1192230 LOG                  basesrc
gstbasesrc.c:2842:gst_base_src_loop:<mysrc> next_ts 99:99:99.999999999 size
4096
0:00:35.618623128 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:513:gst_base_src_wait_playing_unlocked:<mysrc>* live source
waiting for running state*
0:00:35.935379468 12688 0xaaaae0f76c00 DEBUG              GST_EVENT
gstevent.c:308:gst_event_new_custom: creating new event 0xffff88006480 eos
28174
0:00:35.935451469 12688 0xaaaae0f76c00 DEBUG       GST_ELEMENT_PADS
gstelement.c:1851:gst_element_send_event: send eos event on element pipeline
0:00:35.935493095 12688 0xaaaae0f76c00 DEBUG                    bin
gstbin.c:3135:gst_bin_send_event:<pipeline> Sending eos event to src
children
0:00:35.935524096 12688 0xaaaae0f76c00 DEBUG             GST_STATES
gstbin.c:2032:bin_element_is_src:<pipeline> child appsink38 is not src
0:00:35.935548597 12688 0xaaaae0f76c00 DEBUG             GST_STATES
gstbin.c:2032:bin_element_is_src:<pipeline> child mysrc is src
0:00:35.935572097 12688 0xaaaae0f76c00 DEBUG       GST_ELEMENT_PADS
gstelement.c:1851:gst_element_send_event: send eos event on element mysrc
0:00:35.935600348 12688 0xaaaae0f76c00 DEBUG                basesrc
gstbasesrc.c:1801:gst_base_src_send_event:<mysrc> handling event
0xffff88006480 eos event: 0xffff88006480, time 99:99:99.999999999, seq-num
1765, (NULL)
0:00:35.935620474 12688 0xaaaae0f76c00 DEBUG                basesrc
gstbasesrc.c:3696:gst_base_src_set_flushing:<mysrc> flushing 1
0:00:35.935671475 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:515:gst_base_src_wait_playing_unlocked:<mysrc> live source
unlocked
0:00:35.935697975 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:526:gst_base_src_wait_playing_unlocked:<mysrc> we are flushing
0:00:35.935722601 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:2653:gst_base_src_get_range:<mysrc> wait_playing returned -2
(flushing)
0:00:35.935782852 12688 0xaaaae1192230 INFO                 basesrc
gstbasesrc.c:2853:gst_base_src_loop:<mysrc> pausing after
gst_base_src_get_range() = flushing
0:00:35.935804353 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:3025:gst_base_src_loop:<mysrc> pausing task, reason flushing
0:00:35.935822603 12688 0xaaaae1192230 DEBUG               GST_PADS
gstpad.c:6206:gst_pad_pause_task:<mysrc:src> pause task
0:00:35.935845354 12688 0xaaaae1192230 DEBUG                   task
gsttask.c:684:gst_task_set_state:<mysrc:src> Changing task 0xaaaae11a3710 to
state 2
0:00:35.935881230 12688 0xaaaae1192230 INFO                    task
gsttask.c:312:gst_task_func:<mysrc:src> Task going to paused
0:00:35.935895605 12688 0xaaaae0f76c00 DEBUG                basesrc
gstbasesrc.c:3696:gst_base_src_set_flushing:<mysrc> flushing 0
0:00:35.935923356 12688 0xaaaae0f76c00 DEBUG                basesrc
gstbasesrc.c:1884:gst_base_src_send_event:<mysrc> EOS marked, start task for
asynchronous handling
0:00:35.935943481 12688 0xaaaae0f76c00 DEBUG               GST_PADS
gstpad.c:6150:gst_pad_start_task:<mysrc:src> start task
0:00:35.935965607 12688 0xaaaae0f76c00 DEBUG                   task
gsttask.c:684:gst_task_set_state:<mysrc:src> Changing task 0xaaaae11a3710 to
state 0
0:00:35.935991233 12688 0xaaaae1192230 INFO                    task
gsttask.c:314:gst_task_func:<mysrc:src> Task resume from paused
0:00:35.935994858 12688 0xaaaae0f76c00 LOG                      bin
gstbin.c:3152:gst_bin_send_event:<mysrc> After handling eos event: 1
0:00:35.936037984 12688 0xaaaae1192230 LOG                  basesrc
gstbasesrc.c:2842:gst_base_src_loop:<mysrc> next_ts 99:99:99.999999999 size
4096
0:00:35.936050109 12688 0xaaaae0f76c00 DEBUG                    bin
gstbin.c:3175:gst_bin_send_event:<pipeline> Sending eos event to sink pads
0:00:35.936058359 12688 0xaaaae1192230 DEBUG                basesrc
gstbasesrc.c:513:gst_base_src_wait_playing_unlocked:<mysrc> *live source
waiting for running state*
0:00:36.576052446 12688 0xaaaae0f76c00 DEBUG              GST_EVENT
gstevent.c:308:gst_event_new_custom: creating new event 0xffff8801bc00 eos
28174/

Any help will be greatly appreciated, thank you!



--
Sent from: http://gstreamer-devel.966125.n4.nabble.com/