Playbin missing state notifications

[Henning Riis]

Trying to write a player using gstreamer and the playbin element. I'm creating a pipeline, adding a bus watch and waiting for messages on the bus. I then set the uri on the pipeline and wait for it to go to playing state. The code is something like this (checks and cleanup removed):

//when user selects a resource
m_pipeline = gst_element_factory_make("playbin", "playbin0");
GstBus *bus = gst_pipeline_get_bus(GST_PIPELINE(m_pipeline));
m_busWatchId = gst_bus_add_watch (bus, IPlayer::s_busCallback, this);
gst_object_unref(bus);
g_object_set(G_OBJECT (m_pipeline), "uri", m_uri.c_str(), NULL);
gst_element_set_state(m_pipeline, GST_STATE_PAUSED);
//when user presses 'play'
gst_element_set_state(m_pipeline, GST_STATE_PLAYING);

In my bus callback I then look for GST_MESSAGE_STATE_CHANGED in order to know when the pipeline starts playing. Sometimes this works as expected, I get: NULL->READY, READY->PAUSED, PAUSED->PLAYING.

Sometimes I only get first: NULL->READY. The video starts playing anyway however, so something is working but my application just has no idea that playback has started.

This is just on application startup, so preconditions should be the same for all runs. I'm guessing something is racing but cannot figure out what.

My only vague guess is that it's somehow not allowed to set GST_STATE_PLAYING before the first full transition from NULL to PAUSED (via READY) has completed. But I cannot find documentation that confirms this, and it would take a lot of code to queue up my state changes like that, so I'd rather not do it unless it's totally necessary.

Here are some logs obtained by setting GST_DEBUG to 4.

When I get the state change:

0:00:02.918974302  7028   0DF19EC0 INFO              GST_STATES gstelement.c:2277:_priv_gst_element_state_changed: notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:02.919185366  7028   06452D20 FIXME                    bin gstbin.c:4144:gst_bin_query: implement duration caching in GstBin again
0:00:02.919405213  7028   06452D20 FIXME                    bin gstbin.c:4144:gst_bin_query: implement duration caching in GstBin again
0:00:02.919624475  7028   06452D20 FIXME                    bin gstbin.c:4144:gst_bin_query: implement duration caching in GstBin again
0:00:02.919882670  7028   06452D20 FIXME                    bin gstbin.c:4144:gst_bin_query: implement duration caching in GstBin again [Media]
IPlayer.cpp:555  gst_element_query_duration 85542000000ns [Media]
IPlayer.cpp:152  Pipeline playbin0 changed state from PAUSED to PLAYING pending VOID_PENDING. Duration 85542ms
0:00:02.926384105  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.927016128  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.927645809  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.929138777  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.929487722  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.929740355  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.931064998  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.931415992  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.932754686  7028   06452D20 INFO              GST_STATES gstbin.c:1915:gst_bin_get_state_func: getting state
0:00:02.933954622  7028   06452D20 INFO                 default gstdebugutils.c:811:gst_debug_bin_to_dot_file: wrote bin graph to : 'dot\IPlayer-PLAYING.dot'
0:00:02.950122584  7028   0DEB5920 INFO            videodecoder gstvideodecoder.c:1432:gst_video_decoder_sink_event_default: upstream tags: taglist, video-codec=(string)"H.264\ \(Main\ Profile\)", bitrate=(uint)2981313, minimum-bitrate=(uint)281200, maximum-bitrate=(uint)1461000;


When I don't get the state change:

0:00:02.947089811 11792   0D369EC0 INFO            GST_STATES gstelement.c:2277:_priv_gst_element_state_changed: notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:02.981495398 11792   0D307920 INFO            videodecoder gstvideodecoder.c:1432:gst_video_decoder_sink_event_default: upstream tags: taglist, video-codec=(string)"H.264\ \(Main\ Profile\)", bitrate=(uint)2981313, minimum-bitrate=(uint)281200, maximum-bitrate=(uint)1461000;
0:00:03.020488493 11792   0D307920 INFO                videodecoder gstvideodecoder.c:1432:gst_video_decoder_sink_event_default: upstream tags: taglist, video-codec=(string)"H.264\ \(Main\ Profile\)", bitrate=(uint)2981313, minimum-bitrate=(uint)281200, maximum-bitrate=(uint)3918800;

Of course the logs are a lot longer, but I'm assuming this is the relevant place. The IPlayer.cpp stuff is my application, so this is only when I get the callback. When I add/remove certain printf's I can no longer reproduce the problem.

I'm using gstreamer 1.8.1 on windows7.

Best Regards,
Henning
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20160613/9b0bbe45/attachment-0001.html>