This will need more explanation.

It seems like you want to use a monotonic clock for the pipeline and then try to avoid the clock slaving because you know that the alsa API also uses the monotonic clock for the timestamps.

for example, what is the problem?

Is the problem that there is an undefined delay between getting the pipeline clock timestamp and the alsa device delay?

This is exactly the problem that we want to resolve. No matter what target we are running our firmware on, or the load of the system we want to have consistent timestamps in the pipeline. This is important for us in order to have perfectly synchronized audio and video. This method is also used by us to timestamp the video pipeline from our video source element.

Just for the record, we should do something similar on v4l2src. The v4l2 kernel side switched to monotonic clock as well and we currently introduce quite some timestamp jitter by setting a timestamp when user-space is scheduled instead of taking the timestamp from kernelspace. If we want to do that configurable by a gobject-property, I would call it "use-driver-timestamps" or something similar.

Although I have not understood yet, why the patch is modifying basesrc.

The problem is that these kernel timestamps may or may not have anything to do with the pipeline clock. 

The usual thing to do is to take a snapshot of the pipeline clock and the same monotonic clock and then subtract the monotonic clock diff from the pipeline clock timestamp.

Since our application must stream synchronized video/audio for weeks or months without interruptions we can't use two clocks because of the clock drift between these.

To have the best synchronization and the least amount of jitter we want to
1) Use the same clock to time stamp audio and video and 'drive' the pipeline
2) Take the audio and video buffer time stamps as close to the hardware as possible.

Patrick, Wims comment is all that we need to do. If you ensure that all components use the smae clock, the delta is constant and there is no drift. Its just so that we can't make assumptions on the gstreamer level.

Stefan, your comment is very true if drift was all we needed to address. Unfortunately, in a heavily loaded system it is possible that our user space gstreamer application is scheduled so that large delays are introduced before being able to serve timestamps. Thus introducing either a constant audio delay or a jitter depending on implementation.

With the suggested architectural changes we stand a better chance of getting an accurate timestamp in these situations.

So is there still anything that needs to be done here?

I think there are at least two other ways of doing it, without adding new properties:

1. alsasrc always use driver timestamps and provides a clock which is an instance of GstSystemClock that uses the monotonic clock. Does this ensure that the src element will always timestamp correctly according to the pipeline clock?

2. alsasrc checks if the pipeline (element) clock is an instance of GstSystemClock with clock-type set to monotonic clock and in that case uses driver timestamps, otherwise it will do what it does in the current implementation. The application will have to make sure the pipeline uses monotonic clock or the alsasrc will work exactly as before.

Would any of those two alternatives work without problems in an arbitrary pipeline?

Continuing with the ideas from Jonas for doing this automatically, (combining 1 and 2), I think the following should work.

* alsasrc always provides a clock, the monotonic clock
* when alsasrc changes state from PAUSED to PLAYING it checks the pipeline clock. If it's the monotonic clock it uses alsa driver time stamps. If it's a different clock it uses that clock to time stamp the buffers.

So, as long as a different clock isn't chosen for the pipeline alsa driver time stamps will always be used. And if a different clock is chosen, that clock will be used and everything will still work (as it does today)


The only side effect of this that I can think of is that it changes the clock that is used today when alsasrc is the clock provider. From time stamps based on the number of samples played to alsa driver samples. But I would think that driver time stamps always are to be preferred, or?

Conclusion after IRC discussion with Wim

- alsasrc should continue to provide the sample based clock as default clock (this clock is more accurate).

- when alsasrc changes state from PAUSED to PLAYING it checks the pipeline
clock. If it's the monotonic clock it uses alsa driver time stamps. If it's a
different clock it uses that clock to time stamp the buffers.

- to enable alsa driver time stamping it's up to the application controlling the pipeline to set the monotonic clock on the pipeline.

No extra properties are thus needed and alsasrc will work like it does today unless you set the monotonic clock on the pipeline, in which case you will get more accurate monotonic timestamps since they are taken from the driver.

Created attachment 178307 [details] [review]
New patch based on discussions and new suggestions on implementation.

This new patch removes the need for an element property to control the timestamp behavior. The clock is examined when the pipeline changes state from paused to playing and depending on what clock is used, driver timestamps or the normal sample clock timestamps are used.

