GNOME Bugzilla – Bug 340697
gstsystemclock hangs when outputting to stdout via fdsink
Last modified: 2006-05-08 09:16:31 UTC
Hi, Running the following pipeline causes a hang after the decode finishes: gst-launch-0.10 filesrc location=down.mp3 ! mad ! audioconvert ! vorbisenc ! oggmux ! fdsink > x That writes to stdout, but when it finishes decoding, instead of exiting, it will simply hang (I think for the length of the song, but possibly infinitely). I reported this in #gstreamer; here's the relevant bits: 17:30 < dilinger> gst-launch-0.10 filesrc location=01-down.flac ! flacdec ! audioconvert ! vorbisenc ! oggmux ! fdsink >/dev/null 17:30 < dilinger> that basically decodes the entire file (when using filesink location=x vs. fdsink > x, both files end up the same size) 17:31 < dilinger> however, it hangs at the end; afaict, there's no EOS getting sent 17:31 < dilinger> it's not hanging anywhere inside fdsink; i added a bunch of fprintfs to the code 17:31 < dilinger> w/ debug level set to 5, this is the last line 17:32 < dilinger> EBUG (0x80792a0 - 0:00:14.427177000) GST_CLOCK( 6668) gstsystemclock.c(383):gst_system_clock_id_wait_unlocked: entry 0x8183dc0 target 318549:29:21.811932332 entry 318549:29:21.811930332 now 318549:26:42.760279000 real 318549:26:42.760279000 diff 159051651332 17:32 < dilinger> at some point, gstpad sees the EOS: 17:32 < dilinger> DEBUG (0x80792a0 - 0:00:14.427032000) GST_EVENT( 6668) gstpad.c(3784):gst_pad_send_event: have event type eos on pad fdsink:sink 17:33 < dilinger> after that, the Gst*Clock seems to just hang 17:37 < dilinger> if i had to guess, i would say that gst_system_clock_id_wait_unlocked is hanging 17:41 < dilinger> hm, yep 17:41 < dilinger> DEBUG (0x80792a0 - 0:00:13.803882000) GST_CLOCK( 6849) gstsystemclock.c(389):gst_system_clock_id_wait_unlocked: entering loop 17:41 < dilinger> ok, so it gets stuck in there, infinitely looping 17:43 < dilinger> hm, so diff is in nanoseconds.. 17:45 < dilinger> so for some reason, this is attempting to wait 159 seconds? 17:45 < dilinger> now 318549:40:25.047062000 => target 318549:43:04.717443332 17:51 < moch_> dilinger: does setting sync=false on the fdsink help? 17:53 < dilinger> moch_: hm, yes; setting sync=false causes it to exit 17:53 < dilinger> moch_: exit properly, i mean 17:55 < moch_> dilinger: I guess that means something is generating a broken timestamp, but I wouldn't really know where to look for that. 18:01 < mathrick> dilinger: I tried with mp3 file and mad, and it works with no hitch 18:02 < dilinger> mathrick: strange 18:02 < mathrick> GStreamer Core Library version 0.10.4 18:02 < dilinger> ii libgstreamer0. 0.10.5-0bpo1 Core GStreamer libraries 18:12 < moch_> it does the same here 18:15 < dilinger> moch_: good, so it's not just me 18:15 < dilinger> moch_: it looks like it's hanging for the length of the song 18:16 < mathrick> moch_: what version do you have? 18:17 < moch_> mathrick: currentish cvs 18:17 < moch_> I don't think this is actually a bug, I think it's what sync=true is meant to do. 18:17 < mathrick> then it might have been introduced after 10.4 18:17 < moch_> although maybe it should have been waiting for the system clock to catch up all the way through.. I don't know. 18:18 < mathrick> yeah
note that fdsink will synchronize to the clock for each buffer, which is not desirable for writing to a file descriptor (but might be when writing to a network socket). Setting sync=false for this use case would not make it hang on EOS. The proper fix is to figure out why it hangs though...
ugh.. it's even worse. fdsink sets sync to TRUE but then sets get_times to NULL. The effect is that sync will _not_ be done on buffers but it will be done on EOS.
* libs/gst/base/gstbasesink.c: (gst_base_sink_get_sync_times), (gst_base_sink_do_sync), (gst_base_sink_chain_unlocked), (gst_base_sink_get_position), (gst_base_sink_change_state): Store the sync time of the buffer end position separatly in a new variable eos_rtime so we can properly sync the EOS event. Fixes #340697. Fix the docs for gst_base_sink_set_qos_enabled(). Don't set segment start to invalid value when we receive a non TIME newsegment. get closer to handling position reporting for negative rates correctly.