diff mbox series

ALSA: core: Remove trigger_tstamp_latched

Message ID 20240812142029.46608-1-zeno.endemann@mailbox.org (mailing list archive)
State New, archived
Headers show
Series ALSA: core: Remove trigger_tstamp_latched | expand

Commit Message

Zeno Endemann Aug. 12, 2024, 2:20 p.m. UTC
The trigger_tstamp_latched hook was introduced to allow drivers to
provide their own trigger timestamp instead of the default generated
one for higher accuracy. This makes sense in theory, but in practice
the only place that uses this is the hda core, and:

* The custom timestamp there does not seem to be a meaningful
  improvement over the default one; There is virtually no code in
  between them, so I measured only a difference of around 300ns in a
  KVM VM with ich9-intel-hda device.
* It is also bugged as it does not set a timestamp when the stream
  stops.
* It creates a pitfall for hda driver writers; Calling
  snd_hdac_stream_timecounter_init implicitly makes them responsible
  for generating these timestamps.

Since there is no real good use of this facility, I propose to remove
it.

I reported the bug initially on github (see below), there one can also
find a reproducer userspace app, as well as some other potential ways
to fix this issue, in case this removal is not accepted.

Cc'ing the Intel ASoC maintainers, as the skl-pcm.c is using the
snd_hdac_stream_timecounter_init function this patch modifies.

Closes: https://github.com/alsa-project/alsa-lib/issues/387
Signed-off-by: Zeno Endemann <zeno.endemann@mailbox.org>
---
 include/sound/pcm.h     | 1 -
 sound/core/pcm_native.c | 4 +---
 sound/hda/hdac_stream.c | 6 ------
 3 files changed, 1 insertion(+), 10 deletions(-)

Comments

Pierre-Louis Bossart Aug. 12, 2024, 5:25 p.m. UTC | #1
On 8/12/24 16:20, Zeno Endemann wrote:
> The trigger_tstamp_latched hook was introduced to allow drivers to
> provide their own trigger timestamp instead of the default generated
> one for higher accuracy. This makes sense in theory, but in practice
> the only place that uses this is the hda core, and:
> 
> * The custom timestamp there does not seem to be a meaningful
>   improvement over the default one; There is virtually no code in
>   between them, so I measured only a difference of around 300ns in a
>   KVM VM with ich9-intel-hda device.

Humm, you're analyzing timestamps with a VM and a rather old device?
ICH9 support was added in 2014, some ten years ago. The timestamping
stuff is only improved with SKL+.


> * It is also bugged as it does not set a timestamp when the stream
>   stops.

That's quite possible, the main point was to get accurate timestamps on
start and during playback.
https://github.com/alsa-project/alsa-lib/issues/387 maybe be a valid
issue, we never looked at the sequence with a drop.


> * It creates a pitfall for hda driver writers; Calling
>   snd_hdac_stream_timecounter_init implicitly makes them responsible
>   for generating these timestamps.

That's the point, let those drivers generate a better timestamp if they
can. Not sure what the problem is?

> Since there is no real good use of this facility, I propose to remove
> it.
> 
> I reported the bug initially on github (see below), there one can also
> find a reproducer userspace app, as well as some other potential ways
> to fix this issue, in case this removal is not accepted.
> 
> Cc'ing the Intel ASoC maintainers, as the skl-pcm.c is using the
> snd_hdac_stream_timecounter_init function this patch modifies.
> 
> Closes: https://github.com/alsa-project/alsa-lib/issues/387
> Signed-off-by: Zeno Endemann <zeno.endemann@mailbox.org>
> ---
>  include/sound/pcm.h     | 1 -
>  sound/core/pcm_native.c | 4 +---
>  sound/hda/hdac_stream.c | 6 ------
>  3 files changed, 1 insertion(+), 10 deletions(-)
> 
> diff --git a/include/sound/pcm.h b/include/sound/pcm.h
> index ac8f3aef9205..3539af9f733e 100644
> --- a/include/sound/pcm.h
> +++ b/include/sound/pcm.h
> @@ -361,7 +361,6 @@ struct snd_pcm_runtime {
>  	snd_pcm_state_t suspended_state; /* suspended stream state */
>  	struct snd_pcm_substream *trigger_master;
>  	struct timespec64 trigger_tstamp;	/* trigger timestamp */
> -	bool trigger_tstamp_latched;     /* trigger timestamp latched in low-level driver/hardware */
>  	int overrange;
>  	snd_pcm_uframes_t avail_max;
>  	snd_pcm_uframes_t hw_ptr_base;	/* Position at buffer restart */
> diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
> index 4057f9f10aee..ced5bd2d7ebb 100644
> --- a/sound/core/pcm_native.c
> +++ b/sound/core/pcm_native.c
> @@ -1194,8 +1194,7 @@ static void snd_pcm_trigger_tstamp(struct snd_pcm_substream *substream)
>  	if (runtime->trigger_master == NULL)
>  		return;
>  	if (runtime->trigger_master == substream) {
> -		if (!runtime->trigger_tstamp_latched)
> -			snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
> +		snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
>  	} else {
>  		snd_pcm_trigger_tstamp(runtime->trigger_master);
>  		runtime->trigger_tstamp = runtime->trigger_master->runtime->trigger_tstamp;
> @@ -1422,7 +1421,6 @@ static int snd_pcm_pre_start(struct snd_pcm_substream *substream,
>  	if (substream->stream == SNDRV_PCM_STREAM_PLAYBACK &&
>  	    !snd_pcm_playback_data(substream))
>  		return -EPIPE;
> -	runtime->trigger_tstamp_latched = false;
>  	runtime->trigger_master = substream;
>  	return 0;
>  }
> diff --git a/sound/hda/hdac_stream.c b/sound/hda/hdac_stream.c
> index b53de020309f..271d42b765fc 100644
> --- a/sound/hda/hdac_stream.c
> +++ b/sound/hda/hdac_stream.c
> @@ -660,14 +660,11 @@ static void azx_timecounter_init(struct hdac_stream *azx_dev,
>   *
>   * Initializes the time counter of streams marked by the bit flags (each
>   * bit corresponds to the stream index).
> - * The trigger timestamp of PCM substream assigned to the given stream is
> - * updated accordingly, too.
>   */
>  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>  				      unsigned int streams)
>  {
>  	struct hdac_bus *bus = azx_dev->bus;
> -	struct snd_pcm_runtime *runtime = azx_dev->substream->runtime;
>  	struct hdac_stream *s;
>  	bool inited = false;
>  	u64 cycle_last = 0;
> @@ -681,9 +678,6 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>  			}
>  		}
>  	}
> -
> -	snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
> -	runtime->trigger_tstamp_latched = true;
>  }
>  EXPORT_SYMBOL_GPL(snd_hdac_stream_timecounter_init);
>
Zeno Endemann Aug. 12, 2024, 9:05 p.m. UTC | #2
Pierre-Louis Bossart wrote on 12.08.24 19:25:
>> * The custom timestamp there does not seem to be a meaningful
>>    improvement over the default one; There is virtually no code in
>>    between them, so I measured only a difference of around 300ns in a
>>    KVM VM with ich9-intel-hda device.
> 
> Humm, you're analyzing timestamps with a VM and a rather old device?
> ICH9 support was added in 2014, some ten years ago. The timestamping
> stuff is only improved with SKL+.

With more modern hardware on bare metal I would assume this difference to
the default timestamp to be even smaller. I am not a hardware guy, so
correct me if I'm wrong, but I would think that the unknown timing delays
of the IO operations and internal audio hardware are orders of magnitude
larger than even 300ns, making this improvement drown in the noise. Do you
have some measurements of the differences with modern hardware?

Besides, the only improvement here is that the timestamp is taken slightly
earlier, nothing fancy as far as I can tell. It seems a bit odd to me that
the hda core is the only one that cares for this.

Finally, I cannot imagine what audio application needs sub-microsecond
accuracy for the trigger timestamps. That is less than a single audio frame
even for silly sample rates. Is this intended for some scientific use case?
For regular audio apps I'd think most do not even care that much for the
trigger timestamps and rather use the hw-pointer-update timestamps anyway,
to prevent clock drifts. In my case I use only the stop trigger timestamp
to estimate at which sample position a snd_pcm_drop happened, and don't use
the start timestamp at all.

