On 04.04.2018 08:01, Takashi Iwai wrote:
> On Wed, 04 Apr 2018 00:35:24 +0200,
> Pierre-Louis Bossart wrote:
>> On 4/2/18 3:14 PM, Georg Chini wrote:
>>> On 02.04.2018 21:35, Pierre-Louis Bossart wrote:
>>>>
>>>> On 04/02/2018 07:54 AM, Georg Chini wrote:
>>>>> The current code does not call snd_pcm_status_set_audio_htstamp_config()
>>>>> to configure the way timestamps are updated in ALSA. This leads to
>>>>> incorrect time stamps in the status object returned by snd_pcm_status(),
>>>>> so the computed latencies are wrong.
>>>>>
>>>>> This patch uses snd_pcm_status_set_audio_htstamp_config() to set the
>>>>> ALSA report_delay flag to 1 before the call to snd_pcm_status(). With
>>>>> this, time stamps are updated as expected.
>>>>> ---
>>>>> Â src/modules/alsa/alsa-util.c | 7 +++++++
>>>>> Â 1 file changed, 7 insertions(+)
>>>>>
>>>>> diff --git a/src/modules/alsa/alsa-util.c b/src/modules/alsa/alsa-util.c
>>>>> index 61fb4903..b91a0e98 100644
>>>>> --- a/src/modules/alsa/alsa-util.c
>>>>> +++ b/src/modules/alsa/alsa-util.c
>>>>> @@ -1187,6 +1187,7 @@ int pa_alsa_safe_delay(snd_pcm_t *pcm,
>>>>> snd_pcm_status_t *status, snd_pcm_sframes
>>>>> Â Â Â Â Â size_t abs_k;
>>>>> Â Â Â Â Â int err;
>>>>> Â Â Â Â Â snd_pcm_sframes_t avail = 0;
>>>>> +Â Â Â snd_pcm_audio_tstamp_config_t tstamp_config;
>>>>> Â Â Â Â Â Â pa_assert(pcm);
>>>>> Â Â Â Â Â pa_assert(delay);
>>>>> @@ -1200,6 +1201,12 @@ int pa_alsa_safe_delay(snd_pcm_t *pcm,
>>>>> snd_pcm_status_t *status, snd_pcm_sframes
>>>>> Â Â Â Â Â Â * avail, delay and timestamp values in a single kernel call
>>>>> to improve
>>>>> Â Â Â Â Â Â * timer-based scheduling */
>>>>> Â +Â Â Â /* The time stamp configuration needs to be set so that the
>>>>> +Â Â Â Â * ALSA code will use the internal delay reported by the driver */
>>>>> +Â Â Â tstamp_config.type_requested = 1; /* ALSA default time stamp
>>>>> type */
>>>>> +Â Â Â tstamp_config.report_delay = 1;
>>>>> +Â Â Â snd_pcm_status_set_audio_htstamp_config(status, &tstamp_config);
>>>>> +
>>>> are you sure it's necessary or is this possibly a misunderstanding
>>>> of what audio_tstamps are?
>>>>
>>>> this command is only for the audio timestamp, and to the best of my
>>>> knowledge you are not using the results using one of the
>>>> snd_pcm_status_get_audio_htstamp_* commands
>>>>
>>>> the typical usage (see alsa-lib/test/audio_time.c) is this:
>>>>
>>>> Â Â Â snd_pcm_status_set_audio_htstamp_config(status, audio_tstamp_config);
>>>>
>>>> Â Â Â if ((err = snd_pcm_status(handle, status)) < 0) {
>>>> Â Â Â Â Â Â printf("Stream status error: %s\n", snd_strerror(err));
>>>> Â Â Â Â Â Â exit(0);
>>>> Â Â Â }
>>>> Â Â Â snd_pcm_status_get_trigger_htstamp(status, trigger_timestamp);
>>>> Â Â Â snd_pcm_status_get_htstamp(status, timestamp);
>>>> Â Â Â snd_pcm_status_get_audio_htstamp(status, audio_timestamp);
>>>> Â Â Â snd_pcm_status_get_audio_htstamp_report(status, audio_tstamp_report);
>>>>
>>>> if you are not using the _get_audio_hstamp() then the config has
>>>> essentially no effect, and the delay is available separately in the
>>>> status command as before.
>>>>
>>>>> Â Â Â Â Â if ((err = snd_pcm_status(pcm, status)) < 0)
>>>>> Â Â Â Â Â Â Â Â Â return err;
>>> See this bug report, why it is needed:
>>>
>>> https://bugzilla.kernel.org/show_bug.cgi?id=199235
>>>
>>> It finally turned out that there was not a bug but just the flag missing.
>>> We are using snd_pcm_status_get_htstamp() with the time smoother
>>> to calculate sink/source latency.
>> Humm, that looks more like a bug in the fix (20e3f9 'ALSA: pcm: update
>> tstamp only in audio_tstamp changed'). I don't think we intended that
>> changes in the way the audio_tstamp is calculated (with or without
>> delay) would impact when the system timestamp is updated. I am pretty
>> sure we only wanted to update the timestamp when the hw_ptr changed
>> with this fix so as to go back to the traditional behavior before
>> kernel 4.1.
> The fact here is that hwptr still remains same but only the delay
> changes. As the prior-4.1 traditional behavior, the timestamp isn't
> updated in such a case. Before the commit, the timestamp is always
> updated no matter whether hwptr is updated or not, and it broke
> applications.
>
> So, the question is how we should look at the timestamp. The fix is
> based on the assumption that tstamp is always coupled with
> audio_tstamp, where the latter calculation depends on the tstamp
> config flag.
>
> OTOH, if we take rather audio_tstamp always coupled with the
> hwptr+delay, we may fix the code in a different way, too. But this
> would need to remember the last delay, and moreover, I don't think
> it's better interpretation -- if we read tstamp in that way, what the
> heck audio_tstamp is for?
>
>
> thanks,
>
> Takashi
As already said in the bug discussion, I think the right way to fix
the issue is to exclude runtime->delay from the delay estimation
when report_delay is not set. What caused the problems for me
was that the delay snapshot was taken at another time than the
time stamp indicated. snd_pcm_status_get_delay() includes
the delay, while audio time stamp does not and time stamp is
kept at the time of the last audio time stamp update. So the
values are inconsistent which renders the returned delay unusable
if combined with the time stamp.
If the returned delay is also kept at the value corresponding to the
time stamp, it would be all consistent. This does not match the
historical behavior, however.
Regards
           Georg
