GNOME Bugzilla – Bug 576064
gst-launch playbin2 of a youtube stream doesn't exit after eos
Last modified: 2009-04-24 10:49:38 UTC
Please describe the problem: after playback of youtube mpeg 4 video stream using playbin2 on the command line, the application doesn't exit after EOS. Steps to reproduce: GST_DEBUG="*queue2*:5,*decodebin*:5,*playbin2*:5" gst-launch playbin2 uri="http://www.youtube.com/get_video?video_id=E_AhiIJzGbA&l=20&sk=AkrJIMSwvkty9zXfJUjyxDy5UT1K056oC&fmt_map=34%2F0%2F9%2F0%2F115%2C5%2F0%2F7%2F0%2F0&t=vjVQa1PpcFMWCoD1DyKRUrBPwwepMLOxz9qWmxxOs18%3D&hl=en&plid=AARlirnx7EAsGMse&cr=US&fmt=18" Actual results: just sits there and does nothing until ctrl-c pressed Expected results: exit normally after eos Does this happen every time? tested it a couple of times with different urls, yes Other information:
Created attachment 131021 [details] log of command from above
The EOS event was dropped because of some wrongly initialized boolean.. commit 554b3aafe48bf9bcbb87053e23552c192b100538 Author: Wim Taymans <wim.taymans@collabora.co.uk> Date: Fri Mar 20 15:47:47 2009 +0100 decodebin2: a pad starts out being not drained. Mark a new pad as not drained until we get EOS on it.
not working yet. here's a log excerpt with current git head 0:00:13.969048000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1168:gst_queue_locked_dequeue:<queue20> retrieved buffer 0x100c7070 from queue 0:00:13.970441000 12101 0x10041e80 DEBUG queue2 gstqueue2.c:650:apply_buffer:<queue20> last_stop updated to 0:00:00.000000000 0:00:13.971945000 12101 0x10041e80 DEBUG queue2 gstqueue2.c:580:update_time_level:<queue20> sink 0:00:00.000000000, src 0:00:00.000000000 0:00:13.974703000 12101 0x10041e80 DEBUG queue2 gstqueue2.c:828:update_out_rates:<queue20> rates: out 187448.187046, time 0:00:00.000000000 0:00:13.976299000 12101 0x10041e80 DEBUG queue2 gstqueue2.c:722:update_buffering:<queue20> filled 100 percent 0:00:13.981175000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1459:gst_queue_push_one:<queue20> got UNEXPECTED from downstream 0:00:13.982703000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1183:gst_queue_locked_dequeue:<queue20> retrieved event 0x10092120 from queue 0:00:13.984215000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1478:gst_queue_push_one:<queue20> pushing pushable event eos after UNEXPECTED 0:00:13.986333000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:2435:source_pad_event_probe:<decodebin20:src0> eos dpad:0x100ac6f0 0:00:13.987389000 12101 0x100cbe50 DEBUG decodebin2 gstdecodebin2.c:2438:source_pad_event_probe:<decodebin20:src0> we received EOS 0:00:13.988262000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1978:gst_decode_pad_handle_eos:<decodebin20> group : 0x100c06b8, pad 0x100ac6f0 0:00:13.989203000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1980:gst_decode_pad_handle_eos:<decodebin20> locking group 0x100c06b8 from thread 0x100cbe50 0:00:13.990154000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1980:gst_decode_pad_handle_eos:<decodebin20> locked group 0x100c06b8 from thread 0x100cbe50 0:00:13.991111000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1991:gst_decode_pad_handle_eos:<decodebin20> testing dpad 0x100ac6f0 1 0:00:13.992036000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1991:gst_decode_pad_handle_eos:<decodebin20> testing dpad 0x100ac600 0 0:00:13.994304000 12101 0x100cbe50 LOG decodebin2 gstdecodebin2.c:1999:gst_decode_pad_handle_eos:<decodebin20> unlocking group 0x100c06b8from thread 0x100cbe50 0:00:13.998501000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:2435:source_pad_event_probe:<decodebin20:src1> eos dpad:0x100ac600 0:00:14.000319000 12101 0x100b2670 DEBUG decodebin2 gstdecodebin2.c:2438:source_pad_event_probe:<decodebin20:src1> we received EOS 0:00:14.001882000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1978:gst_decode_pad_handle_eos:<decodebin20> group : 0x100c06b8, pad 0x100ac600 0:00:14.003455000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1980:gst_decode_pad_handle_eos:<decodebin20> locking group 0x100c06b8 from thread 0x100b2670 0:00:14.005128000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1980:gst_decode_pad_handle_eos:<decodebin20> locked group 0x100c06b8 from thread 0x100b2670 0:00:14.006594000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1991:gst_decode_pad_handle_eos:<decodebin20> testing dpad 0x100ac6f0 1 0:00:14.008031000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1991:gst_decode_pad_handle_eos:<decodebin20> testing dpad 0x100ac600 1 0:00:14.009429000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1999:gst_decode_pad_handle_eos:<decodebin20> unlocking group 0x100c06b8from thread 0x100b2670 0:00:14.011014000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1942:gst_decode_bin_activate_next_group:<decodebin20> locking from thread 0x100b2670 0:00:14.013416000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1942:gst_decode_bin_activate_next_group:<decodebin20> locked from thread 0x100b2670 0:00:14.014971000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:1960:gst_decode_bin_activate_next_group:<decodebin20> unlocking from thread 0x100b2670 0:00:14.016366000 12101 0x100b2670 LOG decodebin2 gstdecodebin2.c:2007:gst_decode_pad_handle_eos:<decodebin20> all groups drained, fire signal 0:00:14.017821000 12101 0x100b2670 DEBUG uridecodebin gsturidecodebin.c:1095:proxy_drained_signal:<uridecodebin0> drained signaled 0:00:14.019255000 12101 0x100b2670 DEBUG playbin2 gstplaybin2.c:2018:drained_cb:<playbin20> about to finish in group 0x1004838c 0:00:14.020715000 12101 0x100b2670 DEBUG playbin2 gstplaybin2.c:2375:setup_next_source:<playbin20> setup sources 0:00:14.022085000 12101 0x100b2670 DEBUG playbin2 gstplaybin2.c:2405:setup_next_source:<playbin20> no next group 0:00:14.024337000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1505:gst_queue_push_one:<queue20> pushed EOS event 0x10092120, return UNEXPECTED 0:00:14.025777000 12101 0x10041e80 LOG queue2_dataflow gstqueue2.c:1572:gst_queue_loop:<queue20> pause task, reason: unexpected Caught interrupt -- handling interrupt. Interrupt: Stopping pipeline ... Execution ended after 121869831000 ns. Setting pipeline to PAUSED ... Setting pipeline to READY ... 0:02:06.645889000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2479:gst_play_bin_change_state:<playbin20> setting shutdown flag 0:02:06.646828000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2486:gst_play_bin_change_state:<playbin20> dynamic lock taken, we can continue shutdown 0:02:06.704874000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2618:gst_decode_bin_change_state:<decodebin20> dynlocking from thread 0x10001050 0:02:06.706655000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2618:gst_decode_bin_change_state:<decodebin20> dynlocked from thread 0x10001050 0:02:06.707723000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2619:gst_decode_bin_change_state:<decodebin20> setting shutdown flag 0:02:06.708718000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2622:gst_decode_bin_change_state:<decodebin20> dynunlocking from thread 0x10001050 0:02:06.721045000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:1537:pad_removed_cb:<qtdemux0:audio_00> Pad removed from non-grouped element 0:02:06.723339000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:1537:pad_removed_cb:<qtdemux0:video_00> Pad removed from non-grouped element 0:02:06.729217000 12101 0x10001050 DEBUG queue2 gstqueue2.c:1828:gst_queue_src_activate_push:<queue20> deactivating push mode 0:02:06.731174000 12101 0x10001050 DEBUG queue2 gstqueue2.c:1796:gst_queue_sink_activate_push:<queue20> deactivating push mode 0:02:06.740262000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:1847:gst_uri_decode_bin_change_state: paused to ready 0:02:06.744268000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:1013:remove_decoders:<uridecodebin0> removing old decoder element 0:02:06.752586000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:1272:remove_source:<uridecodebin0> removing old src element 0:02:06.757245000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2425:save_current_group:<playbin20> save current group 0:02:06.758643000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2328:deactivate_group:<playbin20> unlinking group 0x1004838c 0:02:06.760087000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2338:deactivate_group:<playbin20> unlinking selector audio/ 0:02:06.761607000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2341:deactivate_group:<playbin20> unlinking from sink 0:02:06.763803000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2345:deactivate_group:<playbin20> release sink pad 0:02:06.767469000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2338:deactivate_group:<playbin20> unlinking selector video/ 0:02:06.768776000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2341:deactivate_group:<playbin20> unlinking from sink 0:02:06.771212000 12101 0x10001050 LOG playbin2 gstplaybin2.c:2345:deactivate_group:<playbin20> release sink pad 0:02:06.775755000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2154:group_set_locked_state_unlocked:<playbin20> locked_state 1 on group 0x1004838c Setting pipeline to NULL ... 0:02:06.778040000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2448:groups_set_locked_state:<playbin20> setting locked state to 0 on allgroups 0:02:06.779035000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2154:group_set_locked_state_unlocked:<playbin20> locked_state 0 on group 0x100482b4 0:02:06.780523000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2154:group_set_locked_state_unlocked:<playbin20> locked_state 0 on group 0x1004838c 0:02:06.790318000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2304:gst_decode_group_free: group 0x100c06b8 0:02:06.792054000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2306:gst_decode_group_free:<decodebin20> locking group 0x100c06b8 from thread 0x10001050 0:02:06.794588000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2306:gst_decode_group_free:<decodebin20> locked group 0x100c06b8 from thread 0x10001050 0:02:06.796283000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:714:pad_removed_cb:<decodebin20> pad removed name: <decodebin20:src0> 0:02:06.797964000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:1844:pad_removed_cb:<playbin20> pad uridecodebin0:src0 removed from group0x1004838c 0:02:06.799506000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:1854:pad_removed_cb:<playbin20> pad 0x1004a658 removed from array 0:02:06.802756000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:714:pad_removed_cb:<decodebin20> pad removed name: <decodebin20:src1> 0:02:06.804479000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:1844:pad_removed_cb:<playbin20> pad uridecodebin0:src1 removed from group0x1004838c 0:02:06.806059000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:1854:pad_removed_cb:<playbin20> pad 0x1004a788 removed from array 0:02:06.814498000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2241:deactivate_free_recursive: element:multiqueue0 0:02:06.816301000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2287:deactivate_free_recursive:<decodebin20> locking from thread 0x10001050 0:02:06.817697000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2287:deactivate_free_recursive:<decodebin20> locked from thread 0x10001050 0:02:06.819129000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2290:deactivate_free_recursive:<decodebin20> unlocking from thread 0x10001050 0:02:06.820920000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:2341:gst_decode_group_free:<decodebin20> unlocking group 0x100c06b8 from thread 0x10001050 0:02:06.823965000 12101 0x10001050 LOG decodebin2 gstdecodebin2.c:1537:pad_removed_cb:<qtdemux0:sink> Pad removed from non-grouped element 0:02:06.828080000 12101 0x10001050 DEBUG uridecodebin gsturidecodebin.c:714:pad_removed_cb:<decodebin20> pad removed name: <decodebin20:sink> 0:02:06.832579000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2448:groups_set_locked_state:<playbin20> setting locked state to 1 on allgroups 0:02:06.835127000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2154:group_set_locked_state_unlocked:<playbin20> locked_state 1 on group 0x100482b4 0:02:06.836374000 12101 0x10001050 DEBUG playbin2 gstplaybin2.c:2154:group_set_locked_state_unlocked:<playbin20> locked_state 1 on group 0x1004838c FREEING pipeline ... 0:02:06.841309000 12101 0x10001050 DEBUG queue2 gstqueue2.c:511:gst_queue_finalize:<queue20> finalizing queue
red alert!! this is not only a problem with gst-launch but also in my application, after playing a youtube video both live from http or from a grabbed file, there's no GST_MESSAGE_EOS message on the bus ever. i'm using prereleases 0.10.22.2. of core and base.
Could you provide new debug logs ?
yes of course! just let me know which elements exactly to log and with which level since an entire level 5 debug gets too big :)
Created attachment 133247 [details] no EOF bus message :( log created with GST_DEBUG="*queue2*:5,*decodebin*:5,*playbin2*:5" enigma2 >no_eof.log 2>&1 please note, that the STOP command was manually invoked by our gui, it did not stop on its own.
Created attachment 133250 [details] more detailed log GST_DEBUG=*queue*:5,*decodebin*:5,*playbin*:5,*EVENT*:5,*MESSAGE*:5,*sink:4 enigma2 >no_eof_3.log 2>&1
That's a bug in your audiosink, it's not handling EOS properly.