But these are just my possibly narrow views on this. If you really have
valid use cases for those improved timestamps I won't insist on removing it.
In fact I'd be rather interested to know if you can point me to an
application that makes use of this.


> 
>> * It creates a pitfall for hda driver writers; Calling
>>    snd_hdac_stream_timecounter_init implicitly makes them responsible
>>    for generating these timestamps.
> 
> That's the point, let those drivers generate a better timestamp if they
> can. Not sure what the problem is?

This is more of an API issue. At least to me it seems bad to sneakily enable
this flag in snd_hdac_stream_timecounter_init. The documentation of it does
not make it clear that after calling it the driver is responsible for the
timestamps. Now I am admittedly not that deep into this code, so there may
be a reason, but again at least to an "outsider" like me it is quite unclear
why initializing the time counter also means the driver now has to manage the
trigger timestamps.

If you really want this functionality to stay, maybe it would be better to
move that out of snd_hdac_stream_timecounter_init and just make every driver
that wants to manage them raise the flag explicitly themselves.
Pierre-Louis Bossart Aug. 13, 2024, 8:04 a.m. UTC | #3
On 8/12/24 23:05, Zeno Endemann wrote:
> Pierre-Louis Bossart wrote on 12.08.24 19:25:
>>> * The custom timestamp there does not seem to be a meaningful
>>>    improvement over the default one; There is virtually no code in
>>>    between them, so I measured only a difference of around 300ns in a
>>>    KVM VM with ich9-intel-hda device.
>>
>> Humm, you're analyzing timestamps with a VM and a rather old device?
>> ICH9 support was added in 2014, some ten years ago. The timestamping
>> stuff is only improved with SKL+.
> 
> With more modern hardware on bare metal I would assume this difference to
> the default timestamp to be even smaller. I am not a hardware guy, so
> correct me if I'm wrong, but I would think that the unknown timing delays
> of the IO operations and internal audio hardware are orders of magnitude
> larger than even 300ns, making this improvement drown in the noise. Do you
> have some measurements of the differences with modern hardware?
> 
> Besides, the only improvement here is that the timestamp is taken slightly
> earlier, nothing fancy as far as I can tell. It seems a bit odd to me that
> the hda core is the only one that cares for this.

The timestamping is not limited to HDaudio, it just turns out that only
Intel upstreamed the solution.

> Finally, I cannot imagine what audio application needs sub-microsecond
> accuracy for the trigger timestamps. That is less than a single audio frame
> even for silly sample rates. Is this intended for some scientific use case?
> For regular audio apps I'd think most do not even care that much for the
> trigger timestamps and rather use the hw-pointer-update timestamps anyway,
> to prevent clock drifts. In my case I use only the stop trigger timestamp
> to estimate at which sample position a snd_pcm_drop happened, and don't use
> the start timestamp at all.
> 
> But these are just my possibly narrow views on this. If you really have
> valid use cases for those improved timestamps I won't insist on removing
> it.
> In fact I'd be rather interested to know if you can point me to an
> application that makes use of this.

by focusing on the trigger timestamp I think you're looking at the wrong
side of the problem. The timestamping is improved by using the same
hardware counter for the trigger AND regular timestamp during
playback/capture. If you look at a hardware counter during
playback/capture but the start position is recorded with another method,
would you agree that there's a systematic non-reproducible offset at
each run? You want the trigger and regular timestamps to be measured in
the same way to avoid measurement differences.

>>> * It creates a pitfall for hda driver writers; Calling
>>>    snd_hdac_stream_timecounter_init implicitly makes them responsible
>>>    for generating these timestamps.
>>
>> That's the point, let those drivers generate a better timestamp if they
>> can. Not sure what the problem is?
> 
> This is more of an API issue. At least to me it seems bad to sneakily
> enable
> this flag in snd_hdac_stream_timecounter_init. The documentation of it does
> not make it clear that after calling it the driver is responsible for the
> timestamps. Now I am admittedly not that deep into this code, so there may
> be a reason, but again at least to an "outsider" like me it is quite
> unclear
> why initializing the time counter also means the driver now has to
> manage the
> trigger timestamps.
> 
> If you really want this functionality to stay, maybe it would be better to
> move that out of snd_hdac_stream_timecounter_init and just make every
> driver
> that wants to manage them raise the flag explicitly themselves.

Not every hardware provides a counter than can be used for precise
timestamping, so there's no practical way to require that all solutions
use the same API. USB has e.g. no such counter, the only thing you'll
get is a 1ms counter which isn't great.

I would also refer you to the different types of timestamps that can be
taken, the wallclock counter is the simple case but there's also a
capability to get an atomic snapshop for precise measurements.

I will not disagree that most applications do not need precise
timestamping, but if you want to try to enable time-of-flight
measurements for presence or gesture detection you will need higher
sampling rates and micro-second level accuracy.
Takashi Iwai Aug. 13, 2024, 9:26 a.m. UTC | #4
On Mon, 12 Aug 2024 16:20:29 +0200,
Zeno Endemann wrote:
> 
> The trigger_tstamp_latched hook was introduced to allow drivers to
> provide their own trigger timestamp instead of the default generated
> one for higher accuracy. This makes sense in theory, but in practice
> the only place that uses this is the hda core, and:
> 
> * The custom timestamp there does not seem to be a meaningful
>   improvement over the default one; There is virtually no code in
>   between them, so I measured only a difference of around 300ns in a
>   KVM VM with ich9-intel-hda device.
> * It is also bugged as it does not set a timestamp when the stream
>   stops.
> * It creates a pitfall for hda driver writers; Calling
>   snd_hdac_stream_timecounter_init implicitly makes them responsible
>   for generating these timestamps.
> 
> Since there is no real good use of this facility, I propose to remove
> it.
> 
> I reported the bug initially on github (see below), there one can also
> find a reproducer userspace app, as well as some other potential ways
> to fix this issue, in case this removal is not accepted.
> 
> Cc'ing the Intel ASoC maintainers, as the skl-pcm.c is using the
> snd_hdac_stream_timecounter_init function this patch modifies.
> 
> Closes: https://github.com/alsa-project/alsa-lib/issues/387
> Signed-off-by: Zeno Endemann <zeno.endemann@mailbox.org>

As long as I read the thread, there seems still use cases for this
high resolution time counter, so I'm rather for fixing the bugs of
bogus trigger tstamp than dropping the feature.

I still wonder, though, why the trigger_tstamp becomes *earlier* when
runtime->trigger_tstamp_latched is set.  I thought the same value
would be kept, instead.  What am I overlooking?

In anyway, if it's only about the missing trigger_tstamp update at PCM
trigger actions other than START, it could be fixed simply by clearing
trigger_tstamp_latched flag, too.  Alternatively, move the conditional
call to snd_pcm_post_start() instead of snd_pcm_trigger_tstamp()
itself, something like below.


thanks,

Takashi

