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 770498 - multiqueue: decodebin, decodebin3 mpegts pipeline hangs
multiqueue: decodebin, decodebin3 mpegts pipeline hangs
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
git master
Other Linux
: Normal normal
: 1.11.1
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2016-08-28 00:12 UTC by carl
Modified: 2017-05-08 09:01 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description carl 2016-08-28 00:12:27 UTC
gst-launch-1.0 filesrc location=12_55_51.ts ! decodebin ! audioconvert ! fakesink 

to repo, get the above file 7gig
wget http://veyepar3.nextdayvideo.com/static/temp/12_55_51.ts

After a few minutes, top shows cpu cores drop to mostly idle.  ^c stops the pipeline and exits.

versions:
GStreamer 1.8.2 from ubuntu repos,  and gst-uninstalled Aug 20.


I ran with GST_DEBUG=5 and this was the tail:

0:02:04.242907888  7272 0x7fa988036e30 DEBUG         GST_SCHEDULING gstpad.c:4181:gst_pad_chain_data_unchecked:<mpegvparse0:sink> called chainfunction &gst_base_parse_chain with buffer 0x7fa988044bc0, returned not-linked
0:02:04.242919351  7272 0x7fa988036e30 DEBUG             multiqueue gstmultiqueue.c:1568:gst_multi_queue_loop:<multiqueue0> SingleQueue 0 : trying to pop an object
0:02:04.242933255  7272 0x7fa988036e30 DEBUG             multiqueue gstmultiqueue.c:1641:gst_multi_queue_loop:<multiqueue0> queue 0 sleeping for not-linked wakeup with newid 35819, highid 35818, next_time +0:15:35.117266667, high_time +0:15:34.889277778
0:02:04.242967390  7272 0x7fa98c052e80 DEBUG             multiqueue gstmultiqueue.c:2550:single_queue_check_full:<multiqueue0> queue 0: visible 4/38, bytes 2339734/2097152, time 166833334/0

