GNOME Bugzilla – Bug 578612
[flacdec] seek on flac file sometimes triggers flac decoder ABORT
Last modified: 2009-07-30 10:21:24 UTC
It seems like a race. It happens about 1 out of 10 attempts. Attaching a debug 5 log of my application, which simply pauses a pipeline, sends a flushing seek (for the whole length of the file), sets it to play, and pulls buffers from appsink.
Created attachment 132471 [details] logfile
After some probing, it seems it happens when I have a queue in my pipeline. Attaching an example program; run it like this: GST_DEBUG=*:2 python flacseek.py /home/thomas/gst/media/small/dark.441-16-s.flac and it will show this: loop 0 loop 1 loop 2 0:00:00.248875112 6535 0x8a99810 WARN GST_SCHEDULING gstpad.c:4474:gst_pad_pull_range:<flacdec2:sink> pullrange failed wrong-state 0:00:00.249019475 6535 0x8a99810 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec2> error: FLAC__STREAM_DECODER_ABORTED 0:00:00.249176690 6535 0x87a2090 WARN flacdec gstflacdec.c:1772:gst_flac_dec_handle_seek_event:<flacdec2> seek failed 0:00:00.249334114 6535 0x8a99810 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec2> error: FLAC__STREAM_DECODER_ABORTED loop 3 loop 4 loop 5 loop 6 0:00:00.299152927 6535 0xb66810e8 WARN GST_SCHEDULING gstpad.c:4474:gst_pad_pull_range:<flacdec6:sink> pullrange failed wrong-state 0:00:00.299202445 6535 0xb66810e8 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec6> error: FLAC__STREAM_DECODER_ABORTED 0:00:00.299328789 6535 0x87a2090 WARN flacdec gstflacdec.c:1772:gst_flac_dec_handle_seek_event:<flacdec6> seek failed 0:00:00.299451572 6535 0xb66810e8 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec6> error: FLAC__STREAM_DECODER_ABORTED loop 7 0:00:00.301697203 6535 0xb6684be0 WARN GST_SCHEDULING gstpad.c:4474:gst_pad_pull_range:<flacdec7:sink> pullrange failed wrong-state 0:00:00.301729819 6535 0xb6684be0 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec7> error: FLAC__STREAM_DECODER_ABORTED 0:00:00.301845338 6535 0x87a2090 WARN flacdec gstflacdec.c:1772:gst_flac_dec_handle_seek_event:<flacdec7> seek failed 0:00:00.301959320 6535 0xb6684be0 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec7> error: FLAC__STREAM_DECODER_ABORTED loop 8 loop 9 loop 10 0:00:01.337539321 6535 0xaba107d8 WARN GST_SCHEDULING gstpad.c:4474:gst_pad_pull_range:<flacdec10:sink> pullrange failed wrong-state 0:00:01.337580388 6535 0xaba107d8 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec10> error: FLAC__STREAM_DECODER_ABORTED 0:00:01.337655608 6535 0x87a2090 WARN flacdec gstflacdec.c:1772:gst_flac_dec_handle_seek_event:<flacdec10> seek failed 0:00:01.337699957 6535 0xaba107d8 WARN flacdec gstflacdec.c:1141:gst_flac_dec_loop:<flacdec10> error: FLAC__STREAM_DECODER_ABORTED loop 11 loop 12 Removing the queue from the example makes it not give STREAM_DECODER_ABORTED (although it will hang at some point, indicating other races)
Created attachment 132499 [details] test case
For me sometimes = almost always. This is not a regression, since it happens with the last release as well apparently, but important enough.
Created attachment 138933 [details] [review] flacdec: fix intermittent FLAC__STREAM_DECODER_ABORTED errors when seeking This fixes it for me.
commit 375976c847b80ab40ff30e1e5cef91ff12bddf50 Author: Tim-Philipp Müller <tim.muller@collabora.co.uk> Date: Tue Jul 21 19:46:55 2009 +0100 flacdec: fix intermittent FLAC__STREAM_DECODER_ABORTED errors when seeking When seeking in a local flac file (ie. operating pull-based), the decoder would often just error out after the loop function sees a DECODER_ABORTED status. This, however, is the read callback's way of telling our loop function that pull_range failed and streaming should stop, in this case because of the flush-start event that the seek handler pushed upstream from the seeking thread. Handle this slightly better by storing the last flow return from pull_range, so the loop function can evaluate it properly when it encounters a DECODER_ABORTED and take the right action. Fixes #578612.
Apparently not enough to get it working though. It fails to play back any sound after seeking: https://bugzilla.redhat.com/show_bug.cgi?id=508253#c5 Shall I open a new bug?
> Shall I open a new bug? Yes, please. Might be related to my patch or not, hard to say. A GST_DEBUG=*:5 log or so would be appreciated. Works fine for me now with git of everything (and pulsesink), fwiw.
I can confirm that updating *all* gstreamer modules to git master as of yesterday seems to fix the playback problem. During my test seeks I got a number of segfaults though... Should I file a new bug for this now and if yes, what kind of information should I attach? (smallest GST_DEBUG=*:5 log I came up with is 136MB, still 4.5MB compressed)
Yes, please file a new bug (unless it looks like it's the same as bug #589849). A GST_DEBUG=*sink:5,flac*:5,*audio*:5 log might be sufficient as well.