--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -1194,8 +1194,7 @@ static void snd_pcm_trigger_tstamp(struct snd_pcm_substream *substream)
 	if (runtime->trigger_master == NULL)
 		return;
 	if (runtime->trigger_master == substream) {
-		if (!runtime->trigger_tstamp_latched)
-			snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
+		snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
 	} else {
 		snd_pcm_trigger_tstamp(runtime->trigger_master);
 		runtime->trigger_tstamp = runtime->trigger_master->runtime->trigger_tstamp;
@@ -1454,7 +1453,8 @@ static void snd_pcm_post_start(struct snd_pcm_substream *substream,
 			       snd_pcm_state_t state)
 {
 	struct snd_pcm_runtime *runtime = substream->runtime;
-	snd_pcm_trigger_tstamp(substream);
+	if (!runtime->trigger_tstamp_latched)
+		snd_pcm_trigger_tstamp(substream);
 	runtime->hw_ptr_jiffies = jiffies;
 	runtime->hw_ptr_buffer_jiffies = (runtime->buffer_size * HZ) / 
 							    runtime->rate;
Zeno Endemann Aug. 13, 2024, 10:41 a.m. UTC | #5
Takashi Iwai wrote on 13.08.24 11:26:
> As long as I read the thread, there seems still use cases for this
> high resolution time counter, so I'm rather for fixing the bugs of
> bogus trigger tstamp than dropping the feature.

I still remain fully unconvinced that moving the point where the
timestamp is taken back by a couple of fairly trivial CPU instructions
does anything of value, but if that convinces you I suppose I'll have
to propose an alternative.

In that case I'd rather simply go with what also Jaroslav Kysela
suggested, and add a timestamp read in the azx_pcm_trigger when stopping.
There may be some Intel drivers that have their own trigger callback,
where this bug would still remain, but I believe it is fair that I do not
worry about that, as I wouldn't be able to test it anyway.

> 
> I still wonder, though, why the trigger_tstamp becomes *earlier* when
> runtime->trigger_tstamp_latched is set.  I thought the same value
> would be kept, instead.  What am I overlooking?

The trigger timestamp is kept separately from the runtime timestamp. So
the runtime timestamp gets updated, but the trigger timestamp does not,
thus the stop trigger timestamp is the same as the start trigger timestamp,
which is earlier than any runtime timestamp.

> 
> In anyway, if it's only about the missing trigger_tstamp update at PCM
> trigger actions other than START, it could be fixed simply by clearing
> trigger_tstamp_latched flag, too.  Alternatively, move the conditional
> call to snd_pcm_post_start() instead of snd_pcm_trigger_tstamp()
> itself, something like below.

I strongly advise against that. That would make the trigger_tstamp_latched
flag even more confusing, as then the driver would only be able to override
the start trigger timestamp, not any other.

If that flag should stay, it may also be a good idea to rename it to
something more descriptive, like "trigger_tstamp_managed_by_driver".
With simply "latched" it is unclear whether it is only latched for the
next timestamp that would be taken (and need to be re-raised by the driver)
or stays in effect permanently (or, as it is now, stays in effect until
the next start)...
Zeno Endemann Aug. 13, 2024, 12:54 p.m. UTC | #6
Pierre-Louis Bossart wrote on 13.08.24 10:04:
> by focusing on the trigger timestamp I think you're looking at the wrong
> side of the problem. The timestamping is improved by using the same
> hardware counter for the trigger AND regular timestamp during
> playback/capture. If you look at a hardware counter during
> playback/capture but the start position is recorded with another method,
> would you agree that there's a systematic non-reproducible offset at
> each run? You want the trigger and regular timestamps to be measured in
> the same way to avoid measurement differences.

I am not sure what you are talking about. I have not seen any place in the
code where the trigger timestamp is taken in any other more sophisticated
way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
not see how your custom *trigger* timestamps are done "with another method".

> I will not disagree that most applications do not need precise
> timestamping, but if you want to try to enable time-of-flight
> measurements for presence or gesture detection you will need higher
> sampling rates and micro-second level accuracy.

I don't know, this sounds very theoretical at best to me. However I do not
have the desire to try to further argue and convince you otherwise.

Do you want to propose a different solution for the stop trigger timestamp
bug? That is my main goal after all.
Takashi Iwai Aug. 13, 2024, 1:41 p.m. UTC | #7
On Tue, 13 Aug 2024 14:54:42 +0200,
Zeno Endemann wrote:
> 
> Pierre-Louis Bossart wrote on 13.08.24 10:04:
> > by focusing on the trigger timestamp I think you're looking at the wrong
> > side of the problem. The timestamping is improved by using the same
> > hardware counter for the trigger AND regular timestamp during
> > playback/capture. If you look at a hardware counter during
> > playback/capture but the start position is recorded with another method,
> > would you agree that there's a systematic non-reproducible offset at
> > each run? You want the trigger and regular timestamps to be measured in
> > the same way to avoid measurement differences.
> 
> I am not sure what you are talking about. I have not seen any place in the
> code where the trigger timestamp is taken in any other more sophisticated
> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
> not see how your custom *trigger* timestamps are done "with another method".
> 
> > I will not disagree that most applications do not need precise
> > timestamping, but if you want to try to enable time-of-flight
> > measurements for presence or gesture detection you will need higher
> > sampling rates and micro-second level accuracy.
> 
> I don't know, this sounds very theoretical at best to me. However I do not
> have the desire to try to further argue and convince you otherwise.
> 
> Do you want to propose a different solution for the stop trigger timestamp
> bug? That is my main goal after all.

Ah, I guess that the discussion drifted because of misunderstanding.

This isn't about the accuracy of the audio timestamp, but rather the
timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
taken in the driver's trigger callback.  But, the effectiveness of
this change is dubious, because the timestamp taken in the usual code
path in PCM core is right after the trigger callback, hence the
difference should be negligible -- that's the argument.

No matter how the fix will be, could you put the Fixes tag pointing to
the culprit commit(s) at the next submission?


thanks,

Takashi
Zeno Endemann Aug. 13, 2024, 1:58 p.m. UTC | #8
Takashi Iwai wrote on 13.08.24 15:41:
> On Tue, 13 Aug 2024 14:54:42 +0200,
> Zeno Endemann wrote:
>>
>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
>>> by focusing on the trigger timestamp I think you're looking at the wrong
>>> side of the problem. The timestamping is improved by using the same
>>> hardware counter for the trigger AND regular timestamp during
>>> playback/capture. If you look at a hardware counter during
>>> playback/capture but the start position is recorded with another method,
>>> would you agree that there's a systematic non-reproducible offset at
>>> each run? You want the trigger and regular timestamps to be measured in
>>> the same way to avoid measurement differences.
>>
>> I am not sure what you are talking about. I have not seen any place in the
>> code where the trigger timestamp is taken in any other more sophisticated
>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
>> not see how your custom *trigger* timestamps are done "with another method".
>>
>>> I will not disagree that most applications do not need precise
>>> timestamping, but if you want to try to enable time-of-flight
>>> measurements for presence or gesture detection you will need higher
>>> sampling rates and micro-second level accuracy.
>>
>> I don't know, this sounds very theoretical at best to me. However I do not
>> have the desire to try to further argue and convince you otherwise.
>>
>> Do you want to propose a different solution for the stop trigger timestamp
>> bug? That is my main goal after all.
> 
> Ah, I guess that the discussion drifted because of misunderstanding.
> 
> This isn't about the accuracy of the audio timestamp, but rather the
> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
> taken in the driver's trigger callback.  But, the effectiveness of
> this change is dubious, because the timestamp taken in the usual code
> path in PCM core is right after the trigger callback, hence the
> difference should be negligible -- that's the argument.

Exactly. Sorry if my communication was not clear on that.

> 
> No matter how the fix will be, could you put the Fixes tag pointing to
> the culprit commit(s) at the next submission?

Will do. I guess I'll have to look up which commit actually enabled the
trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
yet, so is not technically the culprit?
Takashi Iwai Aug. 13, 2024, 2:05 p.m. UTC | #9
On Tue, 13 Aug 2024 15:58:13 +0200,
Zeno Endemann wrote:
> 
> Takashi Iwai wrote on 13.08.24 15:41:
> > On Tue, 13 Aug 2024 14:54:42 +0200,
> > Zeno Endemann wrote:
> >> 
> >> Pierre-Louis Bossart wrote on 13.08.24 10:04:
> >>> by focusing on the trigger timestamp I think you're looking at the wrong
> >>> side of the problem. The timestamping is improved by using the same
> >>> hardware counter for the trigger AND regular timestamp during
> >>> playback/capture. If you look at a hardware counter during
> >>> playback/capture but the start position is recorded with another method,
> >>> would you agree that there's a systematic non-reproducible offset at
> >>> each run? You want the trigger and regular timestamps to be measured in
> >>> the same way to avoid measurement differences.
> >> 
> >> I am not sure what you are talking about. I have not seen any place in the
> >> code where the trigger timestamp is taken in any other more sophisticated
> >> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
> >> not see how your custom *trigger* timestamps are done "with another method".
> >> 
> >>> I will not disagree that most applications do not need precise
> >>> timestamping, but if you want to try to enable time-of-flight
> >>> measurements for presence or gesture detection you will need higher
> >>> sampling rates and micro-second level accuracy.
> >> 
> >> I don't know, this sounds very theoretical at best to me. However I do not
> >> have the desire to try to further argue and convince you otherwise.
> >> 
> >> Do you want to propose a different solution for the stop trigger timestamp
> >> bug? That is my main goal after all.
> > 
> > Ah, I guess that the discussion drifted because of misunderstanding.
> > 
> > This isn't about the accuracy of the audio timestamp, but rather the
> > timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
> > for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
> > taken in the driver's trigger callback.  But, the effectiveness of
> > this change is dubious, because the timestamp taken in the usual code
> > path in PCM core is right after the trigger callback, hence the
> > difference should be negligible -- that's the argument.
> 
> Exactly. Sorry if my communication was not clear on that.
> 
> > 
> > No matter how the fix will be, could you put the Fixes tag pointing to
> > the culprit commit(s) at the next submission?
> 
> Will do. I guess I'll have to look up which commit actually enabled the
> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
> yet, so is not technically the culprit?

You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
read trigger_timestamp immediately after starting DMA") instead, too.
Maybe it doesn't matter much which commit is chosen; both should
appear in the same kernel version.


thanks,

Takashi
Zeno Endemann Aug. 21, 2024, 2:27 p.m. UTC | #10
Takashi Iwai wrote on 13.08.24 16:05:
> On Tue, 13 Aug 2024 15:58:13 +0200,
> Zeno Endemann wrote:
>>
>> Takashi Iwai wrote on 13.08.24 15:41:
>>> On Tue, 13 Aug 2024 14:54:42 +0200,
>>> Zeno Endemann wrote:
>>>>
>>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
>>>>> by focusing on the trigger timestamp I think you're looking at the wrong
>>>>> side of the problem. The timestamping is improved by using the same
>>>>> hardware counter for the trigger AND regular timestamp during
>>>>> playback/capture. If you look at a hardware counter during
>>>>> playback/capture but the start position is recorded with another method,
>>>>> would you agree that there's a systematic non-reproducible offset at
>>>>> each run? You want the trigger and regular timestamps to be measured in
>>>>> the same way to avoid measurement differences.
>>>>
>>>> I am not sure what you are talking about. I have not seen any place in the
>>>> code where the trigger timestamp is taken in any other more sophisticated
>>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
>>>> not see how your custom *trigger* timestamps are done "with another method".
>>>>
>>>>> I will not disagree that most applications do not need precise
>>>>> timestamping, but if you want to try to enable time-of-flight
>>>>> measurements for presence or gesture detection you will need higher
>>>>> sampling rates and micro-second level accuracy.
>>>>
>>>> I don't know, this sounds very theoretical at best to me. However I do not
>>>> have the desire to try to further argue and convince you otherwise.
>>>>
>>>> Do you want to propose a different solution for the stop trigger timestamp
>>>> bug? That is my main goal after all.
>>>
>>> Ah, I guess that the discussion drifted because of misunderstanding.
>>>
>>> This isn't about the accuracy of the audio timestamp, but rather the
>>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
>>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
>>> taken in the driver's trigger callback.  But, the effectiveness of
>>> this change is dubious, because the timestamp taken in the usual code
>>> path in PCM core is right after the trigger callback, hence the
>>> difference should be negligible -- that's the argument.
>>
>> Exactly. Sorry if my communication was not clear on that.
>>
>>>
>>> No matter how the fix will be, could you put the Fixes tag pointing to
>>> the culprit commit(s) at the next submission?
>>
>> Will do. I guess I'll have to look up which commit actually enabled the
>> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
>> yet, so is not technically the culprit?
> 
> You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
> read trigger_timestamp immediately after starting DMA") instead, too.
> Maybe it doesn't matter much which commit is chosen; both should
> appear in the same kernel version.

Well, I think I've waited a decent amount of time now for more comments.
How do we proceed?

I'm still of the opinion that the removal is the most sensible solution,
so if we agree I could prepare a V2 where I just improve the commit message
a bit further.

But if we don't have a good enough consensus on this, I'd need some guidance
which alternate path should be taken to at least fix the bug of bad stop
trigger timestamps for hda devices (e.g. should I try to fix it also for
soc/intel/skylake without any testing? That seems to me the only other place
that should be affected, apart from the generic pci hda code).

Thanks,
Zeno
Takashi Iwai Aug. 21, 2024, 2:44 p.m. UTC | #11
On Wed, 21 Aug 2024 16:27:43 +0200,
Zeno Endemann wrote:
> 
> Takashi Iwai wrote on 13.08.24 16:05:
> > On Tue, 13 Aug 2024 15:58:13 +0200,
> > Zeno Endemann wrote:
> >> 
> >> Takashi Iwai wrote on 13.08.24 15:41:
> >>> On Tue, 13 Aug 2024 14:54:42 +0200,
> >>> Zeno Endemann wrote:
> >>>> 
> >>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
> >>>>> by focusing on the trigger timestamp I think you're looking at the wrong
> >>>>> side of the problem. The timestamping is improved by using the same
> >>>>> hardware counter for the trigger AND regular timestamp during
> >>>>> playback/capture. If you look at a hardware counter during
> >>>>> playback/capture but the start position is recorded with another method,
> >>>>> would you agree that there's a systematic non-reproducible offset at
> >>>>> each run? You want the trigger and regular timestamps to be measured in
> >>>>> the same way to avoid measurement differences.
> >>>> 
> >>>> I am not sure what you are talking about. I have not seen any place in the
> >>>> code where the trigger timestamp is taken in any other more sophisticated
> >>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
> >>>> not see how your custom *trigger* timestamps are done "with another method".
> >>>> 
> >>>>> I will not disagree that most applications do not need precise
> >>>>> timestamping, but if you want to try to enable time-of-flight
> >>>>> measurements for presence or gesture detection you will need higher
> >>>>> sampling rates and micro-second level accuracy.
> >>>> 
> >>>> I don't know, this sounds very theoretical at best to me. However I do not
> >>>> have the desire to try to further argue and convince you otherwise.
> >>>> 
> >>>> Do you want to propose a different solution for the stop trigger timestamp
> >>>> bug? That is my main goal after all.
> >>> 
> >>> Ah, I guess that the discussion drifted because of misunderstanding.
> >>> 
> >>> This isn't about the accuracy of the audio timestamp, but rather the
> >>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
> >>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
> >>> taken in the driver's trigger callback.  But, the effectiveness of
> >>> this change is dubious, because the timestamp taken in the usual code
> >>> path in PCM core is right after the trigger callback, hence the
> >>> difference should be negligible -- that's the argument.
> >> 
> >> Exactly. Sorry if my communication was not clear on that.
> >> 
> >>> 
> >>> No matter how the fix will be, could you put the Fixes tag pointing to
> >>> the culprit commit(s) at the next submission?
> >> 
> >> Will do. I guess I'll have to look up which commit actually enabled the
> >> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
> >> yet, so is not technically the culprit?
> > 
> > You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
> > read trigger_timestamp immediately after starting DMA") instead, too.
> > Maybe it doesn't matter much which commit is chosen; both should
> > appear in the same kernel version.
> 
> Well, I think I've waited a decent amount of time now for more comments.
> How do we proceed?
> 
> I'm still of the opinion that the removal is the most sensible solution,
> so if we agree I could prepare a V2 where I just improve the commit message
> a bit further.
> 
> But if we don't have a good enough consensus on this, I'd need some guidance
> which alternate path should be taken to at least fix the bug of bad stop
> trigger timestamps for hda devices (e.g. should I try to fix it also for
> soc/intel/skylake without any testing? That seems to me the only other place
> that should be affected, apart from the generic pci hda code).

IIUC, the achievement of the timestamp at the exact timing was the
goal of that change (which caused a regression unfortunately), so
keeping that feature may still make sense.  I'd rather try to fix in
HD-audio side at first.

If Pierre agrees with the removal of the local timestamp call, we can
revert to there afterwards, too.


thanks,

Takashi
Jaroslav Kysela Aug. 21, 2024, 2:59 p.m. UTC | #12
On 21. 08. 24 16:44, Takashi Iwai wrote:
> On Wed, 21 Aug 2024 16:27:43 +0200,
> Zeno Endemann wrote:
>>
>> Takashi Iwai wrote on 13.08.24 16:05:
>>> On Tue, 13 Aug 2024 15:58:13 +0200,
>>> Zeno Endemann wrote:
>>>>
>>>> Takashi Iwai wrote on 13.08.24 15:41:
>>>>> On Tue, 13 Aug 2024 14:54:42 +0200,
>>>>> Zeno Endemann wrote:
>>>>>>
>>>>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
>>>>>>> by focusing on the trigger timestamp I think you're looking at the wrong
>>>>>>> side of the problem. The timestamping is improved by using the same
>>>>>>> hardware counter for the trigger AND regular timestamp during
>>>>>>> playback/capture. If you look at a hardware counter during
>>>>>>> playback/capture but the start position is recorded with another method,
>>>>>>> would you agree that there's a systematic non-reproducible offset at
>>>>>>> each run? You want the trigger and regular timestamps to be measured in
>>>>>>> the same way to avoid measurement differences.
>>>>>>
>>>>>> I am not sure what you are talking about. I have not seen any place in the
>>>>>> code where the trigger timestamp is taken in any other more sophisticated
>>>>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
>>>>>> not see how your custom *trigger* timestamps are done "with another method".
>>>>>>
>>>>>>> I will not disagree that most applications do not need precise
>>>>>>> timestamping, but if you want to try to enable time-of-flight
>>>>>>> measurements for presence or gesture detection you will need higher
>>>>>>> sampling rates and micro-second level accuracy.
>>>>>>
>>>>>> I don't know, this sounds very theoretical at best to me. However I do not
>>>>>> have the desire to try to further argue and convince you otherwise.
>>>>>>
>>>>>> Do you want to propose a different solution for the stop trigger timestamp
>>>>>> bug? That is my main goal after all.
>>>>>
>>>>> Ah, I guess that the discussion drifted because of misunderstanding.
>>>>>
>>>>> This isn't about the accuracy of the audio timestamp, but rather the
>>>>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
>>>>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
>>>>> taken in the driver's trigger callback.  But, the effectiveness of
>>>>> this change is dubious, because the timestamp taken in the usual code
>>>>> path in PCM core is right after the trigger callback, hence the
>>>>> difference should be negligible -- that's the argument.
>>>>
>>>> Exactly. Sorry if my communication was not clear on that.
>>>>
>>>>>
>>>>> No matter how the fix will be, could you put the Fixes tag pointing to
>>>>> the culprit commit(s) at the next submission?
>>>>
>>>> Will do. I guess I'll have to look up which commit actually enabled the
>>>> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
>>>> yet, so is not technically the culprit?
>>>
>>> You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
>>> read trigger_timestamp immediately after starting DMA") instead, too.
>>> Maybe it doesn't matter much which commit is chosen; both should
>>> appear in the same kernel version.
>>
>> Well, I think I've waited a decent amount of time now for more comments.
>> How do we proceed?
>>
>> I'm still of the opinion that the removal is the most sensible solution,
>> so if we agree I could prepare a V2 where I just improve the commit message
>> a bit further.
>>
>> But if we don't have a good enough consensus on this, I'd need some guidance
>> which alternate path should be taken to at least fix the bug of bad stop
>> trigger timestamps for hda devices (e.g. should I try to fix it also for
>> soc/intel/skylake without any testing? That seems to me the only other place
>> that should be affected, apart from the generic pci hda code).
> 
> IIUC, the achievement of the timestamp at the exact timing was the
> goal of that change (which caused a regression unfortunately), so
> keeping that feature may still make sense.  I'd rather try to fix in
> HD-audio side at first.
> 
> If Pierre agrees with the removal of the local timestamp call, we can
> revert to there afterwards, too.

What about a patch bellow. I'll send it with proper formatting, when we decide to go with it. Perhaps, the latched flag may be reset when start is false, too.

					Jaroslav

diff --git a/include/sound/hdaudio.h b/include/sound/hdaudio.h
index 7e39d486374a..b098ceadbe74 100644
--- a/include/sound/hdaudio.h
+++ b/include/sound/hdaudio.h
@@ -590,7 +590,7 @@ void snd_hdac_stream_sync_trigger(struct hdac_stream *azx_dev, bool set,
  void snd_hdac_stream_sync(struct hdac_stream *azx_dev, bool start,
  			  unsigned int streams);
  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
-				      unsigned int streams);
+				      unsigned int streams, bool start);
  int snd_hdac_get_stream_stripe_ctl(struct hdac_bus *bus,
  				struct snd_pcm_substream *substream);
  
diff --git a/sound/hda/hdac_stream.c b/sound/hda/hdac_stream.c
index b53de020309f..0411a8fe9d6f 100644
--- a/sound/hda/hdac_stream.c
+++ b/sound/hda/hdac_stream.c
@@ -664,7 +664,7 @@ static void azx_timecounter_init(struct hdac_stream *azx_dev,
   * updated accordingly, too.
   */
  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
-				      unsigned int streams)
+				      unsigned int streams, bool start)
  {
  	struct hdac_bus *bus = azx_dev->bus;
  	struct snd_pcm_runtime *runtime = azx_dev->substream->runtime;
@@ -672,6 +672,9 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
  	bool inited = false;
  	u64 cycle_last = 0;
  
+	if (!start)
+		goto skip;
+
  	list_for_each_entry(s, &bus->stream_list, list) {
  		if ((streams & (1 << s->index))) {
  			azx_timecounter_init(s, inited, cycle_last);
@@ -682,6 +685,7 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
  		}
  	}
  
+skip:
  	snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
  	runtime->trigger_tstamp_latched = true;
  }
