[BUG][GLK][Capture] Overrun during pause-release

[ranj063]

Describe the bug
System shows I/O error when pause arecord then resume. Similar behaviour with all arecord devices. Looks like a pipeline overrun when the user releases pause.

To Reproduce

1. Arecord via "arecord -Dhw:0,1 -r48000 -c2 -fs16_le 1.wav -vv -i"
   2.Pause arecord
   3.Resume asrecord

Reproduction Rate
100% on GLK Ubuntu
On BYT it happens after a few iterations of pause/release

Expected behavior
Resume playback after pause-release

Impact
showstopper

Environment
Firmware: c0c858c https://github.com/thesofproject/sof/commits/master
Kernel: a50a20a https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-glk-da7219.tplg same as firmware
platform： GLK

Screenshots or console output
please refer to thesofproject/linux#1022

[ranj063]

@tlauda FYI. what I notice is that on GLK, the first dai_copy() after release ends up in a overrun because dd->dma_buffer->free is always 0. Could you please take a look?

[ranj063]

@michalgrodzicki could you please assign someone to take a into this?

[mrajwa]

@ranj063 looks like we are facing the same issue on in KWD although conditions are a bit different. Have you spotted commit which causes it?

[ranj063]

@mrajwa no I am not sure when this feature ever worked on GLK. I'll try to find out today.

[keyonjie]

@mrajwa @ranj063 I think you hit 2 kinds of xrun here, they are both because of copy_bytes == 0:
copy_bytes = MIN(avail_bytes, dd->dma_buffer->free),
but @ranj063's case is dd->dma_buffer->free == 0 after pause/release, and @mrajwa's case is avail_bytes from dw-dma driver is 0.

For the former case, we can check how it handled the pausing(e.g. does the last pipeline_copy() is finished before paused? if the dai_copy() is done but the downstream copying(e.g. volume_copy()) is not run, then the dd->dma_buffer may be full).

For the latter case, looks like the logic for chan->ptr_data.current_ptr for capture(without preload) stream is problematic, but let's wait for the author @tlauda's confirm.

[ranj063]

@mrajwa no I am not sure when this feature ever worked on GLK. I'll try to find out today.

@mrajwa I've gone back as far as a month and I still can reproduce this issue.

[YvonneYang2]

Issue reproduced when stop via "ctrl + z" , then resume via command "fg".

Test recipe:
Firmware: 767a81b-2 https://github.com/thesofproject/sof/tree/master
Kernel: 0087d4a-2 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: sof-glk-da7219.tplg same as firmware
platform ：GLK

console

Max peak (4080 samples): 0x01da6ba9 #                    1%
Max peak (4080 samples): 0x011ca6ff #                    0%
Max peak (4080 samples): 0x017b8954 #                    1%
^Z
[1]+  Stopped                 arecord -Dhw:0,1 -f S32_LE -r 48000 -c 2 -i test.wav -vvv -i
test@test-Bobba:~$ fg
arecord -Dhw:0,1 -f S32_LE -r 48000 -c 2 -i test.wav -vvv -i
Max peak (816 samples): 0x011ca6ff #                    0%
overrun!!! (at least 986.694 ms long)
Status:
  state       : XRUN
  trigger_time: 4317.159813239
  tstamp      : 0.000000
  delay       : 0
  avail       : 10224
  avail_max   : 10224
arecord: pcm_read:2103: read error: Input/output error

xrun_error_dmesg.log
xrun_error_logger.log

[tlauda]

@ranj063 Could you share FW logs? What is the sequence from kernel perspective on pause/release? What stream bits are you setting?

@YvonneYang2 In your logs I see that you are doing stop/start instead of pause/release. It looks like there is some kind of host pointer mismatch after such sequence.
Edit: However in dmesg I see pause/release. Are you sure that dmesg and logger logs are from the same scenario?

[ranj063]

@tlauda the firmware logs are in thesofproject/linux#1022

For the sequence, please refer to https://github.com/thesofproject/linux/blob/0087d4afe31bad40a0f365b774547fd69124d58c/sound/soc/sof/intel/hda-stream.c#L215