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 340697 - gstsystemclock hangs when outputting to stdout via fdsink
gstsystemclock hangs when outputting to stdout via fdsink
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
0.10.5
Other Linux
: Normal normal
: 0.10.6
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2006-05-05 02:52 UTC by Andres Salomon
Modified: 2006-05-08 09:16 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description Andres Salomon 2006-05-05 02:52:09 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
Comment 1 Wim Taymans 2006-05-05 14:32:03 UTC
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...
Comment 2 Wim Taymans 2006-05-05 15:29:52 UTC
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.
Comment 3 Wim Taymans 2006-05-08 09:16:31 UTC
        * 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.