gtkwaylandsink: cancel pending redraw callback on pause/resume
Describe your issue
Gtk-based application freeze have been observed when doing intensive pause/resume on video playback or camera preview.
Setup
- STM32MP25-EV evaluation board
- GStreamer-1.22.3
How reproducible is the bug?
Launch Gtk player demo app provided with ST image (the moving ball on blue background is observed):
root@stm32mp25:~# /usr/local/demo/bin/touch-event-gtk-player
Then single-tap on touchscreen to pause/resume several time till all is frozen. At this stage this is not possible to exit from app using double-tap on touchscreen. Only way to exit is CTRL+C
root@stm32mp25:~# GST_DEBUG=gtkway*:3,*GST_STATES*:9 /usr/local/demo/bin/touch-event-gtk-player
0:00:13.358123558 2131 0x2722c90 ERROR gtkwaylandsink gstgtkwaylandsink.c:713:gst_gtk_wayland_sink_change_state:<gtkwsink> > gst_gtk_wayland_sink_change_state
0:00:13.691456850 2131 0x2722c90 ERROR gtkwaylandsink gstgtkwaylandsink.c:744:gst_gtk_wayland_sink_change_state:<gtkwsink> 1 gst_gtk_wayland_sink_change_state
0:00:13.691524750 2131 0x2722c90 LOG GST_STATES gstelement.c:3292:gst_element_change_state_func:<gtkwsink> default handler tries setting state from PLAYING to PAUSED (0023)
0:00:13.693506664 2131 0x2722c90 DEBUG GST_STATES gstbin.c:3351:bin_handle_async_start:<pipeline0> state change busy
0:00:13.693591765 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3110:gst_element_change_state:<gtkwsink> element will change state ASYNC
0:00:13.693636515 2131 0x2722c90 LOG GST_STATES gstelement.c:3150:gst_element_change_state:<gtkwsink> exit async state change 2
0:00:13.693734391 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3051:gst_element_set_state_func:<gtkwsink> returned ASYNC
==============================> gtkwaylandsink return ASYNC here and never complete to PAUSED <===========================
0:00:13.693780116 2131 0x2722c90 INFO GST_STATES gstbin.c:2942:gst_bin_change_state_func:<pipeline0> child 'gtkwsink' is changing state asynchronously to PAUSED
0:00:13.693840567 2131 0x2722c90 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<videotestsrc0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:13.693886117 2131 0x2722c90 DEBUG GST_STATES 91eaaac464e7641de6acae13c2ff36782629d786gstelement.c:2967:gst_element_set_state_func:<videotestsrc0> set_state to PAUSED
0:00:13.693924167 2131 0x2722c90 DEBUG GST_STATES gstelement.c:2992:gst_element_set_state_func:<videotestsrc0> setting target state to PAUSED
0:00:13.693970417 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3001:gst_element_set_state_func:<videotestsrc0> current PLAYING, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:13.694013443 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3037:gst_element_set_state_func:<videotestsrc0> final: setting state from PLAYING to PAUSED
0:00:13.694062118 2131 0x2722c90 LOG GST_STATES gstelement.c:3292:gst_element_change_state_func:<videotestsrc0> default handler tries setting state from PLAYING to PAUSED (0023)
0:00:13.694100393 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3128:gst_element_change_state:<videotestsrc0> element changed state SUCCESS
0:00:13.694138119 2131 0x2722c90 INFO GST_STATES gstelement.c:2816:gst_element_continue_state:<videotestsrc0> completed state change to PAUSED
0:00:13.694180294 2131 0x2722c90 INFO GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<videotestsrc0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:13.694248519 2131 0x2722c90 LOG GST_STATES gstelement.c:3145:gst_element_change_state:<videotestsrc0> exit state change 1
0:00:13.694288445 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3051:gst_element_set_state_func:<videotestsrc0> returned SUCCESS
0:00:13.694331270 2131 0x2722c90 INFO GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'videotestsrc0' changed state to 3(PAUSED) successfully
0:00:14.027793538 2131 0x2722c90 DEBUG GST_STATES gstbin.c:2997:gst_bin_change_state_func:<pipeline0> iterator done
0:00:14.027864139 2131 0x2722c90 LOG GST_STATES gstelement.c:3292:gst_element_change_state_func:<pipeline0> default handler tries setting state from PLAYING to PAUSED (0023)
0:00:14.027905664 2131 0x2722c90 DEBUG GST_STATES gstbin.c:3013:gst_bin_change_state_func:<pipeline0> we have ASYNC elements SUCCESS -> ASYNC
0:00:13.698795726 2131 0x2365300 INFO GST_STATES gstelement.c:2688:gst_element_abort_state:<gtkwsink> aborting state from PLAYING to PAUSED
0:00:14.027965964 2131 0x2722c90 DEBUG GST_STATES gstbin.c:3061:gst_bin_change_state_func:<pipeline0> done changing bin's state from PLAYING to PAUSED, now in PLAYING, ret ASYNC
0:00:14.028064440 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3110:gst_element_change_state:<pipeline0> element will change state ASYNC
0:00:14.028104065 2131 0x2722c90 LOG GST_STATES gstelement.c:3150:gst_element_change_state:<pipeline0> exit async state change 2
0:00:14.028140941 2131 0x2722c90 DEBUG GST_STATES gstelement.c:3051:gst_element_set_state_func:<pipeline0> returned ASYNC
--> SIMPLE TAP
--> BEGIN diff = 1199
Got qos message from /GstPipeline:pipeline0/GstGtkWaylandSink:gtkwsink
[...]
Got state-changed message from /GstPipeline:pipeline0/GstGtkWaylandSink:gtkwsink
Got state-changed message from /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0
Got state-changed message from /GstPipeline:pipeline0
new state: GST_STATE_PLAYING
Got state-changed message from /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0
0:00:14.733821170 2131 0x2722c90 INFO GST_STATES gstbin.c:2069:gst_bin_get_state_func:<pipeline0> getting state
0:00:14.733914821 2131 0x2722c90 DEBUG GST_STATES gstelement.c:2504:gst_element_get_state_func:<pipeline0> getting state, timeout 99:99:99.999999999
0:00:14.733948471 2131 0x2722c90 DEBUG GST_STATES gstelement.c:2509:gst_element_get_state_func:<pipeline0> RETURN is ASYNC
0:00:14.733976421 2131 0x2722c90 INFO GST_STATES gstelement.c:2532:gst_element_get_state_func:<pipeline0> waiting for element to commit state
==============================> FROZEN HERE <===========================
Solutions you have tried
Traces & analysis shows that gtkwaylandsink element is stalled on state change from PLAYING to PAUSED or PAUSED to PLAYING.
There is a first problem when ASYNC state change is returned by parent class; in this case we prematurely return from state_change, fix that by checking GST_STATE_CHANGE_FAILURE instead:
diff --git a/ext/gtk/gstgtkwaylandsink.c b/ext/gtk/gstgtkwaylandsink.c @@ -736,7 +736,7 @@ gst_gtk_wayland_sink_change_state (GstElement * element, } ret = GST_ELEMENT_CLASS (parent_class)->change_state (element, transition); - if (ret != GST_STATE_CHANGE_SUCCESS) + if (ret == GST_STATE_CHANGE_FAILURE) return ret;
=> This code has been taken from waylandsink which more or less share the same code here.
The other problem is about eventual pending wayland listener callback (see redraw_callback mechanism) while changing state which cause further freeze of element. Fix this by destroying listener callback and resetting redraw_callback flag when going from PLAYING to PAUSED and PAUSED to PLAYING.
diff --git a/ext/gtk/gstgtkwaylandsink.c b/ext/gtk/gstgtkwaylandsink.c switch (transition) { @@ -762,6 +762,18 @@ gst_gtk_wayland_sink_change_state (GstElement * element, priv->redraw_pending = FALSE; g_mutex_unlock (&priv->render_lock); break; + case GST_STATE_CHANGE_PAUSED_TO_PLAYING: + case GST_STATE_CHANGE_PLAYING_TO_PAUSED: + /* Destroy pending redraw callback otherwise + * element may freeze */ + g_mutex_lock (&priv->render_lock); + if (priv->callback) { + wl_callback_destroy (priv->callback); + priv->callback = NULL; + } + priv->redraw_pending = FALSE; + g_mutex_unlock (&priv->render_lock); + break; default: break; }