GNOME Bugzilla – Bug 591934
timestamp drift in audioresample
Last modified: 2009-09-10 07:40:28 UTC
The audioresample element uses a running total of the durations of past output buffers to compute the timestamp of each new output buffer. For buffers whose lengths are not an integer number of nanoseconds, this results in an accumulation of round-off error, and a growing phase error in the output. The patch attached fixes the problem by re-working the timestamp and offset book-keeping. the next_offset, next_ts and next_upstream_ts in the element instance are replaced with t0, in_offset0, out_offset0, next_in_offset, and next_out_offset. t0 and in_offset0 are the timestamp and sample offset at the input at the most recent stream discontinuity (or new segment). out_offset0 is computed from in_offset0 by scaling by the ratio of the sample rates, and is the output sample offset at the most recent stream discontinuity. next_in_offset and next_out_offset are initialized to in_offset0 and out_offset0 respectively, and are incremented as samples are clocked through the resampler. They always indicate the start offset of the next expected input and output buffers respectively. Non-flagged discontinuities are identified by comparing the observed input offset to the expected input offset, next_in_offset. The timestamp of each output buffer is computed from the number of output samples that have been produced so far, (next_out_offset-out_offset0), the sample rate, and t0 (the timestamp when the offset was out_offset0). t0 is set to GST_CLOCK_TIME_NONE if no valid timestamp information has been extracted from the input stream. This patch relies on bug #590919, and obsoletes the patches in bug #586570 (which we will re-work and re-submit after this problem is resolved).
Created attachment 140863 [details] [review] fix timestamp drift by re-working timestamp and offset book-keeping
(In reply to comment #1) > Created an attachment (id=140863) [details] > fix timestamp drift by re-working timestamp and offset book-keeping hmm. bugzilla refused to allow me to upload a patch, it says I must select a valid "status" for the attachment but there is no facility to change the status from "None" --- there's no drop-down list, no text entry, it's just hard-coded text in the add attachment page.
I think the bugzilla installation is being updated at the moment, so expect a few hickups. People in #bugs on irc.gimp.org might be able to help with problems. Any chance you could whip up a unit test for this issue? (tests/check/elements/audioresample.c)
Comment on attachment 140863 [details] [review] fix timestamp drift by re-working timestamp and offset book-keeping Looks good, I'll commit it if you provide a unit test for the problem that this fixes :)
Here's a before and after comparison of the resampler (plots to follow). I ran the following pipeline without and without the patch. The "nxydump" element is a thing we've got going locally that converts an audio stream into an ascii, n-column, "time val val val ..." dump that can be plotted with grace. I should probably consider proposing it for inclusion in gstreamer (-bad?) because it's a useful debugging tool. Anyway, what's going on here is the sample rates of 16384 Hz and 4096 Hz mean that individual samples don't fall on integer nanosecond boundaries (some do, but not all), and in particular with 10 samples per buffer the buffer boundaries don't fall on integer nanoseconds. The current version of the resampler drifts its timestamps when fed a stream like this. The patch fixes it by using the integer sample count as the clock for the stream (always tells the right time because sample count really is an integer), and computes timestamps and durations for each buffer from that with rounding. Note in particular that the patch should assign durations to each buffer that are rounded so that any downstream element that does the "silly" thing of keeping a running total of buffer durations actually knows the correct total elapsed time in the stream (to the nearest nanosecond). gst-launch \ audiotestsrc wave=0 freq=1024 samplesperbuffer=10 num-buffers=1000000 \ ! audio/x-raw-float, channels=1, width=64, rate=16384 \ ! tee name=input \ ! audioresample \ ! audio/x-raw-float, rate=4096 \ ! lal_nxydump start-time=0 stop-time=1000000000000 \ ! queue ! filesink buffer-mode=2 location="dump_out.txt" \ input. \ ! lal_nxydump start-time=0 stop-time=1000000000000 \ ! queue ! filesink buffer-mode=2 location="dump_in.txt"
Created attachment 141039 [details] Input in blue, output in red. Start of stream. Without patch.
Created attachment 141040 [details] Input in blue, output in red. After 600 seconds. Without patch.
Created attachment 141041 [details] Input in blue, output in red. Start of stream. With patch. This part of the stream appears unchanged. (it basically is).
Created attachment 141042 [details] Input in blue, output in red. After 600 seconds. With patch. Looks exactly like the start of the stream. No phase shift. You can even flip back and forth in an image viewer and except for the axis labels you can't tell the difference! :-)
(In reply to comment #9) > Created an attachment (id=141042) [details] > Input in blue, output in red. After 600 seconds. With patch. > > Looks exactly like the start of the stream. No phase shift. You can even flip > back and forth in an image viewer and except for the axis labels you can't tell > the difference! :-) But I didn't fake it, I promise.
(In reply to comment #10) > (In reply to comment #9) > > Created an attachment (id=141042) [details] [details] > > Input in blue, output in red. After 600 seconds. With patch. > > > > Looks exactly like the start of the stream. No phase shift. You can even flip > > back and forth in an image viewer and except for the axis labels you can't tell > > the difference! :-) > > But I didn't fake it, I promise. Heh, looks good, yes :) But what Tim and I asked for was a unit test that we can have in tests/check/gst/audioresample.c to make sure that this is never broken again. It should run the pipeline for some time and then check if there's a timestamp drift again.
(In reply to comment #11) > (In reply to comment #10) > > (In reply to comment #9) > > > Created an attachment (id=141042) [details] [details] [details] > > > Input in blue, output in red. After 600 seconds. With patch. > > > > > > Looks exactly like the start of the stream. No phase shift. You can even flip > > > back and forth in an image viewer and except for the axis labels you can't tell > > > the difference! :-) > > > > But I didn't fake it, I promise. > > Heh, looks good, yes :) But what Tim and I asked for was a unit test that we > can have in tests/check/gst/audioresample.c to make sure that this is never > broken again. It should run the pipeline for some time and then check if > there's a timestamp drift again. Ok, sure, sorry I didn't understand. I'll go see what I can come up with. Thanks,
Created attachment 141129 [details] [review] fix buffer overflow in push_drain() the original patch introduced a buffer overflow into the push_drain() method. this patch fixes it. Needs to be applied on top of patch 140863.
I'm not sure if this is an appropriate unit test, but the following pipeline can be used to detect the timestamp drift from the command line: gst-launch \ audiotestsrc wave=0 freq=1024 samplesperbuffer=10 num-buffers=1000000 \ ! audio/x-raw-float, channels=1, width=64, rate=16384 \ ! audioresample \ ! audio/x-raw-float, rate=4096 \ ! testsink sync=false allowed-timestamp-deviation=0 With the original resampler, this pipeline terminates with the message ERROR: from element /GstPipeline:pipeline0/GstTest:test0: The stream is in the wrong format. Additional debug info: testplugin.c(223): gst_test_sink_event (): /GstPipeline:pipeline0/GstTest:test0: test timestamp-deviation returned value "8" and not expected value "0" with the patched version, the pipeline runs to completion without an error message. Unfortunately gst-launch doesn't exit with a non-zero exit code when the pipeline emits an error, so it's not easy to test for the failure from a shell script. One could grep for "timestamp-deviation" in the output to stderr: gst-launch \ audiotestsrc wave=0 freq=1024 samplesperbuffer=10 num-buffers=1000000 \ ! audio/x-raw-float, channels=1, width=64, rate=16384 \ ! audioresample \ ! audio/x-raw-float, rate=4096 \ ! testsink sync=false allowed-timestamp-deviation=0 2>&1 \ | grep "timestamp-deviation" -q && echo "fail" || echo "pass"
(In reply to comment #13) > Created an attachment (id=141129) [details] > fix buffer overflow in push_drain() > > the original patch introduced a buffer overflow into the push_drain() method. > this patch fixes it. Needs to be applied on top of patch 140863 [details]. Oh right, thanks. That's of course the right thing to do :) You don't need to include gstutils.h though, that's already included as part of gst.h. I'll remove that when committing it. (In reply to comment #14) > I'm not sure if this is an appropriate unit test, but the following pipeline > can be used to detect the timestamp drift from the command line: > > gst-launch \ > audiotestsrc wave=0 freq=1024 samplesperbuffer=10 num-buffers=1000000 \ > ! audio/x-raw-float, channels=1, width=64, rate=16384 \ > ! audioresample \ > ! audio/x-raw-float, rate=4096 \ > ! testsink sync=false allowed-timestamp-deviation=0 > > With the original resampler, this pipeline terminates with the message > > ERROR: from element /GstPipeline:pipeline0/GstTest:test0: The stream is in the > wrong format. > Additional debug info: > testplugin.c(223): gst_test_sink_event (): > /GstPipeline:pipeline0/GstTest:test0: > test timestamp-deviation returned value "8" and not expected value "0" > > with the patched version, the pipeline runs to completion without an error > message. > > Unfortunately gst-launch doesn't exit with a non-zero exit code when the > pipeline emits an error, so it's not easy to test for the failure from a shell > script. One could grep for "timestamp-deviation" in the output to stderr: That's not exactly what we need, also testsink is not part of any gstreamer modules yet (would be nice to have patches to get testsink and nxydump into gst-plugins-bad btw). What we need is some code to do essentially what your gst-launch line does. Take a look at the existing code in tests/check/elements/audioresample.c for example. Whatever, I'll write a testcase for that later and attach it here too ;)
(In reply to comment #15) > (In reply to comment #13) > > Created an attachment (id=141129) [details] [details] > > fix buffer overflow in push_drain() > > > > the original patch introduced a buffer overflow into the push_drain() method. > > this patch fixes it. Needs to be applied on top of patch 140863 [details] [details]. > > Oh right, thanks. That's of course the right thing to do :) You don't need to > include gstutils.h though, that's already included as part of gst.h. I'll > remove that when committing it. > > (In reply to comment #14) > > I'm not sure if this is an appropriate unit test, but the following pipeline > > can be used to detect the timestamp drift from the command line: > > > > gst-launch \ > > audiotestsrc wave=0 freq=1024 samplesperbuffer=10 num-buffers=1000000 \ > > ! audio/x-raw-float, channels=1, width=64, rate=16384 \ > > ! audioresample \ > > ! audio/x-raw-float, rate=4096 \ > > ! testsink sync=false allowed-timestamp-deviation=0 > > > > With the original resampler, this pipeline terminates with the message > > > > ERROR: from element /GstPipeline:pipeline0/GstTest:test0: The stream is in the > > wrong format. > > Additional debug info: > > testplugin.c(223): gst_test_sink_event (): > > /GstPipeline:pipeline0/GstTest:test0: > > test timestamp-deviation returned value "8" and not expected value "0" > > > > with the patched version, the pipeline runs to completion without an error > > message. > > > > Unfortunately gst-launch doesn't exit with a non-zero exit code when the > > pipeline emits an error, so it's not easy to test for the failure from a shell > > script. One could grep for "timestamp-deviation" in the output to stderr: > > That's not exactly what we need, also testsink is not part of any gstreamer > modules yet (would be nice to have patches to get testsink and nxydump into > gst-plugins-bad btw). > > What we need is some code to do essentially what your gst-launch line does. > Take a look at the existing code in tests/check/elements/audioresample.c for > example. Whatever, I'll write a testcase for that later and attach it here too > ;) Actually, testsink is in gst-plugins-good (in the "debug" plugin). But I understand, I guess it's best if gstreamer's unit tests require only code available in gstreamer proper, not elements from other packages. Don't worry, I'll try again. I think I'm iterating towards what you want :-) ...
So, I looked into patching the existing audioresample unit test code in gst-plugins-base, but it's segfaulting on me. I mean, it segfaults when building and running it on the master branch (before applying any patches from this PR). I'm a bit stumped. Does it run correctly for you guys?
(In reply to comment #17) > So, I looked into patching the existing audioresample unit test code in > gst-plugins-base, but it's segfaulting on me. I mean, it segfaults when > building and running it on the master branch (before applying any patches from > this PR). I'm a bit stumped. Does it run correctly for you guys? Yes, it works for me. Could you get a backtrace and open a new bug for that? I'll care for a unit test for this problem now, don't worry this time :)
But then, the unit test doesn't work anymore after applying your patch :) ** ERROR:gstaudioresample.c:841:gst_audio_resample_push_drain: assertion failed: (out_len >= out_processed) 57%: Checks: 7, Failures: 2, Errors: 1 elements/audioresample.c:155:F:general:test_perfect_stream:0: 'timestamp' (0) is not equal to 'GST_BUFFER_TIMESTAMP (buffer)' (18446744073709551615) elements/audioresample.c:309:F:general:test_discont_stream:0: 'ints' (0) is not equal to 'GST_BUFFER_TIMESTAMP (outbuffer)' (18446744073709551615) elements/audioresample.c:628:E:general:test_pipelines:0: (after this point) Received signal 6 (Abgebrochen) I'll look into that too (this evening probably), unless you're faster :)
(In reply to comment #19) > But then, the unit test doesn't work anymore after applying your patch :) > > ** > ERROR:gstaudioresample.c:841:gst_audio_resample_push_drain: assertion failed: > (out_len >= out_processed) > 57%: Checks: 7, Failures: 2, Errors: 1 > elements/audioresample.c:155:F:general:test_perfect_stream:0: 'timestamp' (0) > is not equal to 'GST_BUFFER_TIMESTAMP (buffer)' (18446744073709551615) > elements/audioresample.c:309:F:general:test_discont_stream:0: 'ints' (0) is not > equal to 'GST_BUFFER_TIMESTAMP (outbuffer)' (18446744073709551615) > elements/audioresample.c:628:E:general:test_pipelines:0: (after this point) > Received signal 6 (Abgebrochen) > > I'll look into that too (this evening probably), unless you're faster :) Ok, the unit test is fixed now. There were some minor bugs at some places. Now I'll write the new unit test ;)
commit d6e698e1101e258a4787f27dd7693a83478d3625 Author: Sebastian Dröge <sebastian.droege@collabora.co.uk> Date: Fri Aug 21 11:51:47 2009 +0200 audioresample: Add unit test for checking for timestamp drifts This also checks for perfect timestamping and offsetting. commit 8d445e04abd05735ad44b9a5d2d8fb50ab215435 Author: Sebastian Dröge <sebastian.droege@collabora.co.uk> Date: Fri Aug 21 10:11:23 2009 +0200 audioresample: Fix drain processing In case we have to convert internally don't process output length input samp but history length input samples. commit 780368880b3364e2b034a88787ad42763b8c764e Author: Sebastian Dröge <sebastian.droege@collabora.co.uk> Date: Fri Aug 21 10:02:05 2009 +0200 audioresample: Improve debugging a bit in the unit test commit 989e3d9cb1a34b283d2c95ac8cbfde09528768c8 Author: Sebastian Dröge <sebastian.droege@collabora.co.uk> Date: Fri Aug 21 10:00:49 2009 +0200 audioresample: On the first buffer we need discont handling Otherwise we won't get upstream timestamps and everything and all output buffers would have -1 timestamps. commit 6621631dd0e5fb17afb2ff1a7ebbf90ffb63a215 Author: Kipp Cannon <kcannon@ligo.caltech.edu> Date: Fri Aug 21 06:58:31 2009 +0200 audioresample: Fix buffer overflow when pushing the drain commit 41e74aa61bd5e92d4e6b5d0fe2b1a552189eb440 Author: Kipp Cannon <kcannon@ligo.caltech.edu> Date: Fri Aug 21 06:57:58 2009 +0200 audioresample: Fix timestamp drift Fixes bug #591934.
(In reply to comment #20) > (In reply to comment #19) > > But then, the unit test doesn't work anymore after applying your patch :) > > > > ** > > ERROR:gstaudioresample.c:841:gst_audio_resample_push_drain: assertion failed: > > (out_len >= out_processed) > > 57%: Checks: 7, Failures: 2, Errors: 1 > > elements/audioresample.c:155:F:general:test_perfect_stream:0: 'timestamp' (0) > > is not equal to 'GST_BUFFER_TIMESTAMP (buffer)' (18446744073709551615) > > elements/audioresample.c:309:F:general:test_discont_stream:0: 'ints' (0) is not > > equal to 'GST_BUFFER_TIMESTAMP (outbuffer)' (18446744073709551615) > > elements/audioresample.c:628:E:general:test_pipelines:0: (after this point) > > Received signal 6 (Abgebrochen) > > > > I'll look into that too (this evening probably), unless you're faster :) > > Ok, the unit test is fixed now. There were some minor bugs at some places. Now > I'll write the new unit test ;) Thank you! Yeah, I don't know what was going on at my end, I just erased everything, recompiled from scratch, and now it's working again. I think some stuff moved between packages and I was maybe getting weird symbol collisions. Anyway, yeah so then I found that problem you spotted too: in the unit tests the resampler isn't always resetting the timestamp tracking info. Was the problem with the unit test or the element? It looks to me like the unit test isn't always preceding each test stream with a newsegment event, but I don't know if that's a problem with the unit test or if the element is supposed to deal with that.
(In reply to comment #5) > Here's a before and after comparison of the resampler (plots to follow). I ran > the following pipeline without and without the patch. The "nxydump" element is > a thing we've got going locally that converts an audio stream into an ascii, > n-column, "time val val val ..." dump that can be plotted with grace. I should > probably consider proposing it for inclusion in gstreamer (-bad?) because it's > a useful debugging tool. > Sounds cool. Could you add that to gst/debugutils plugin and file a new bug with a patch? Bonus points if the patch has a docblob telling how to use it :)
Small addition to my previous comment. What I used in the past is outputting raw data to filesink and plotting useing gnuplot: plot [0:] [-35000:35000] 'output1.raw' binary format="%short" using 1 with lines