Page MenuHomePhabricator

emotion (gst) can deadlock during file close
Open, Showstopper IssuesPublic

Description

#0  0x00007f2d0d21542d in __lll_lock_wait () at /lib64/libpthread.so.0
#1  0x00007f2d0d20e248 in pthread_mutex_lock () at /lib64/libpthread.so.0
#2  0x00007f2cbb257429 in activate_mode_internal () at /lib64/libgstreamer-1.0.so.0
#3  0x00007f2cbb257ee5 in gst_pad_set_active () at /lib64/libgstreamer-1.0.so.0
#4  0x00007f2cbb2369bd in activate_pads () at /lib64/libgstreamer-1.0.so.0
#5  0x00007f2cbb248774 in gst_iterator_fold () at /lib64/libgstreamer-1.0.so.0
#6  0x00007f2cbb2374c6 in iterator_activate_fold_with_resync.constprop () at /lib64/libgstreamer-1.0.so.0
#7  0x00007f2cbb23916a in gst_element_pads_activate () at /lib64/libgstreamer-1.0.so.0
#8  0x00007f2cbb239496 in gst_element_change_state_func () at /lib64/libgstreamer-1.0.so.0
#9  0x00007f2cbb23b3ae in gst_element_change_state () at /lib64/libgstreamer-1.0.so.0
#10 0x00007f2cbb23bae9 in gst_element_set_state_func () at /lib64/libgstreamer-1.0.so.0
#11 0x00007f2cbb219c22 in gst_bin_change_state_func () at /lib64/libgstreamer-1.0.so.0
#12 0x00007f2cbacec809 in gst_decode_bin_change_state () at /usr/lib64/gstreamer-1.0/libgstplayback.so
#13 0x00007f2cbb23b3ae in gst_element_change_state () at /lib64/libgstreamer-1.0.so.0
#14 0x00007f2cbb23bae9 in gst_element_set_state_func () at /lib64/libgstreamer-1.0.so.0
#15 0x00007f2cbb219c22 in gst_bin_change_state_func () at /lib64/libgstreamer-1.0.so.0
#16 0x00007f2cbacfed2a in gst_uri_decode_bin_change_state () at /usr/lib64/gstreamer-1.0/libgstplayback.so
#17 0x00007f2cbb23b3ae in gst_element_change_state () at /lib64/libgstreamer-1.0.so.0
#18 0x00007f2cbb23bae9 in gst_element_set_state_func () at /lib64/libgstreamer-1.0.so.0
#19 0x00007f2cbb219c22 in gst_bin_change_state_func () at /lib64/libgstreamer-1.0.so.0
#20 0x00007f2cbad1a6c5 in gst_play_bin_change_state () at /usr/lib64/gstreamer-1.0/libgstplayback.so
#21 0x00007f2cbb23b3ae in gst_element_change_state () at /lib64/libgstreamer-1.0.so.0
#22 0x00007f2cbb23bae9 in gst_element_set_state_func () at /lib64/libgstreamer-1.0.so.0
#23 0x00007f2cd1d84afe in em_file_close (video=0x191e0d0) at modules/emotion/gstreamer1/emotion_gstreamer.c:167
#24 0x00007f2d0b08b552 in emotion_engine_instance_file_close (inst=0x191e150) at lib/emotion/emotion_modules.c:476
#25 0x00007f2d0b088a36 in _efl_canvas_video_efl_canvas_group_group_del (obj=0x40000009ddf6, sd=0x17099b0) at lib/emotion/emotion_smart.c:1920
#26 0x00007f2d0bbe6ab0 in efl_canvas_group_del (obj=0x40000009ddf6) at lib/evas/canvas/evas_object_smart.c:1846
#27 0x00007f2d0bbe53f5 in evas_object_smart_del (eo_obj=0x40000009ddf6) at lib/evas/canvas/evas_object_smart.c:1286
#28 0x00007f2d0bbd0dbb in _efl_canvas_object_efl_object_destructor (eo_obj=0x40000009ddf6, obj=0x17097f0) at lib/evas/canvas/evas_object_main.c:1365
#29 0x00007f2d068ca27c in efl_destructor (obj=0x40000009ddf6) at lib/eo/efl_object.eo.c:68
#30 0x00007f2d0bbe395e in _efl_canvas_group_efl_object_destructor (eo_obj=0x40000009ddf6, o=0x1709920) at lib/evas/canvas/evas_object_smart.c:712
#31 0x00007f2d068ca27c in efl_destructor (obj=0x40000009ddf6) at lib/eo/efl_object.eo.c:68

Related Objects