diff --git a/sound/pci/hda/hda_controller.c b/sound/pci/hda/hda_controller.c
index 5d86e5a9c814..f3330b7e0fcf 100644
--- a/sound/pci/hda/hda_controller.c
+++ b/sound/pci/hda/hda_controller.c
@@ -275,8 +275,7 @@ static int azx_pcm_trigger(struct snd_pcm_substream *substream, int cmd)
  	spin_lock(&bus->reg_lock);
  	/* reset SYNC bits */
  	snd_hdac_stream_sync_trigger(hstr, false, sbits, sync_reg);
-	if (start)
-		snd_hdac_stream_timecounter_init(hstr, sbits);
+	snd_hdac_stream_timecounter_init(hstr, sbits, start);
  	spin_unlock(&bus->reg_lock);
  	return 0;
  }
diff --git a/sound/soc/intel/skylake/skl-pcm.c b/sound/soc/intel/skylake/skl-pcm.c
index 613b27b8da13..7eec15a2c49e 100644
--- a/sound/soc/intel/skylake/skl-pcm.c
+++ b/sound/soc/intel/skylake/skl-pcm.c
@@ -446,10 +446,10 @@ static int skl_decoupled_trigger(struct snd_pcm_substream *substream,
  
  	if (start) {
  		snd_hdac_stream_start(hdac_stream(stream));
-		snd_hdac_stream_timecounter_init(hstr, 0);
  	} else {
  		snd_hdac_stream_stop(hdac_stream(stream));
  	}
+	snd_hdac_stream_timecounter_init(hstr, 0, start);
  
  	spin_unlock_irqrestore(&bus->reg_lock, cookie);
  
@@ -1145,8 +1145,7 @@ static int skl_coupled_trigger(struct snd_pcm_substream *substream,
  
  	/* reset SYNC bits */
  	snd_hdac_stream_sync_trigger(hstr, false, sbits, AZX_REG_SSYNC);
-	if (start)
-		snd_hdac_stream_timecounter_init(hstr, sbits);
+	snd_hdac_stream_timecounter_init(hstr, sbits, start);
  	spin_unlock_irqrestore(&bus->reg_lock, cookie);
  
  	return 0;


					Jaroslav
Takashi Iwai Aug. 21, 2024, 3:05 p.m. UTC | #13
On Wed, 21 Aug 2024 16:59:41 +0200,
Jaroslav Kysela wrote:
> 
> On 21. 08. 24 16:44, Takashi Iwai wrote:
> > On Wed, 21 Aug 2024 16:27:43 +0200,
> > Zeno Endemann wrote:
> >> 
> >> Takashi Iwai wrote on 13.08.24 16:05:
> >>> On Tue, 13 Aug 2024 15:58:13 +0200,
> >>> Zeno Endemann wrote:
> >>>> 
> >>>> Takashi Iwai wrote on 13.08.24 15:41:
> >>>>> On Tue, 13 Aug 2024 14:54:42 +0200,
> >>>>> Zeno Endemann wrote:
> >>>>>> 
> >>>>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
> >>>>>>> by focusing on the trigger timestamp I think you're looking at the wrong
> >>>>>>> side of the problem. The timestamping is improved by using the same
> >>>>>>> hardware counter for the trigger AND regular timestamp during
> >>>>>>> playback/capture. If you look at a hardware counter during
> >>>>>>> playback/capture but the start position is recorded with another method,
> >>>>>>> would you agree that there's a systematic non-reproducible offset at
> >>>>>>> each run? You want the trigger and regular timestamps to be measured in
> >>>>>>> the same way to avoid measurement differences.
> >>>>>> 
> >>>>>> I am not sure what you are talking about. I have not seen any place in the
> >>>>>> code where the trigger timestamp is taken in any other more sophisticated
> >>>>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
> >>>>>> not see how your custom *trigger* timestamps are done "with another method".
> >>>>>> 
> >>>>>>> I will not disagree that most applications do not need precise
> >>>>>>> timestamping, but if you want to try to enable time-of-flight
> >>>>>>> measurements for presence or gesture detection you will need higher
> >>>>>>> sampling rates and micro-second level accuracy.
> >>>>>> 
> >>>>>> I don't know, this sounds very theoretical at best to me. However I do not
> >>>>>> have the desire to try to further argue and convince you otherwise.
> >>>>>> 
> >>>>>> Do you want to propose a different solution for the stop trigger timestamp
> >>>>>> bug? That is my main goal after all.
> >>>>> 
> >>>>> Ah, I guess that the discussion drifted because of misunderstanding.
> >>>>> 
> >>>>> This isn't about the accuracy of the audio timestamp, but rather the
> >>>>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
> >>>>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
> >>>>> taken in the driver's trigger callback.  But, the effectiveness of
> >>>>> this change is dubious, because the timestamp taken in the usual code
> >>>>> path in PCM core is right after the trigger callback, hence the
> >>>>> difference should be negligible -- that's the argument.
> >>>> 
> >>>> Exactly. Sorry if my communication was not clear on that.
> >>>> 
> >>>>> 
> >>>>> No matter how the fix will be, could you put the Fixes tag pointing to
> >>>>> the culprit commit(s) at the next submission?
> >>>> 
> >>>> Will do. I guess I'll have to look up which commit actually enabled the
> >>>> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
> >>>> yet, so is not technically the culprit?
> >>> 
> >>> You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
> >>> read trigger_timestamp immediately after starting DMA") instead, too.
> >>> Maybe it doesn't matter much which commit is chosen; both should
> >>> appear in the same kernel version.
> >> 
> >> Well, I think I've waited a decent amount of time now for more comments.
> >> How do we proceed?
> >> 
> >> I'm still of the opinion that the removal is the most sensible solution,
> >> so if we agree I could prepare a V2 where I just improve the commit message
> >> a bit further.
> >> 
> >> But if we don't have a good enough consensus on this, I'd need some guidance
> >> which alternate path should be taken to at least fix the bug of bad stop
> >> trigger timestamps for hda devices (e.g. should I try to fix it also for
> >> soc/intel/skylake without any testing? That seems to me the only other place
> >> that should be affected, apart from the generic pci hda code).
> > 
> > IIUC, the achievement of the timestamp at the exact timing was the
> > goal of that change (which caused a regression unfortunately), so
> > keeping that feature may still make sense.  I'd rather try to fix in
> > HD-audio side at first.
> > 
> > If Pierre agrees with the removal of the local timestamp call, we can
> > revert to there afterwards, too.
> 
> What about a patch bellow. I'll send it with proper formatting, when we decide to go with it. Perhaps, the latched flag may be reset when start is false, too.

It's similar like what I had in mind, too.
(My version was to drop the call of snd_pcm_gettime() from
 snd_hdac_stream_timecounter_init() but call it at each place,
 instead.)


Takashi

> 
> 					Jaroslav
> 
> diff --git a/include/sound/hdaudio.h b/include/sound/hdaudio.h
> index 7e39d486374a..b098ceadbe74 100644
> --- a/include/sound/hdaudio.h
> +++ b/include/sound/hdaudio.h
> @@ -590,7 +590,7 @@ void snd_hdac_stream_sync_trigger(struct hdac_stream *azx_dev, bool set,
>  void snd_hdac_stream_sync(struct hdac_stream *azx_dev, bool start,
>  			  unsigned int streams);
>  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
> -				      unsigned int streams);
> +				      unsigned int streams, bool start);
>  int snd_hdac_get_stream_stripe_ctl(struct hdac_bus *bus,
>  				struct snd_pcm_substream *substream);
>  diff --git a/sound/hda/hdac_stream.c b/sound/hda/hdac_stream.c
> index b53de020309f..0411a8fe9d6f 100644
> --- a/sound/hda/hdac_stream.c
> +++ b/sound/hda/hdac_stream.c
> @@ -664,7 +664,7 @@ static void azx_timecounter_init(struct hdac_stream *azx_dev,
>   * updated accordingly, too.
>   */
>  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
> -				      unsigned int streams)
> +				      unsigned int streams, bool start)
>  {
>  	struct hdac_bus *bus = azx_dev->bus;
>  	struct snd_pcm_runtime *runtime = azx_dev->substream->runtime;
> @@ -672,6 +672,9 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>  	bool inited = false;
>  	u64 cycle_last = 0;
>  +	if (!start)
> +		goto skip;
> +
>  	list_for_each_entry(s, &bus->stream_list, list) {
>  		if ((streams & (1 << s->index))) {
>  			azx_timecounter_init(s, inited, cycle_last);
> @@ -682,6 +685,7 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>  		}
>  	}
>  +skip:
>  	snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
>  	runtime->trigger_tstamp_latched = true;
>  }
> diff --git a/sound/pci/hda/hda_controller.c b/sound/pci/hda/hda_controller.c
> index 5d86e5a9c814..f3330b7e0fcf 100644
> --- a/sound/pci/hda/hda_controller.c
> +++ b/sound/pci/hda/hda_controller.c
> @@ -275,8 +275,7 @@ static int azx_pcm_trigger(struct snd_pcm_substream *substream, int cmd)
>  	spin_lock(&bus->reg_lock);
>  	/* reset SYNC bits */
>  	snd_hdac_stream_sync_trigger(hstr, false, sbits, sync_reg);
> -	if (start)
> -		snd_hdac_stream_timecounter_init(hstr, sbits);
> +	snd_hdac_stream_timecounter_init(hstr, sbits, start);
>  	spin_unlock(&bus->reg_lock);
>  	return 0;
>  }
> diff --git a/sound/soc/intel/skylake/skl-pcm.c b/sound/soc/intel/skylake/skl-pcm.c
> index 613b27b8da13..7eec15a2c49e 100644
> --- a/sound/soc/intel/skylake/skl-pcm.c
> +++ b/sound/soc/intel/skylake/skl-pcm.c
> @@ -446,10 +446,10 @@ static int skl_decoupled_trigger(struct snd_pcm_substream *substream,
>   	if (start) {
>  		snd_hdac_stream_start(hdac_stream(stream));
> -		snd_hdac_stream_timecounter_init(hstr, 0);
>  	} else {
>  		snd_hdac_stream_stop(hdac_stream(stream));
>  	}
> +	snd_hdac_stream_timecounter_init(hstr, 0, start);
>   	spin_unlock_irqrestore(&bus->reg_lock, cookie);
>  @@ -1145,8 +1145,7 @@ static int skl_coupled_trigger(struct
> snd_pcm_substream *substream,
>   	/* reset SYNC bits */
>  	snd_hdac_stream_sync_trigger(hstr, false, sbits, AZX_REG_SSYNC);
> -	if (start)
> -		snd_hdac_stream_timecounter_init(hstr, sbits);
> +	snd_hdac_stream_timecounter_init(hstr, sbits, start);
>  	spin_unlock_irqrestore(&bus->reg_lock, cookie);
>   	return 0;
> 
> 
> 					Jaroslav
> 
> -- 
> Jaroslav Kysela <perex@perex.cz>
> Linux Sound Maintainer; ALSA Project; Red Hat, Inc.
>
Jaroslav Kysela Aug. 21, 2024, 3:09 p.m. UTC | #14
On 21. 08. 24 17:05, Takashi Iwai wrote:
> On Wed, 21 Aug 2024 16:59:41 +0200,
> Jaroslav Kysela wrote:
>>
>> On 21. 08. 24 16:44, Takashi Iwai wrote:
>>> On Wed, 21 Aug 2024 16:27:43 +0200,
>>> Zeno Endemann wrote:
>>>>
>>>> Takashi Iwai wrote on 13.08.24 16:05:
>>>>> On Tue, 13 Aug 2024 15:58:13 +0200,
>>>>> Zeno Endemann wrote:
>>>>>>
>>>>>> Takashi Iwai wrote on 13.08.24 15:41:
>>>>>>> On Tue, 13 Aug 2024 14:54:42 +0200,
>>>>>>> Zeno Endemann wrote:
>>>>>>>>
>>>>>>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
>>>>>>>>> by focusing on the trigger timestamp I think you're looking at the wrong
>>>>>>>>> side of the problem. The timestamping is improved by using the same
>>>>>>>>> hardware counter for the trigger AND regular timestamp during
>>>>>>>>> playback/capture. If you look at a hardware counter during
>>>>>>>>> playback/capture but the start position is recorded with another method,
>>>>>>>>> would you agree that there's a systematic non-reproducible offset at
>>>>>>>>> each run? You want the trigger and regular timestamps to be measured in
>>>>>>>>> the same way to avoid measurement differences.
>>>>>>>>
>>>>>>>> I am not sure what you are talking about. I have not seen any place in the
>>>>>>>> code where the trigger timestamp is taken in any other more sophisticated
>>>>>>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
>>>>>>>> not see how your custom *trigger* timestamps are done "with another method".
>>>>>>>>
>>>>>>>>> I will not disagree that most applications do not need precise
>>>>>>>>> timestamping, but if you want to try to enable time-of-flight
>>>>>>>>> measurements for presence or gesture detection you will need higher
>>>>>>>>> sampling rates and micro-second level accuracy.
>>>>>>>>
>>>>>>>> I don't know, this sounds very theoretical at best to me. However I do not
>>>>>>>> have the desire to try to further argue and convince you otherwise.
>>>>>>>>
>>>>>>>> Do you want to propose a different solution for the stop trigger timestamp
>>>>>>>> bug? That is my main goal after all.
>>>>>>>
>>>>>>> Ah, I guess that the discussion drifted because of misunderstanding.
>>>>>>>
>>>>>>> This isn't about the accuracy of the audio timestamp, but rather the
>>>>>>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
>>>>>>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
>>>>>>> taken in the driver's trigger callback.  But, the effectiveness of
>>>>>>> this change is dubious, because the timestamp taken in the usual code
>>>>>>> path in PCM core is right after the trigger callback, hence the
>>>>>>> difference should be negligible -- that's the argument.
>>>>>>
>>>>>> Exactly. Sorry if my communication was not clear on that.
>>>>>>
>>>>>>>
>>>>>>> No matter how the fix will be, could you put the Fixes tag pointing to
>>>>>>> the culprit commit(s) at the next submission?
>>>>>>
>>>>>> Will do. I guess I'll have to look up which commit actually enabled the
>>>>>> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
>>>>>> yet, so is not technically the culprit?
>>>>>
>>>>> You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
>>>>> read trigger_timestamp immediately after starting DMA") instead, too.
>>>>> Maybe it doesn't matter much which commit is chosen; both should
>>>>> appear in the same kernel version.
>>>>
>>>> Well, I think I've waited a decent amount of time now for more comments.
>>>> How do we proceed?
>>>>
>>>> I'm still of the opinion that the removal is the most sensible solution,
>>>> so if we agree I could prepare a V2 where I just improve the commit message
>>>> a bit further.
>>>>
>>>> But if we don't have a good enough consensus on this, I'd need some guidance
>>>> which alternate path should be taken to at least fix the bug of bad stop
>>>> trigger timestamps for hda devices (e.g. should I try to fix it also for
>>>> soc/intel/skylake without any testing? That seems to me the only other place
>>>> that should be affected, apart from the generic pci hda code).
>>>
>>> IIUC, the achievement of the timestamp at the exact timing was the
>>> goal of that change (which caused a regression unfortunately), so
>>> keeping that feature may still make sense.  I'd rather try to fix in
>>> HD-audio side at first.
>>>
>>> If Pierre agrees with the removal of the local timestamp call, we can
>>> revert to there afterwards, too.
>>
>> What about a patch bellow. I'll send it with proper formatting, when we decide to go with it. Perhaps, the latched flag may be reset when start is false, too.
> 
> It's similar like what I had in mind, too.
> (My version was to drop the call of snd_pcm_gettime() from
>   snd_hdac_stream_timecounter_init() but call it at each place,
>   instead.)

It would be probably better to change snd_hdac_stream_timecounter_init() 
arguments to catch all callers even for random backports. Also bonus is to 
have the timestamping in one place. But both ways are fine.

				Jaroslav
Zeno Endemann Aug. 21, 2024, 4:04 p.m. UTC | #15
Jaroslav Kysela wrote on 21.08.24 16:59:
> On 21. 08. 24 16:44, Takashi Iwai wrote:
>> On Wed, 21 Aug 2024 16:27:43 +0200,
>> Zeno Endemann wrote:
>>>
>>> Takashi Iwai wrote on 13.08.24 16:05:
>>>> On Tue, 13 Aug 2024 15:58:13 +0200,
>>>> Zeno Endemann wrote:
>>>>>
>>>>> Takashi Iwai wrote on 13.08.24 15:41:
>>>>>> On Tue, 13 Aug 2024 14:54:42 +0200,
>>>>>> Zeno Endemann wrote:
>>>>>>>
>>>>>>> Pierre-Louis Bossart wrote on 13.08.24 10:04:
>>>>>>>> by focusing on the trigger timestamp I think you're looking at the wrong
>>>>>>>> side of the problem. The timestamping is improved by using the same
>>>>>>>> hardware counter for the trigger AND regular timestamp during
>>>>>>>> playback/capture. If you look at a hardware counter during
>>>>>>>> playback/capture but the start position is recorded with another method,
>>>>>>>> would you agree that there's a systematic non-reproducible offset at
>>>>>>>> each run? You want the trigger and regular timestamps to be measured in
>>>>>>>> the same way to avoid measurement differences.
>>>>>>>
>>>>>>> I am not sure what you are talking about. I have not seen any place in the
>>>>>>> code where the trigger timestamp is taken in any other more sophisticated
>>>>>>> way than what the default is doing, i.e. calling snd_pcm_gettime. So I do
>>>>>>> not see how your custom *trigger* timestamps are done "with another method".
>>>>>>>
>>>>>>>> I will not disagree that most applications do not need precise
>>>>>>>> timestamping, but if you want to try to enable time-of-flight
>>>>>>>> measurements for presence or gesture detection you will need higher
>>>>>>>> sampling rates and micro-second level accuracy.
>>>>>>>
>>>>>>> I don't know, this sounds very theoretical at best to me. However I do not
>>>>>>> have the desire to try to further argue and convince you otherwise.
>>>>>>>
>>>>>>> Do you want to propose a different solution for the stop trigger timestamp
>>>>>>> bug? That is my main goal after all.
>>>>>>
>>>>>> Ah, I guess that the discussion drifted because of misunderstanding.
>>>>>>
>>>>>> This isn't about the accuracy of the audio timestamp, but rather the
>>>>>> timing of trigger tstamp.  The commit 2b79d7a6bf34 ("ALSA: pcm: allow
>>>>>> for trigger_tstamp snapshot in .trigger") allowed the trigger_tstamp
>>>>>> taken in the driver's trigger callback.  But, the effectiveness of
>>>>>> this change is dubious, because the timestamp taken in the usual code
>>>>>> path in PCM core is right after the trigger callback, hence the
>>>>>> difference should be negligible -- that's the argument.
>>>>>
>>>>> Exactly. Sorry if my communication was not clear on that.
>>>>>
>>>>>>
>>>>>> No matter how the fix will be, could you put the Fixes tag pointing to
>>>>>> the culprit commit(s) at the next submission?
>>>>>
>>>>> Will do. I guess I'll have to look up which commit actually enabled the
>>>>> trigger_tstamp_latched in hda, as 2b79d7a6bf34 has no driver using that
>>>>> yet, so is not technically the culprit?
>>>>
>>>> You can take the HD-audio side, the commit ed610af86a71 ("ALSA: hda:
>>>> read trigger_timestamp immediately after starting DMA") instead, too.
>>>> Maybe it doesn't matter much which commit is chosen; both should
>>>> appear in the same kernel version.
>>>
>>> Well, I think I've waited a decent amount of time now for more comments.
>>> How do we proceed?
>>>
>>> I'm still of the opinion that the removal is the most sensible solution,
>>> so if we agree I could prepare a V2 where I just improve the commit message
>>> a bit further.
>>>
>>> But if we don't have a good enough consensus on this, I'd need some guidance
>>> which alternate path should be taken to at least fix the bug of bad stop
>>> trigger timestamps for hda devices (e.g. should I try to fix it also for
>>> soc/intel/skylake without any testing? That seems to me the only other place
>>> that should be affected, apart from the generic pci hda code).
>>
>> IIUC, the achievement of the timestamp at the exact timing was the
>> goal of that change (which caused a regression unfortunately), so
>> keeping that feature may still make sense.  I'd rather try to fix in
>> HD-audio side at first.
>>
>> If Pierre agrees with the removal of the local timestamp call, we can
>> revert to there afterwards, too.
> 
> What about a patch bellow. I'll send it with proper formatting, when we decide to go with it. Perhaps, the 
> latched flag may be reset when start is false, too.
> 
>                      Jaroslav
> 
> diff --git a/include/sound/hdaudio.h b/include/sound/hdaudio.h
> index 7e39d486374a..b098ceadbe74 100644
> --- a/include/sound/hdaudio.h
> +++ b/include/sound/hdaudio.h
> @@ -590,7 +590,7 @@ void snd_hdac_stream_sync_trigger(struct hdac_stream *azx_dev, bool set,
>   void snd_hdac_stream_sync(struct hdac_stream *azx_dev, bool start,
>                 unsigned int streams);
>   void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
> -                      unsigned int streams);
> +                      unsigned int streams, bool start);
>   int snd_hdac_get_stream_stripe_ctl(struct hdac_bus *bus,
>                   struct snd_pcm_substream *substream);
> 
> diff --git a/sound/hda/hdac_stream.c b/sound/hda/hdac_stream.c
> index b53de020309f..0411a8fe9d6f 100644
> --- a/sound/hda/hdac_stream.c
> +++ b/sound/hda/hdac_stream.c
> @@ -664,7 +664,7 @@ static void azx_timecounter_init(struct hdac_stream *azx_dev,
>    * updated accordingly, too.
>    */
>   void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
> -                      unsigned int streams)
> +                      unsigned int streams, bool start)
>   {
>       struct hdac_bus *bus = azx_dev->bus;
>       struct snd_pcm_runtime *runtime = azx_dev->substream->runtime;
> @@ -672,6 +672,9 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>       bool inited = false;
>       u64 cycle_last = 0;
> 
> +    if (!start)
> +        goto skip;
> +
>       list_for_each_entry(s, &bus->stream_list, list) {
>           if ((streams & (1 << s->index))) {
>               azx_timecounter_init(s, inited, cycle_last);
> @@ -682,6 +685,7 @@ void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
>           }
>       }
> 
> +skip:
>       snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
>       runtime->trigger_tstamp_latched = true;
>   }
> diff --git a/sound/pci/hda/hda_controller.c b/sound/pci/hda/hda_controller.c
> index 5d86e5a9c814..f3330b7e0fcf 100644
> --- a/sound/pci/hda/hda_controller.c
> +++ b/sound/pci/hda/hda_controller.c
> @@ -275,8 +275,7 @@ static int azx_pcm_trigger(struct snd_pcm_substream *substream, int cmd)
>       spin_lock(&bus->reg_lock);
>       /* reset SYNC bits */
>       snd_hdac_stream_sync_trigger(hstr, false, sbits, sync_reg);
> -    if (start)
> -        snd_hdac_stream_timecounter_init(hstr, sbits);
> +    snd_hdac_stream_timecounter_init(hstr, sbits, start);
>       spin_unlock(&bus->reg_lock);
>       return 0;
>   }
> diff --git a/sound/soc/intel/skylake/skl-pcm.c b/sound/soc/intel/skylake/skl-pcm.c
> index 613b27b8da13..7eec15a2c49e 100644
> --- a/sound/soc/intel/skylake/skl-pcm.c
> +++ b/sound/soc/intel/skylake/skl-pcm.c
> @@ -446,10 +446,10 @@ static int skl_decoupled_trigger(struct snd_pcm_substream *substream,
> 
>       if (start) {
>           snd_hdac_stream_start(hdac_stream(stream));
> -        snd_hdac_stream_timecounter_init(hstr, 0);
>       } else {
>           snd_hdac_stream_stop(hdac_stream(stream));
>       }
> +    snd_hdac_stream_timecounter_init(hstr, 0, start);
> 
>       spin_unlock_irqrestore(&bus->reg_lock, cookie);
> 
> @@ -1145,8 +1145,7 @@ static int skl_coupled_trigger(struct snd_pcm_substream *substream,
> 
>       /* reset SYNC bits */
>       snd_hdac_stream_sync_trigger(hstr, false, sbits, AZX_REG_SSYNC);
> -    if (start)
> -        snd_hdac_stream_timecounter_init(hstr, sbits);
> +    snd_hdac_stream_timecounter_init(hstr, sbits, start);
>       spin_unlock_irqrestore(&bus->reg_lock, cookie);
> 
>       return 0;
> 
> 
>                      Jaroslav
> 

Functionally it looks correct, so that would be acceptable to me.
diff mbox series

Patch

diff --git a/include/sound/pcm.h b/include/sound/pcm.h
index ac8f3aef9205..3539af9f733e 100644
--- a/include/sound/pcm.h
+++ b/include/sound/pcm.h
@@ -361,7 +361,6 @@  struct snd_pcm_runtime {
 	snd_pcm_state_t suspended_state; /* suspended stream state */
 	struct snd_pcm_substream *trigger_master;
 	struct timespec64 trigger_tstamp;	/* trigger timestamp */
-	bool trigger_tstamp_latched;     /* trigger timestamp latched in low-level driver/hardware */
 	int overrange;
 	snd_pcm_uframes_t avail_max;
 	snd_pcm_uframes_t hw_ptr_base;	/* Position at buffer restart */
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 4057f9f10aee..ced5bd2d7ebb 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -1194,8 +1194,7 @@  static void snd_pcm_trigger_tstamp(struct snd_pcm_substream *substream)
 	if (runtime->trigger_master == NULL)
 		return;
 	if (runtime->trigger_master == substream) {
-		if (!runtime->trigger_tstamp_latched)
-			snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
+		snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
 	} else {
 		snd_pcm_trigger_tstamp(runtime->trigger_master);
 		runtime->trigger_tstamp = runtime->trigger_master->runtime->trigger_tstamp;
@@ -1422,7 +1421,6 @@  static int snd_pcm_pre_start(struct snd_pcm_substream *substream,
 	if (substream->stream == SNDRV_PCM_STREAM_PLAYBACK &&
 	    !snd_pcm_playback_data(substream))
 		return -EPIPE;
-	runtime->trigger_tstamp_latched = false;
 	runtime->trigger_master = substream;
 	return 0;
 }
diff --git a/sound/hda/hdac_stream.c b/sound/hda/hdac_stream.c
index b53de020309f..271d42b765fc 100644
--- a/sound/hda/hdac_stream.c
+++ b/sound/hda/hdac_stream.c
@@ -660,14 +660,11 @@  static void azx_timecounter_init(struct hdac_stream *azx_dev,
  *
  * Initializes the time counter of streams marked by the bit flags (each
  * bit corresponds to the stream index).
- * The trigger timestamp of PCM substream assigned to the given stream is
- * updated accordingly, too.
  */
 void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
 				      unsigned int streams)
 {
 	struct hdac_bus *bus = azx_dev->bus;
-	struct snd_pcm_runtime *runtime = azx_dev->substream->runtime;
 	struct hdac_stream *s;
 	bool inited = false;
 	u64 cycle_last = 0;
@@ -681,9 +678,6 @@  void snd_hdac_stream_timecounter_init(struct hdac_stream *azx_dev,
 			}
 		}
 	}
-
-	snd_pcm_gettime(runtime, &runtime->trigger_tstamp);
-	runtime->trigger_tstamp_latched = true;
 }
 EXPORT_SYMBOL_GPL(snd_hdac_stream_timecounter_init);