Strange trigger_htstamp after snd_pcm_drop

[z-s-e]

I have conceptually the following situation (actual code can be found here):

// sound is currently playing
snd_pcm_status(pcm, pcm_status);
snd_pcm_status_get_htstamp(pcm_status, &ts1);
snd_pcm_drop(pcm);
snd_pcm_status(pcm, pcm_status);
snd_pcm_status_get_trigger_htstamp(status, &ts2);

On my hardware I get a ts2 timestamp that is earlier than ts1. From my understanding that should be impossible, as ts2 should contain the timestamp of when the drop happened, which should obviously be after ts1. Is that a bug or do I misunderstand the meaning of those timestamps?

[perexg]

It looks like a bug. Could you show the plugin chain (using snd_pcm_dump or so) ? Or are you using direct hw:X device?

[z-s-e]

I'm using front:CARD=Generic_1,DEV=0

snd_pcm_dump gives:

Soft volume PCM
Control: PCM Playback Volume
min_dB: -51
max_dB: 0
resolution: 256
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate 

[perexg]

There should be more information (lines after Slave:).

[z-s-e]

ah yeah, sorry.

Soft volume PCM
Control: PCM Playback Volume
min_dB: -51
max_dB: 0
resolution: 256
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate   : 48000 (48000/1)
  msbits       : 32
  buffer_size  : 96000
  period_size  : 48000
  period_time  : 1000000
  tstamp_mode  : ENABLE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 48000
  period_event : 0
  start_threshold  : 9223372036854775807
  stop_threshold   : 96000
  silence_threshold: 0
  silence_size : 0
  boundary     : 6755399441055744000
Slave: Hardware PCM card 1 'HD-Audio Generic' device 0 subdevice 0
Its setup is:
  stream       : PLAYBACK
  access       : MMAP_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate   : 48000 (48000/1)
  msbits       : 32
  buffer_size  : 96000
  period_size  : 48000
  period_time  : 1000000
  tstamp_mode  : ENABLE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 48000
  period_event : 0
  start_threshold  : 9223372036854775807
  stop_threshold   : 96000
  silence_threshold: 0
  silence_size : 0
  boundary     : 6755399441055744000
  appl_ptr     : 96000
  hw_ptr       : 47178

[perexg]

So it's basically equivalent to hw:X device so it appears like a kernel issue, but the kernel changes the trigger tstamp only if the state changes. It may be possible that the stream was already stopped for a reason (underrun or so). Could you check the stream state for the first snd_pcm_status call?

[z-s-e]

The code is called directly from a switch statement that checks for the state here, so this code gets only called when the last update is in SND_PCM_STATE_RUNNING but I also just re-checked it by verifying the value of snd_pcm_status_get_state right before the drop.

[perexg]

Is trigger timestamp identical before and after drop?

[z-s-e]

Good call, indeed they are the same (I assume you meant after the drop+update_status).

[z-s-e]

Well anyway, thanks for clarifying this is a kernel bug.

I can create a bug over at bugzilla.kernel.org if you want, but otherwise I guess I close this then as it is not a alsa-lib bug.

[perexg]

I'd like to keep this open until resolved.

[z-s-e]

Some more info: This happens on my integrated audio (ALC287 Analog) as well as when outputting to hdmi. I've also tested a usb interface, there it does not happen.