zmike created this task.May 9 2018, 11:16 AM
zmike triaged this task as Showstopper Issues priority.

Hi, I'm looking into this. Can you explain how you got this backtrace? That would be great.

zmike edited projects, added Restricted Project; removed efl.Jun 11 2018, 6:50 AM
bu5hm4n edited projects, added efl: rendering; removed Restricted Project.Jun 11 2018, 7:24 AM

"src/modules/emotion/gstreamer1/emotion_gstreamer.c"

static void
em_file_close(void *video)
{
   Emotion_Gstreamer *ev = video;
   Eina_List *l;

   ev->shutdown = EINA_TRUE;

   if (ev->threads)
     {
        Ecore_Thread *t;

        EINA_LIST_FOREACH(ev->threads, l, t)
          {
             ecore_thread_cancel(t);
          }

      // XXX: Should wait for threads to finish unblocking actions ???
     }

   if (ev->pipeline)
     {
       if (ev->audio_buffer_probe)
         {
            gst_pad_remove_probe(ev->audio_buffer_probe_pad, ev->audio_buffer_probe);
            gst_object_unref(ev->audio_buffer_probe_pad);
            ev->audio_buffer_probe_pad = NULL;
            ev->audio_buffer_probe = 0;
         }

       gst_element_set_state(ev->pipeline, GST_STATE_NULL);
       g_object_set(G_OBJECT(ev->vsink), "emotion-object", NULL, NULL);
       gst_object_unref(ev->pipeline);

       ev->pipeline = NULL;
       ev->vsink = NULL;
     }

   if (ev->metadata)
     {
        _free_metadata(ev->metadata);
        ev->metadata = NULL;
     }

   ev->ready = EINA_FALSE;
}

AFAIU two things can cause this:

a) if _set_state is called from a streaming thread (this is bad)
b) If some element does not unblock it's streaming thread.

So, I wonder should we be waiting for the threads to cancel?

See XXX in above code.

gst_element_set_state(ev->pipeline, GST_STATE_NULL) can block in the two above scenarios.

@segfaultxavi you said you had some experience with gstreamer. Adding you into this one!

Yeah, how can I reproduce the issue?

I'm unable to reproduce. I would think with emotion_test cases and using a small test file.

I've just done a little work from the backtrace above and based on that.

Other than this, I'm afraid I can't give you a sure means of achieving the above backtrace or similar yourself.

zmike added a comment.Jun 14 2018, 5:59 AM

This is a very rare corner case which can occur on any emotion object deletion when a video is playing. The OP backtrace is in the main thread, as evidenced by the object deletion being present.

I have started and closed emotion_test about 10 times and never got a deadlock. I have done the same thing with rage and never got a deadlock, but it segfaults on exit every time (can provide backtrace, but this is probably a different issue).

@zmike How often can you trigger this deadlock?

zmike added a comment.Jun 14 2018, 8:16 AM

As I said, it's very rare. I can only recall seeing it once or twice at most--it's likely not something that can be actively debugged and should instead be theoretically debugged.

So, I'm no gst guru, but is it possible in some situations those threads won't be finished after the cancel and gst_element_set_state(ev->pipeline, GST_STATE_NULL); is blocking if that sometimes happens?

gst_element_set_state() is blocking because there's some other thread blocked on a GStreamer call, probably a callback into EFl code. If we could get a backtrace of ALL threads (thread apply all bt in gdb) it should be fairly easy to find out where.

Otherwise, look at all EFl callbacks registered to GStreamer, see if they have suspicious locks, and if nothing jumps to you, add the classic lock debug output ("about to lock", "locked", "lock released") to all locks and pray :)

zmike added a comment.Jun 15 2018, 6:30 AM

I no longer have the process available for debugging. Destroying any emotion object which is currently playing should have a chance to trigger this, though I'm not optimistic that even catching it would yield much in the way of information.

One last thing, @zmike, do you remember the type of media you were playing? Container, codecs... GStreamer behaves differently depending on these.

zmike added a comment.Jun 15 2018, 6:51 AM

Not 100% sure, but I would guess it was the file from T6319 since it's on the desktop of my test machine. Based on the number of stack frames, this probably occurred when destroying a tooltip in Enlightenment, though I don't think that's especially relevant.

Also I'm not sure this is something that we should really be spending a lot of time on right now. It's definitely not a release-blocking issue.

Then you should lower its priority 😛

zmike added a comment.Jun 15 2018, 7:23 AM

An issue's priority is not equal to its ability to block a release. It seems like every existing issue was tagged with the 1.21 milestone, and I've been going through and removing it on a lot of tickets...