Suspicious buffer position reported with insanely large delays

[plbossart]

We seem to have a generic IPC4 delay reporting issue on SoundWire devices:

LNL:

aplay -Dhw:0,0 -c2 -r48000 -fS32_LE /dev/zero -B20000 -F10000 -d1800 --fatal-errors -v --test-position
Suspicious buffer position (3044 total): avail = 48, delay = 7493989779945237086, buffer = 960
Status(R/W) (standalone avail=48 delay=7493989779945237086):
  state       : RUNNING
  trigger_time: 568.697921
  tstamp      : 583.905174
  delay       : 7493989779945237086

TGL (from @bardliao)

Suspicious buffer position (35432 total): avail = 0, delay = 8646911284551353162, buffer = 960
Status(R/W) (standalone avail=0 delay=8646911284551353162):
  state       : RUNNING
  trigger_time: 120.072871
  tstamp      : 0.000000
  delay       : 8646911284551353162
  avail       : 0
  avail_max   : 0

@kv2019i @ujfalusi @RanderWang isn't the firmware supposed to provide timestamps that are used for the delay reporting?

This looks like we have a plumbing issue...

[RanderWang]

@plbossart I add some log in kernel

	/* Calculate the delay taking into account that both pointer can wrap */
	div64_u64_rem(tmp_ptr, substream->runtime->boundary, &tmp_ptr);
	if (substream->stream == SNDRV_PCM_STREAM_PLAYBACK) {
		head_ptr = substream->runtime->status->hw_ptr;
		tail_ptr = tmp_ptr;  // stream position reported by FW
	} else {
		head_ptr = tmp_ptr;
		tail_ptr = substream->runtime->status->hw_ptr;
	}

	if (head_ptr < tail_ptr) {		
		dev_err(sdev->dev, " delay header %lu, tail %lu, b %lu", head_ptr, tail_ptr, substream->runtime->boundary);
		return substream->runtime->boundary - tail_ptr + head_ptr;
	}

[ 1279.512385] sof-audio-pci-intel-mtl 0000:00:1f.3: delay header 35136, tail 35300, b 8646911284551352320
[ 1279.520144] sof-audio-pci-intel-mtl 0000:00:1f.3: delay header 35136, tail 35684, b 8646911284551352320
[ 1279.520622] sof-audio-pci-intel-mtl 0000:00:1f.3: delay header 35520, tail 35684, b 8646911284551352320
[ 1279.520962] sof-audio-pci-intel-mtl 0000:00:1f.3: delay header 35520, tail 35732, b 8646911284551352320
[ 1279.521244] sof-audio-pci-intel-mtl 0000:00:1f.3: delay header 35568, tail 35732, b 8646911284551352320

Should exchange header_ptr & tail_ptr or change above " if (head_ptr < tail_ptr) { " to " if (head_ptr > tail_ptr) {" ?

[plbossart]

What code is this referring to @RanderWang? I can't follow the suggestion since there's no context.

[RanderWang]

@plbossart it is done in SOF delay function

static snd_pcm_sframes_t sof_ipc4_pcm_delay(struct snd_soc_component *component,
					    struct snd_pcm_substream *substream)
{
    ....
}

[plbossart]

replaced by #4781 - same problem with delays.