Yes, looks good now.

So I guess there is no open question left. Hence I am reopening. There is a patch attached, so it'd be nice if anybody could review that :)

Indeed, is there anything more that i can do to speed up the process ?

I will commit this after the freeze.

commit 2b84f5bd74ddb50f7832917ea8b4dd38d005631b
Author: Sebastian Dröge <sebastian.droege@collabora.co.uk>
Date:   Mon May 9 12:56:14 2011 +0200

    alsasrc: Fix some compilation errors

commit 0b774e0b7cf7a8ef1780fb6100228ca6e8ca8bcf
Author: Pontus Oldberg <pontus.oldberg@invector.se>
Date:   Mon May 9 11:50:05 2011 +0200

    alsasrc: Improve timestamp accuracy
    
    Fixes bug #635256.

This seems to break one of the unit tests:

tpm@zingle:~/gst/clean/gst-plugins-base/tests/check$ make pipelines/basetime.check
Running suite(s): baseaudiosrc
0%: Checks: 1, Failures: 1, Errors: 0
pipelines/basetime.c:49:F:general:test_basetime_calculation:0: Two buffers had same timestamp
Running suite(s): baseaudiosrc
0:00:00.074727869  1872      0x257eb70 WARN                     bin gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
0:00:02.083683685  1872      0x24cf300 WARN                     bin gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
0%: Checks: 1, Failures: 1, Errors: 0
pipelines/basetime.c:49:F:general:test_basetime_calculation:0: Two buffers had same timestamp
make: *** [pipelines/basetime.check] Error 1

(Have not investigated further)

I'm looking into it right now.

Pontus, are you still looking into this?

Yes I am. At the moment it looks like the problem is not in the patch itself, instead it looks like the alsa library is simply returning 0 in the timestamps. I have not been able yet to determine why but I am still looking in to it.
/Pontus

I was also noticing the failing test, but not aware of the bug and thus change the test:
commit 7ca9c4ec407d44bad934ba3bd9f7aec550b17cf8
Author: Stefan Sauer <ensonic@google.com>
Date:   Tue Jul 26 13:51:31 2011 +0200

    basetime: fix failing test
    
    Always use audiotestsrc as it seems to have been the intention according to the
    comment header. The test does not work with live-audiosources.

This could be reverted if we figure out a solution. For me the test was running on alsasrc and got 1 ts, another ts that was larger and then the same ts again.

Pontus, any news?

Someone will need to look at this before the next release and understand what's happening, so we can determine if the test is wrong or the new behaviour is wrong.

Otherwise we'll have to revert the patch.

This is what happens for alsasrc:

Running suite(s): baseaudiosrc
pipelines/basetime.c:60:test_basetime_calculation: test start
gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
pipelines/basetime.c:49:buffer_probe_cb: ts = 5124095:34:33.682703544
pipelines/basetime.c:49:buffer_probe_cb: ts = 5124095:34:33.677624179
pipelines/basetime.c:49:buffer_probe_cb: ts = 5124095:34:33.677624179
0%: Checks: 1, Failures: 1, Errors: 0
pipelines/basetime.c:53:F:general:test_basetime_calculation:0: Two buffers had same timestamp: 5124095:34:33.677624179

for audiotestsrc is-live{true,false} and pulsesrc we get e.g.:

Running suite(s): baseaudiosrc
pipelines/basetime.c:60:test_basetime_calculation: test start
pulsemixerctrl.c:365:gst_pulsemixer_ctrl_open:<pulsesrc0> Failed to get source info: Invalid argument
gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.039831769
gstbin.c:2395:gst_bin_do_latency_func:<pipeline0> did not really configure latency of 0:00:00.000000000
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.065818163
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.091804558
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.117790952
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.143777347
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:02.169763741
...
pipelines/basetime.c:49:buffer_probe_cb: ts = 0:00:03.988811360
gstaudiosrc.c:237:audioringbuffer_thread_func:<pulsesrc0> error reading data -1 (reason: Success), skipping segment
pipelines/basetime.c:124:test_basetime_calculation: cleaning up tasks
100%: Checks: 1, Failures: 0, Errors: 0

If I don't make the test fail, but just print a warning, we can see that the timestamps for alsasrc are never increasing.

Created attachment 192740 [details] [review]
make sure we have increasing timestamps