On the above file 12_55_51.ts it consistently hangs.  I tried 6 more files, 3 it completed, 3 it also hung.  months ago I saw the same thing (I think. at the time I didn't dig into the bug, I gave up and did something else.)



[1] The above file was created with this command:

ffmpeg \
	-i tcp://$VOC_CORE:11000 \
	-ac 2 -channel_layout 2c -aspect 16:9 \
        -map 0:v -c:v:0 mpeg2video -pix_fmt:v:0 yuv422p -qscale:v:0 2 -qmin:v:0 2 -qmax:v:0 10 -keyint_min 0 -bf:0 0 -g:0 0 -intra:0 -maxrate:0 140M \
        -map 0:a -c:a:0 mp2 -b:a:0 192k -ac:a:0 2 -ar:a:0 48000 \
        -flags +global_header -flags +ilme+ildct \
        -f segment -segment_time $segment_time \
         -segment_format mpegts \
         -strftime 1 "$dest_dir/%Y-%m-%d/%H_%M_%S.ts"

https://github.com/CarlFK/voctomix-outcasts/blob/master/record-timestamp.sh
	
The server it is connecting to: https://github.com/voc/voctomix

I have about 200 .ts files all created with the same ffmpeg command [1]
Not sure how to test for problems given it hangs.

the mlt lib (based on ffmpeg) is able to decode these files ok.
Comment 1 Vincent Penquerc'h 2016-09-07 08:50:14 UTC
You could try running gdb on that process to see if it's stuck in some deadlock:

gdb `which gst-launch-1.0` `pidof gst-launch-1.0`

Then, in gdb:

thread apply all bt
Comment 2 carl 2016-09-07 16:38:45 UTC
(gdb) thread apply all bt

Thread 6 (Thread 0x7f1642387700 (LWP 13734))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
  • #2 _gst_data_queue_wait_non_empty
    at gstdataqueue.c line 553
  • #3 gst_data_queue_pop
    at gstdataqueue.c line 595
  • #4 gst_multi_queue_loop
    at gstmultiqueue.c line 1575
  • #5 gst_task_func
    at gsttask.c line 332
  • #6 g_thread_pool_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthreadpool.c line 307
  • #7 g_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread.c line 780
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Thread 5 (Thread 0x7f1642db9700 (LWP 13733))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
  • #2 gst_multi_queue_loop
    at gstmultiqueue.c line 1647
  • #3 gst_task_func
    at gsttask.c line 332
  • #4 g_thread_pool_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthreadpool.c line 307
  • #5 g_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread.c line 780
  • #6 start_thread
    at pthread_create.c line 333
  • #7 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Thread 4 (Thread 0x7f16435ba700 (LWP 13732))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
  • #2 gst_data_queue_push
    at gstdataqueue.c line 520
  • #3 gst_multi_queue_chain
    at gstmultiqueue.c line 1890
  • #4 gst_pad_push_data
    at gstpad.c line 4177
  • #5 gst_pad_push_data
    at gstpad.c line 4429
  • #6 gst_pad_push
    at gstpad.c line 4548
  • #7 gst_ts_demux_push_pending_data
    at tsdemux.c line 2654
  • #8 gst_ts_demux_push
    at tsdemux.c line 2710
  • #9 gst_ts_demux_push
    at tsdemux.c line 2789
  • #10 mpegts_base_chain
    at mpegtsbase.c line 1186
  • #11 mpegts_base_loop
    at mpegtsbase.c line 1363
  • #12 gst_task_func
    at gsttask.c line 332
  • #13 g_thread_pool_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthreadpool.c line 307
  • #14 g_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread.c line 780
  • #15 start_thread
    at pthread_create.c line 333
  • #16 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Thread 2 (Thread 0x7f1648e9b700 (LWP 13730))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread-posix.c line 1394
  • #2 gst_task_func
    at gsttask.c line 317
  • #3 g_thread_pool_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthreadpool.c line 307
  • #4 g_thread_proxy
    at /build/glib2.0-7IO_Yw/glib2.0-2.48.1/./glib/gthread.c line 780
  • #5 start_thread
    at pthread_create.c line 333
  • #6 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Comment 3 Vincent Penquerc'h 2016-10-06 10:19:13 UTC
I can reproduce this on some of my test ts files.
It gets fixed by doubling AUTO_PLAY_SIZE_BYTES (from 2 MB to 4 MB) in -base/gst/playback/decodebin2.c.
Comment 4 Tim-Philipp Müller 2016-11-13 10:15:12 UTC
Can reproduce this with your test file and git master, with decodebin and decodebin3.
Comment 5 carl 2016-11-14 18:01:02 UTC
fails with both: git master, with decodebin and decodebin3.

my 7 gig file is still at:
http://veyepar3.nextdayvideo.com/static/temp/12_55_51.ts

juser@cnt7:~/temp$ which gst-launch-1.0
/home/juser/gst/master/gstreamer/tools/gst-launch-1.0

juser@cnt7:~/temp$ gst-inspect-1.0 decodebin
  Filename                 /home/juser/gst/master/gst-plugins-base/gst/playback/.libs/libgstplayback.so
  Version                  1.11.0.1


juser@cnt7:~/temp$ GST_DEBUG=5 gst-launch-1.0 filesrc location=12_55_51.ts ! decodebin ! audioconvert ! fakesink

0:07:02.130876709 18714 0x7f47ac046230 DEBUG                tsdemux tsdemux.c:2737:gst_ts_demux_push_pending_data:<tsdemux0:video_0_0100> Pushing buffer with PTS: 0:15:35.800833333 , DTS: 0:15:35.767466666
0:07:02.130893052 18714 0x7f47ac046230 DEBUG               GST_PADS gstpad.c:3700:do_probe_callbacks:<tsdemux0:video_0_0100> data is passed
0:07:02.130904226 18714 0x7f47ac046230 DEBUG               GST_PADS gstpad.c:3700:do_probe_callbacks:<multiqueue0:sink_0> data is passed
0:07:02.130914295 18714 0x7f47ac046230 DEBUG         GST_SCHEDULING gstpad.c:4204:gst_pad_chain_data_unchecked:<multiqueue0:sink_0> calling chainfunction &gst_multi_queue_chain with buffer buffer: 0x7f47a00e54d0, pts 0:15:35.800833333, dts 0:15:35.767466666, dur 99:99:99.999999999, size 584931, offset none, offset_end none, flags 0x0
0:07:02.130932324 18714 0x7f47ac046230 DEBUG             multiqueue gstmultiqueue.c:2799:single_queue_check_full:<multiqueue0> queue 0: visible 4/38, bytes 2339734/2097152, time 166833334/0
0:07:02.130945248 18714 0x7f47ac046230 DEBUG             multiqueue gstmultiqueue.c:2742:single_queue_overrun_cb:<multiqueue0> Queue 0 is filled, signalling overrun
0:07:02.130956575 18714 0x7f47ac046230 DEBUG             multiqueue gstmultiqueue.c:2799:single_queue_check_full:<multiqueue0> queue 0: visible 4/38, bytes 2339734/2097152, time 166833334/0



juser@cnt7:~/temp$ gst-inspect-1.0 decodebin3
  Long-name                Decoder Bin 3
  Filename                 /home/juser/gst/master/gst-plugins-base/gst/playback/.libs/libgstplayback.so
  Version                  1.11.0.1

juser@cnt7:~/temp$ GST_DEBUG=5 gst-launch-1.0 filesrc location=12_55_51.ts ! decodebin3 ! audioconvert ! fakesink 

0:00:04.744306301 21815 0x7fb0e8036a30 DEBUG         GST_SCHEDULING gstpad.c:4210:gst_pad_chain_data_unchecked:<audioconvert0:sink> called chainfunction &gst_base_transform_chain with buffer 0x7fb0e40151b0, returned ok
0:00:04.744313090 21815 0x7fb0e8036a30 DEBUG         GST_SCHEDULING gstpad.c:4210:gst_pad_chain_data_unchecked:<audio_0:proxypad6> called chainfunction &gst_proxy_pad_chain_default with buffer 0x7fb0e40151b0, returned ok
0:00:04.744320118 21815 0x7fb0e8036a30 DEBUG             GST_MEMORY gstmemory.c:87:_gst_memory_free: free memory 0x7fb0e81abf10
0:00:04.744332613 21815 0x7fb0e8036a30 DEBUG           audiodecoder gstaudiodecoder.c:1509:gst_audio_decoder_push_buffers:<mad0> parsing available: 576
0:00:04.744343856 21815 0x7fb0e8036a30 DEBUG         GST_SCHEDULING gstpad.c:4210:gst_pad_chain_data_unchecked:<mad0:sink> called chainfunction &gst_audio_decoder_chain with buffer 0x7fb0e81066e0, returned ok
0:00:04.744352578 21815 0x7fb0e8036a30 DEBUG             multiqueue gstmultiqueue.c:1762:gst_multi_queue_loop:<multiqueue0> SingleQueue 1 : trying to pop an object
0:00:04.744358111 21815 0x7fb0e8036a30 DEBUG             multiqueue gstmultiqueue.c:2799:single_queue_check_full:<multiqueue0> queue 0: visible 18/0, bytes 1308321/10485760, time 633966667/376883332
0:00:04.744364714 21815 0x7fb0e8036a30 DEBUG             multiqueue gstmultiqueue.c:2799:single_queue_check_full:<multiqueue0> queue 1: visible 0/0, bytes 0/10485760, time 0/376883332
Comment 6 Tim-Philipp Müller 2016-11-14 18:14:36 UTC
Yes, that's what I was trying to say, was just confirming that I could reproduce it as well :)
Comment 7 Jan Schmidt 2016-11-16 12:30:08 UTC
The patch in bug #774322 seems to fix this for the decodebin3 case. I'm not sure we have a sensible way to fix the decodebin2 case - it's one of the reasons we made decodebin3 after all.
Comment 8 Tim-Philipp Müller 2016-11-16 14:06:21 UTC
Confirmed, works for me with decodebin3 and the patch from bug #774322

commit fa3eac2d28e0006f7bf555c866b1daefd15c278b
Author: Jan Schmidt <jan@centricular.com>
Date:   Wed Nov 16 23:19:28 2016 +1100

    multiqueue: Make sure not-linked streams get woken up
    
    When running in sync-by-running-time mode, pad groups
    that have exactly 1 pad and it's not-linked might never
    wake up after computing a high time, as the per-pad-group
    high time was only recomputed when a pad in the group
    advances.
    
    Wake those up using the global multiqueue high-time across
    all other groups instead.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=774322


Unlikely this will ever get fixed with decodebin (aka decodebin2).
Comment 9 rland 2017-05-08 09:01:13 UTC
Android encountered the same problem.(As I mentioned here http://gstreamer-devel.966125.n4.nabble.com/Video-playback-freezes-hangs-with-quot-lt-opensles-ringbuffer-gt-No-segment-available-quot-td4681779.html#a4681809).
----
01-01 09:48:20.126 22614 22907 [gstmultiqueue.c:1125] <multiqueue> queue 0: visible 21/0, bytes 1696632/2097152, time 700700000/5000000000
01-01 09:48:20.126 22614 22907 [gstmultiqueue.c:1125] <multiqueue> queue 1: visible 0/0, bytes 0/2097152, time 0/5000000000

It seems for what reason audio queue can't pop  data ? and finally print with such a warning message:

<opensles_ringbuffer> No segment available

----