pipeline state change returns ASYNC but never completes

[Anssi Hannula]

Hi!

While debugging some KDE code which uses GStreamer via Phonon, I noticed
that when at one point the code asks the pipeline to go from READY to
PAUSED, the state change will be performed asynchronously but the
transition never completes.

Specifically, judging from the debug output it seems the issue happens
when gst tries to change the state of "fakesink"
(pipeline0->bin0->fakesink0); it returns ASYNC but is never heard from
again:

> 0:00:05.233369519 16879      0x21c2c00 DEBUG             GST_STATES gstbin.c:2409:gst_bin_change_state_func:<bin0> changing state of children from READY to PAUSED
> 0:00:05.233400889 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2595:gst_element_set_state_func:<fakesink0> set_state to PAUSED
> 0:00:05.233413377 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2620:gst_element_set_state_func:<fakesink0> setting target state to PAUSED
> 0:00:05.233424935 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2633:gst_element_set_state_func:<fakesink0> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
> 0:00:05.233437822 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2667:gst_element_set_state_func:<fakesink0> final: setting state from READY to PAUSED
> 0:00:05.233472308 16879      0x21c2c00 DEBUG             GST_STATES gstbin.c:2853:bin_handle_async_start:<bin0> state change busy
> 0:00:05.233487226 16879      0x21c2c00 DEBUG             GST_STATES gstbin.c:2853:bin_handle_async_start:<pipeline0> state change busy
> 0:00:05.233500219 16879      0x21c2c00 LOG               GST_STATES gstelement.c:2942:gst_element_change_state_func:<fakesink0> default handler tries setting state from READY to PAUSED (0013)
> 0:00:05.233523500 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2734:gst_element_change_state:<fakesink0> element will change state ASYNC
> 0:00:05.233535236 16879      0x21c2c00 LOG               GST_STATES gstelement.c:2774:gst_element_change_state:<fakesink0> exit async state change 2
> 0:00:05.233547134 16879      0x21c2c00 DEBUG             GST_STATES gstelement.c:2679:gst_element_set_state_func:<fakesink0> returned ASYNC
> 0:00:05.233558708 16879      0x21c2c00 INFO              GST_STATES gstbin.c:2503:gst_bin_change_state_func:<bin0> child 'fakesink0' is changing state asynchronously to PAUSED

A full debug log of the session with "*:2,GST_STATES:5" is at:
http://onse.fi/files/gst-state-issue.log

This is with GStreamer 0.10.35.

I gave up debugging the issue further, but I'm posting this here in case
someone has seen this before or understands where the issue is.
I can provide additional information and/or debug outputs if needed.

The above output is with phonon-gstreamer 4.5.1, simply by creating a
MediaObject(), sleeping 5 seconds, then setting the PAUSED state, then
waiting for another 5 seconds (in which time the transition to PAUSED
didn't happen), then doing some other stuff.

-- 
Anssi Hannula