Bug 769514 – splitmuxsink: Deadlock

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 769514 - splitmuxsink: Deadlock


Summary:	splitmuxsink: Deadlock


Status:	RESOLVED FIXED

Product:	GStreamer
Classification:	Platform
Component:	gst-plugins-good
Version:	git master
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	1.8.3
Assigned To:	GStreamer Maintainers
QA Contact:	GStreamer Maintainers

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2016-08-04 13:45 UTC by Vivia Nikolaidou
Modified:	2016-08-07 15:27 UTC

See Also:
GNOME target:	---
GNOME version:	---

Attachments
*:3,splitmuxsink:6 log (582.90 KB, application/x-zip-compressed) 2016-08-07 14:31 UTC, Vivia Nikolaidou	Details

Description Vivia Nikolaidou 2016-08-04 13:45:18 UTC

gdb --args bash gst-launch-1.0 videotestsrc num-buffers=25000 ! video/x-raw,width=1280,height=720 ! timeoverlay time-mode=2 ! x264enc ! h264parse ! splitmuxsink muxer=qtmux location=/home/vivia/video%05d.mov max-size-time=60000000000

[...]

(gdb) thread apply all bt

+ Trace 236506

Thread 3 (Thread 0x7fffef2cb700 (LWP 5103))

#0 syscall
at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
#1 g_cond_wait
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
#2 handle_mq_input
at gstsplitmuxsink.c line 1241
#3 probe_hook_marshal
at gstpad.c line 3468
#4 g_hook_list_marshal
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/ghook.c line 672
#5 do_probe_callbacks
at gstpad.c line 3620
#6 gst_pad_chain_data_unchecked
at gstpad.c line 4206
#7 gst_pad_push_data
at gstpad.c line 4478
#8 gst_pad_push
at gstpad.c line 4598
#9 gst_proxy_pad_chain_default
at gstghostpad.c line 126
#10 gst_pad_chain_data_unchecked
at gstpad.c line 4226
#11 gst_pad_push_data
at gstpad.c line 4478
#12 gst_pad_push
at gstpad.c line 4598
#13 gst_base_parse_push_frame
at gstbaseparse.c line 2543
#14 gst_base_parse_finish_frame
at gstbaseparse.c line 2360
#15 gst_base_parse_finish_frame
at gstbaseparse.c line 2701
#16 gst_h264_parse_handle_frame
at gsth264parse.c line 1013
#17 gst_h264_parse_handle_frame
at gsth264parse.c line 1065
#18 gst_base_parse_handle_buffer
at gstbaseparse.c line 2168
#19 gst_base_parse_chain
at gstbaseparse.c line 3240
#20 gst_pad_chain_data_unchecked
at gstpad.c line 4226
#21 gst_pad_push_data
at gstpad.c line 4478
#22 gst_pad_push
at gstpad.c line 4598
#23 gst_video_encoder_finish_frame
at gstvideoencoder.c line 2179
#24 gst_x264_enc_encode_frame
at gstx264enc.c line 2237
#25 gst_x264_enc_handle_frame
at gstx264enc.c line 2122
#26 gst_video_encoder_chain
at gstvideoencoder.c line 1455
#27 gst_pad_chain_data_unchecked
at gstpad.c line 4226
#28 gst_pad_push_data
at gstpad.c line 4478
#29 gst_pad_push
at gstpad.c line 4598
#30 gst_base_text_overlay_push_frame
at gstbasetextoverlay.c line 2246
#31 gst_base_text_overlay_video_chain
at gstbasetextoverlay.c line 2726
#32 gst_pad_chain_data_unchecked
at gstpad.c line 4226
#33 gst_pad_push_data
at gstpad.c line 4478
#34 gst_pad_push
at gstpad.c line 4598
#35 gst_base_transform_chain
at gstbasetransform.c line 2369
#36 gst_pad_chain_data_unchecked
at gstpad.c line 4226
#37 gst_pad_push_data
at gstpad.c line 4478
#38 gst_pad_push
at gstpad.c line 4598
#39 gst_base_src_loop
at gstbasesrc.c line 2854
#40 gst_task_func
at gsttask.c line 334
#41 g_thread_pool_thread_proxy
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthreadpool.c line 307
#42 g_thread_proxy
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthread.c line 780
#43 start_thread
at pthread_create.c line 333
#44 clone
at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Thread 2 (Thread 0x7fffefacc700 (LWP 5102))

#0 syscall
at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
#1 g_cond_wait
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
#2 complete_or_wait_on_out
at gstsplitmuxsink.c line 597
#3 handle_mq_output
at gstsplitmuxsink.c line 689
#4 probe_hook_marshal
at gstpad.c line 3468
#5 g_hook_list_marshal
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/ghook.c line 672
#6 do_probe_callbacks
at gstpad.c line 3620
#7 gst_pad_push_event_unchecked
at gstpad.c line 5260
#8 gst_pad_push_event
at gstpad.c line 5424
#9 gst_multi_queue_loop
at gstmultiqueue.c line 1570
#10 gst_multi_queue_loop
at gstmultiqueue.c line 1819
#11 gst_task_func
at gsttask.c line 334
#12 g_thread_pool_thread_proxy
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthreadpool.c line 307
#13 g_thread_proxy
at /build/glib2.0-vjfO_h/glib2.0-2.48.1/./glib/gthread.c line 780
#14 start_thread
at pthread_create.c line 333
#15 clone
at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Comment 1 Vivia Nikolaidou 2016-08-07 13:14:09 UTC

From the backtrace, gstsplitmuxsink.c around line 1241:

      case SPLITMUX_STATE_START_NEXT_FRAGMENT:
        /* A fragment is ending, wait until that's done before continuing */
        GST_DEBUG_OBJECT (pad, "Sleeping for fragment restart");
        GST_SPLITMUX_WAIT (splitmux);
        GST_DEBUG_OBJECT (pad,
            "Done sleeping for fragment restart state now %d", splitmux->state);
        break;

However, the freeze happens at random points, not when a fragment is ending.

Also, it doesn't seem to happen with *:6 debug log enabled.

Comment 2 Vivia Nikolaidou 2016-08-07 14:31:58 UTC

Created attachment 332887 [details]
*:3,splitmuxsink:6 log

Comment 3 Jan Schmidt 2016-08-07 15:26:49 UTC

Fixed by:

commit 89af379ff040923cfcbaf05354ed2b01a620b1b9
Author: Jan Schmidt <jan@centricular.com>
Date:   Mon Aug 8 00:56:38 2016 +1000

    splitmux: Recheck state after unlocking mutex.
    
    After dropping the splitmux lock, re-check the state,
    don't just fall through and sleep unconditionally,
    as we may have already missed the wakeup.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=769514