Prevent or recover from GST_STATE_CHANGE_FAILURE

[Erasmo Alonso Iglesias]

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?

libgstreamer1.0-0:amd64 version 1.14.4-1

Linux version 4.19.0-9-rt-amd64 ([hidden email]) (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
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Nicolas Dufresne-5]

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 ([hidden email]) (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
> [hidden email]
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[Erasmo Alonso Iglesias]

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 ([hidden email]) (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-[hidden email]
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel



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

Subject: Digest Footer

_______________________________________________
gstreamer-devel mailing list
gstreamer-[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel