Prevent or recover from GST_STATE_CHANGE_FAILURE

Erasmo Alonso Iglesias erasmo1982 at hotmail.com
Sun May 31 12:33:19 UTC 2020


Hello,

I run the application with GST_DEBUG=3 during this weekend until it crashed.

According to application log, function gst_element_set_state returned GST_STATE_CHANGE_FAILURE esporadically for 15 times, indicating at these moments current state '2' and pending state '4'. In order to recover from this condition, both playbins are set to GST_STATE_NULL and removed along with their sinks and busses. After that, they are initialized again.

When application is working normally GStreamer log shows these entries for each played file:

18:30:42.674871594  6047 0x564ed00e04d0 ERROR              gldisplay gstgldisplay_gbm.c:394:gst_gl_display_gbm_new: could not find or open DRM device
18:30:42.675286018  6047 0x564ed00e04d0 WARN                glwindow gstglwindow.c:293:gst_gl_window_new: Could not create window. user specified (null), creating dummy window
18:30:42.675524993  6047 0x7f990800b850 WARN               glcontext gstglcontext.c:1244:gst_gl_context_create_thread:<glcontextegl440> Failed to create context
18:30:42.675557731  6047 0x564ed00e04d0 WARN             glimagesink gstglimagesink.c:1012:_ensure_gl_setup:<sink> error: Failed to initialize egl: EGL_NOT_INITIALIZED
18:30:44.127012966  6047 0x564ed00e04d0 WARN                 kmssink gstkmssink.c:710:gst_kms_sink_start:<block_player-actual-sink-kms> error: Could not open DRM module (NULL)
18:30:44.127049551  6047 0x564ed00e04d0 WARN                 kmssink gstkmssink.c:710:gst_kms_sink_start:<block_player-actual-sink-kms> error: reason: No such file or directory (2)
18:30:44.127094726  6047 0x564ed00e04d0 WARN                basesink gstbasesink.c:5265:gst_base_sink_change_state:<block_player-actual-sink-kms> error: Failed to start
18:30:44.127233195  6047 0x564ed00e04d0 WARN              ximagesink ximagesink.c:860:gst_x_image_sink_xcontext_get:<block_player-actual-sink-ximage> error: Could not initialise X output
18:30:44.127306216  6047 0x564ed00e04d0 WARN              ximagesink ximagesink.c:860:gst_x_image_sink_xcontext_get:<block_player-actual-sink-ximage> error: Could not open display
18:30:44.127477253  6047 0x564ed00e04d0 WARN             waylandsink gstwaylandsink.c:333:gst_wayland_sink_find_display:<block_player-actual-sink-wayland> warning: Could not initialise Wayland output
18:30:44.127492154  6047 0x564ed00e04d0 WARN             waylandsink gstwaylandsink.c:333:gst_wayland_sink_find_display:<block_player-actual-sink-wayland> warning: Failed to create GstWlDisplay: 'Failed to connect to the wayland display '(default)''
18:30:44.128254776  6047 0x564ed00e04d0 WARN                 basesrc gstbasesrc.c:3583:gst_base_src_start_complete:<source> pad not activated yet
18:30:44.128461166  6047 0x564ed00e04d0 WARN                 basesrc gstbasesrc.c:3583:gst_base_src_start_complete:<source> pad not activated yet
18:30:44.138282198  6047 0x564ed046d9e0 WARN                oggdemux gstoggdemux.c:3374:gst_ogg_demux_do_seek:<'':src_00000156> Locking on pts 0:00:00.267029478
18:35:24.572183260  6047 0x7f999402e2f0 ERROR             jackclient gstjackaudioclient.c:35:jack_log_error: Cannot use real-time scheduling (RR/5)(1: Operation not permitted)
18:35:24.572281787  6047 0x7f999402e2f0 ERROR             jackclient gstjackaudioclient.c:35:jack_log_error: JackClient::AcquireSelfRealTime error

And before application crash GStreamer log shows the following:

