[BUG] multiple platforms and topologies: multiple-pause-resume failures with "nothing to copy"

[lyakh]

Describe the bug
Running the "multiple-pause-resume-50" test on PTL with the nocodec topology fails intermittently, sometimes with a "nothing to copy" warning repeated frequently in mtrace

To Reproduce
For highest probability run multiple-pause-resume.sh -r 50 on PTL with nocodec

Reproduction Rate
about 20%

Impact
Potential bug in firmware or the driver

Environment

1. Appeared in multiple PR tests, e.g. https://sof-ci.01.org/sofpr/PR10106/build13845/devicetest/index.html?model=MTLP_RVP_NOCODEC&testcase=multiple-pause-resume-50 but has also been reproduced with a clean state:
   • Kernel: 0aa367fe53d5
   • SOF: b35aba3
   • Zephyr: e22ca6b132840efb23b4a00ff7718225a0dd9f29
2. Name of the topology file
   • Topology: sof-mtl-nocodec.tplg, sof-ptl-nocodec.tplg
3. Name of the platform(s) on which the bug is observed.
   • Platform: MTL, PTL

Screenshots or console output
mtrace:

[ 1250.959101] <wrn> dai_comp: dai_common_copy: comp:3 0x30005 nothing to copy, src_frames: 96, sink_frames: 0
[ 1250.960103] <wrn> dai_comp: dai_common_copy: comp:3 0x30005 nothing to copy, src_frames: 96, sink_frames: 0
[ 1250.961101] <wrn> dai_comp: dai_common_copy: comp:3 0x30005 nothing to copy, src_frames: 96, sink_frames: 0
[ 1250.962101] <wrn> dai_comp: dai_common_copy: comp:3 0x30005 nothing to copy, src_frames: 96, sink_frames: 0
[ 1250.962128] <wrn> host_comp: host_get_copy_bytes_normal: comp:2 0x20005 Skipped 20 no-bytes events in last 21 ms, bytes 0
[ 1250.962133] <wrn> host_comp: host_get_copy_bytes_normal: comp:2 0x20005 no bytes to copy, available samples: 384, free_samples: 0

Nothing obvious in the kernel log. In fact it is interesting, that "always" when this bug appears the kernel log is absent in the CI report, but manually reproducing the bug doesn't reveal obvious problems on the Linux side

[abonislawski]

@wszypelt could you please assign someone to reproduce this in python tests?

[lyakh]

Now also observed in a PR test on PTL #10094 (comment) but unclear whether it is caused by that PR or not.

[lyakh]

now also observed on PTL in SDW and nocodec configurations without the IPC timeout https://sof-ci.01.org/sofpr/PR10118/build13953/devicetest/index.html?model=PTLP_RVP_SDW&testcase=multiple-pause-resume-50 and https://sof-ci.01.org/sofpr/PR10118/build13953/devicetest/index.html?model=PTLP_RVP_SDW&testcase=multiple-pause-resume-50

[lgirdwood]

@ranj063 is your pause/release stress tester ready ?

[ranj063]

@ranj063 is your pause/release stress tester ready ?

@lgirdwood nope still working on it. Hopefully by tomorrow.

[lyakh]

Update: this bug is now mostly appearing on PTL. Most often in the "multiple-pause-resume" test with the nocodec topology, but sometimes also with other topologies and in pure playback or capture "pause-resume" tests as well. Some occurrences:
https://sof-ci.01.org/sofpr/PR10094/build13984/devicetest/index.html?model=PTLH_HDA_AIOC&testcase=check-pause-resume-playback-100
https://sof-ci.01.org/sofpr/PR10094/build13984/devicetest/index.html?model=PTLH_RVP_NOCODEC&testcase=multiple-pause-resume-50
https://sof-ci.01.org/sofpr/PR10122/build14047/devicetest/index.html?model=PTLH_RVP_NOCODEC&testcase=multiple-pause-resume-50
https://sof-ci.01.org/sofpr/PR10118/build13953/devicetest/index.html?model=PTLP_RVP_SDW&testcase=multiple-pause-resume-50
https://sof-ci.01.org/sofpr/PR10118/build13953/devicetest/index.html?model=PTLH_RVP_NOCODEC&testcase=multiple-pause-resume-50
https://sof-ci.01.org/sofpr/PR10106/build13845/devicetest/index.html?model=MTLP_RVP_NOCODEC&testcase=multiple-pause-resume-50

[ranj063]

@lyakh I think the MTLP nocodec and PTL nocodec failures should be separate issues. If you look at the errors, on MTLP, it looks like the DW DMA runs into an xrun. That cannot be the case on PTL as we dont use the DWDMA for SSP on PTL

[ranj063]

@lyakh @kv2019i I am thinking our multiple-pause-resume test needs a bit of modification in terms on how we deal with xruns when executing the "press space for pause" specifically. A lot of errors we see look like this:
=== PAUSE === aplay: do_pause:1586: pause push error: File descriptor in bad state

This error when doing pause usually occurs when the stream is not in the RUNNING state.

And I think this is because when an xrun happens, the application will try to recover from the xrun with a prepare and restart and we likely do a pause when the stream is not yet in the RUNNING state after recovering from the xrun.
We probably need to modify the pause script to make sure that the stream state is correct before pausing.

Of course, if the application never recovers from the xrun, we've got to fix that. What do you think?

[ranj063]

@lyakh @kv2019i I am thinking our multiple-pause-resume test needs a bit of modification in terms on how we deal with xruns when executing the "press space for pause" specifically. A lot of errors we see look like this: === PAUSE === aplay: do_pause:1586: pause push error: File descriptor in bad state

This error when doing pause usually occurs when the stream is not in the RUNNING state.

And I think this is because when an xrun happens, the application will try to recover from the xrun with a prepare and restart and we likely do a pause when the stream is not yet in the RUNNING state after recovering from the xrun. We probably need to modify the pause script to make sure that the stream state is correct before pausing.

Of course, if the application never recovers from the xrun, we've got to fix that. What do you think?

@lyakh @kv2019i have a look at this PR thesofproject/sof-test#1287

I ran the multiple-pause-test several times on the PTL nocodec device and it failed with the "File descriptor in bad state" error in about 40-50% of the time. With this PR, I have not seen the error in the last 5 runs on the same device. Hopefully this lets us focus on the real problem, which is why the xruns happen when the test fails.