This makes the test work. Not sure if that's the right thing to do though.

There has been alsa bugs, but those I found are supposed to be fixed:
http://www.spinics.net/lists/alsa-devel/msg10789.html

I have had no luck in recreating this error. I have built master on gstreamer and gst-plugins-base as well as version 1.0.24.1 of alsa-lib. Stefans's rewrite of the testcase (test_basetime_calculation) to use audiotestsrc instead of alsasrc as an audio source works as expected, BUT I also tried to change the test back to using alsasrc as an audio source and it still works fine here for me with a good monotonic clock source being reported.

Having a fallback clock source is not a good solution for this since we've explicitly told the pipeline to use/expect the monotonic clock.

I'm not sure how to proceed, but if someone can verify my findings I'd appreciate it.

For more breakage, see bug #660170.

I am going to revert this if no one looks into it and sees if it's fixable.

Hello,

The patch that came out of this report: 0b774e0b7cf7a8ef1780fb610022 (in -base) broke time-stamping in the simple pipeline: `gst-launch alsasrc ! audiorate ! filesink=/dev/null'. See Bug #660170 which I filed earlier today. Reverting that patch fixes that bug.

Thanks!

Fixable (just ignore those timestamps if ALSA returns a 0 timestamp).
Patch on the other bug.

I'll have a go at this again.

Pontus, Vincent's latest patch on the other bug (#660170) fixes this.

(In reply to comment #26)
> Created an attachment (id=192740) [details] [review]
> make sure we have increasing timestamps
> 
> This makes the test work. Not sure if that's the right thing to do though.

Is this patch still valid? IMHO checking if the driver supports timestamps first makes sense

I think its a good idea. I retested the pipelines in Bug 660170 with my patch applied and run the tests. No regression, will push the patch.

I hate to be the bringer of bad news, but in this case I have to.
My patch is seriously flawed and should really be pulled from the repo, and I'll attempt to explain why.

Basically, create and read are executed in separate threads which can (and will) cause a situation where create and read are not synchronized. In our application this has caused the framework to generate two consecutive equal timestamps (i.e. create is executed twice before a read operation is performed). This situation is more likely to appear in a loaded system, at least this is where we have seen the problems. There is also another problem with some alsa pcm drivers, where the avail parameter is not correctly exposed to the alsa-lib. This also need to be taken into consideration in a new implementation.

I am working on a completely new solution to obtain perfectly synchronized timestamps but it is not anywhere near ready yet.

Reverted these for the release:

commit e88e47cd247e6e573485093cd82e40de087a8193
Author: Tim-Philipp Müller <tim.muller@collabora.co.uk>
Date:   Wed Nov 30 23:15:35 2011 +0000

    Revert "alsasrc: Improve timestamp accuracy"
    
    This reverts commit 0b774e0b7cf7a8ef1780fb6100228ca6e8ca8bcf.

commit e5ae5538500d1f243b5edbd92e0531933e10e4aa
Author: Tim-Philipp Müller <tim.muller@collabora.co.uk>
Date:   Wed Nov 30 23:15:22 2011 +0000

    Revert "alsasrc: Fix some compilation errors"
    
    This reverts commit 2b84f5bd74ddb50f7832917ea8b4dd38d005631b.

commit 4cc8920db4ee742dc5476079fadfe493dcadf028
Author: Tim-Philipp Müller <tim.muller@collabora.co.uk>
Date:   Wed Nov 30 23:15:12 2011 +0000

    Revert "alsa: Remove unused but set variable"
    
    This reverts commit e9aed7f31c7e9e415f733e147140ce3ef2f57a61.

commit 1290f7de0e2bdd493fd70b5715863e118383b4cb
Author: Tim-Philipp Müller <tim.muller@collabora.co.uk>
Date:   Wed Nov 30 23:15:03 2011 +0000

    Revert "alsasrc: fail gracefully when ALSA does not give timestamps"
    
    This reverts commit c7282a5718c7f31f84fb31b2c38fab0f9a38e2b0.

commit d11849114c6a068c4382402d82f26086ded4427d
Author: Tim-Philipp Müller <tim.muller@collabora.co.uk>
Date:   Wed Nov 30 23:14:54 2011 +0000

    Revert "alsasrc: handle the case where the drivers don't supply timestamps"
    
    This reverts commit 8154b69112cdc4830cd6002ec6c1f2917d30437b.

commit 6d167abdfa77108f3c98aae98b04e0225f570b85
Author: Stefan Sauer <ensonic@google.com>
Date:   Mon Nov 28 10:55:39 2011 +0100

    Revert "alsasrc: style fix"
    
    This reverts commit f70ca6d4cbfd2b672dcc7215814bf6b39ce2c3f8.

Created attachment 204448 [details] [review]
Suggestion on having a single thread to solve the timestamp issues.

I have spent some time looking into this the past weeks and have come up with a fix that is a bit more extensive than the previous one.

Note, that it still is a experimental version, but I thought it would be good to have it here for further discussion.

Basically this suggestion introduces a new property (in the audiosrc element) that tells the system to run the alsasrc in a single thread instead of having a separate read thread and the pipeline thread. Time stamps are now taken in the same thread as data is read which solves the problem of having reads and taking the timestamps unsynchronized.

As I understand it, having a separate read thread solves the problem were poorly written alsa drivers would loose data if not served instantly when new data is available. This is why the read thread wasn't removed completely.

This implementation starts up with dual threaded alsasrc as default, and by setting the "single-thread" property to true it goes into a single-thread mode of operation. Driver timestamping is also disabled in dual thread mode since it does not work properly, as discussed before.

Comments, suggestions anyone ?

Oh, I should probably point out that this patch is based on 0.10.35 as this is the version that we currently are using internally.

Created attachment 205626 [details] [review]
Using a return path for timestamps to the ringbuffer.

After comments from Wim I tried the attached solution instead. It does not have the advantage of eliminating the read thread but it is much simpler.

Created attachment 205970 [details] [review]
Updated version......

Here's a new version using an array for holding a timestamp for each entry in the ringbuffer.

Created attachment 213444 [details] [review]
New patch for 0.11

I have created a new patch file for the 0.11 branch. It would be great if someone could have a look at it so that I can make any changes needed. Thank you.

It is too broken:

* 0.10 version breaks ABI
* 0.11 missing audiobasesrc code.
* 0.11 version should simply add the *timestamp to existing read methods.
* In gst_audio_base_src_create() the base_time is not taken into account.
* gst_audio_ring_buffer_read() can read over multiple segments, it seems the 
  timestamp of the last segment is used, not the first (which should be closer to
  the real value). You might want to adjust the timestamp with the amount of
  bytes relative to the segment.
* the ringbuffer timestamp array is leaked
* a timestamp of -1 (instead of 0) should be used when the subclass doesn't
  provide a timestamp. This is because 0 can be a valid clock time.

Created attachment 216398 [details] [review]
Updated patch from Wim's commetns.

This a new patch that solves most of Wim's comments above. Some of you comments need some more discussions on the board.

Giving up again.. still broken

Wim, Any pointers as to what you feel is broken ?

* In gst_audio_base_src_create() the base_time is not taken into account.
* gst_audio_ring_buffer_read() can read over multiple segments, it seems the 
  timestamp of the last segment is used, not the first (which should be closer
to
  the real value). You might want to adjust the timestamp with the amount of
  bytes relative to the segment.
* a timestamp of -1 (instead of 0) should be used when the subclass doesn't
  provide a timestamp. This is because 0 can be a valid clock time.

Created attachment 216823 [details] [review]
Another updated patch with fixes to comments from Wim.

Here's another go at fixing the comments made by Wim. Hopefully this one will make it =)

* fixed some places where 0 was used as invalid timestamp
* fixed possible crasher in alsa when allocation failed.
* ported -good plugins

commit a2f8ec4f5a79eccef129f73053903c63e787ca2e
Author: Pontus Oldberg <pontus.oldberg at invector.se>
Date:   Mon Sep 10 11:26:38 2012 +0200

    ringbuffer: add support for timestamps
    
    Make it possible for subclasses to provide the timestamp (as an absolute time
    against the pipeline clock) of the last read data.
    Fix up alsa to provide the timestamp received from alsa. Because the alsa
    timestamps are in monotonic time, we can only do this when the monotonic clock
    has been selected as the pipeline clock.
    
    Fixes https://bugzilla.gnome.org/show_bug.cgi?id=635256