20:57:41.623603398  6047 0x564ed00e04d0 ERROR              gldisplay gstgldisplay_gbm.c:394:gst_gl_display_gbm_new: could not find or open DRM device
20:57:41.624202720  6047 0x564ed00e04d0 WARN                glwindow gstglwindow.c:293:gst_gl_window_new: Could not create window. user specified (null), creating dummy window
20:57:41.624627895  6047 0x7f99140341e0 WARN               glcontext gstglcontext.c:1244:gst_gl_context_create_thread:<glcontextegl492> Failed to create context
20:57:41.624693999  6047 0x564ed00e04d0 WARN             glimagesink gstglimagesink.c:1012:_ensure_gl_setup:<sink> error: Failed to initialize egl: EGL_NOT_INITIALIZED
20:57:41.624892760  6047 0x564ed00e04d0 WARN                GST_POLL gstpoll.c:724:gst_poll_new: 0x7f9908075e30: can't create socket pair !
20:57:43.093096309  6047 0x564ed00e04d0 WARN                 kmssink gstkmssink.c:710:gst_kms_sink_start:<block_player-actual-sink-kms> error: Could not open DRM module (NULL)
20:57:43.093234080  6047 0x564ed00e04d0 WARN                 kmssink gstkmssink.c:710:gst_kms_sink_start:<block_player-actual-sink-kms> error: reason: No such file or directory (2)
20:57:43.093286507  6047 0x564ed00e04d0 WARN                basesink gstbasesink.c:5265:gst_base_sink_change_state:<block_player-actual-sink-kms> error: Failed to start
20:57:43.093444156  6047 0x564ed00e04d0 WARN              ximagesink ximagesink.c:860:gst_x_image_sink_xcontext_get:<block_player-actual-sink-ximage> error: Could not initialise X output
20:57:43.093457276  6047 0x564ed00e04d0 WARN              ximagesink ximagesink.c:860:gst_x_image_sink_xcontext_get:<block_player-actual-sink-ximage> error: Could not open display
20:57:43.093595345  6047 0x564ed00e04d0 WARN             waylandsink gstwaylandsink.c:333:gst_wayland_sink_find_display:<block_player-actual-sink-wayland> warning: Could not initialise Wayland output
20:57:43.093616205  6047 0x564ed00e04d0 WARN             waylandsink gstwaylandsink.c:333:gst_wayland_sink_find_display:<block_player-actual-sink-wayland> warning: Failed to create GstWlDisplay: 'Failed to connect to the wayland display '(default)''

(aras-daemon:6047): GStreamer-CRITICAL **: 10:51:51.763: gst_poll_free: assertion 'set != NULL' failed
20:57:43.094474883  6047 0x564ed00e04d0 WARN                 basesrc gstbasesrc.c:3583:gst_base_src_start_complete:<source> pad not activated yet
20:57:43.094749347  6047 0x564ed00e04d0 WARN                 basesrc gstbasesrc.c:3583:gst_base_src_start_complete:<source> pad not activated yet
20:57:43.107795330  6047 0x7f998c075800 WARN                oggdemux gstoggdemux.c:3374:gst_ogg_demux_do_seek:<'':src_000003ac> Locking on pts 0:00:00.236553287
21:02:13.348965610  6047 0x7f999402e2f0 ERROR             jackclient gstjackaudioclient.c:35:jack_log_error: Cannot use real-time scheduling (RR/5)(1: Operation not permitted)
21:02:13.349149897  6047 0x7f999402e2f0 ERROR             jackclient gstjackaudioclient.c:35:jack_log_error: JackClient::AcquireSelfRealTime error
21:02:13.426663551  6047 0x564ed00e04d0 WARN                gleglgbm gstgl_gbm_utils.c:472:gst_gl_gbm_find_and_open_drm_node: Found no matching DRM devices
21:02:13.426768343  6047 0x564ed00e04d0 ERROR              gldisplay gstgldisplay_gbm.c:394:gst_gl_display_gbm_new: could not find or open DRM device
21:02:13.429673751  6047 0x564ed00e04d0 WARN                glwindow gstglwindow.c:293:gst_gl_window_new: Could not create window. user specified (null), creating dummy window

(aras-daemon:6047): GLib-ERROR **: 10:56:22.099: Creating pipes for GWakeup: Too many open files

With this information, could you get an idea of what is happening?

Best regards and thank you in advance,
Erasmo

Le mardi 26 mai 2020 ? 22:49 +0000, Erasmo Alonso Iglesias a ?crit :
> Hello,
>
> The ARAS radio automation system uses two GStreamer playbin elements in order
> to play media continuously. Every time a new file has to be played, state is
> changed from GST_STATE_READY to GST_STATE_PLAYING.
>
> Function gst_element_set_state is used to set state GST_STATE_PLAYING from
> state GST_STATE_READY. It usually returns GST_STATE_CHANGE_SUCCESS and
> everything works fine. However, in some systems after a number of played files
> it returns GST_STATE_CHANGE_FAILURE, and after that it seems not possible to
> perform more state transitions without getting a GST_STATE_CHANGE_FAILURE
> again.
>
> Anybody knows how to prevent this condition or recover from it?

At very minimum, you should transition to NULL if you have hit such an error.
Though, for best help, we'd need some debgging traces, maybe try setting
GST_DEBUG=3 to start with and sharing what you see ?

>
> libgstreamer1.0-0:amd64 version 1.14.4-1

Would be nice to bump your distro to latest 1.14, which is .6. Or maybe give a
try and Debian 9 to see if the issue is still present.

> Linux version 4.19.0-9-rt-amd64 (debian-kernel at lists.debian.org) (gcc version
> 8.3.0 (Debian 8.3.0-6)) #1 SMP PREEMPT RT Debian 4.19.118-2 (2020-04-29)
>
> Best regards and thank you in advance,
> Erasmo
>
>
> _______________________________________________
> gstreamer-devel mailing list
> gstreamer-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel



------------------------------

Subject: Digest Footer

_______________________________________________
gstreamer-devel mailing list
gstreamer-devel at lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20200531/9be84f60/attachment-0001.htm>


More information about the gstreamer-devel mailing list