GNOME Bugzilla – Bug 770498
multiqueue: decodebin, decodebin3 mpegts pipeline hangs
Last modified: 2017-05-08 09:01:13 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.
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
(gdb) thread apply all bt
+ Trace 236640
Thread 6 (Thread 0x7f1642387700 (LWP 13734))
Thread 5 (Thread 0x7f1642db9700 (LWP 13733))
Thread 4 (Thread 0x7f16435ba700 (LWP 13732))
Thread 2 (Thread 0x7f1648e9b700 (LWP 13730))
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.
Can reproduce this with your test file and git master, with decodebin and decodebin3.
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
Yes, that's what I was trying to say, was just confirming that I could reproduce it as well :)
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.
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).
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 ----