[BUG] IO error when multiple pause release on APL_UP2_NOCODEC_ZEPHYR

[XiaoyunWu6666]

Describe the bug
IO error when multiple pause release on APL_UP2_NOCODEC_ZEPHYR , but neither xrun nor ipc time out happened

I tried for several times , IO error happened with pcm Port5 Deep Buffer aplay

To Reproduce
TPLG=/lib/firmware/intel/sof-tplg/sof-apl-nocodec.tplg MODEL=APL_UP2_NOCODEC_ZEPHYR ~/sof-test/test-case/multiple-pause-resume.sh -r 100
Reproduction Rate
rather high when -r is set to 100

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 5b26e39d
SOF Branch: main
SOF Commit: 58ce6e6
Zephyr Commit: 8239aea29c16
Topology: sof-apl-nocodec.tplg
Platform:APL_UP2_NOCODEC_ZEPHYR

10429?model=APL_UP2_NOCODEC_ZEPHYR&testcase=multiple-pause-resume-50

Screenshots or console output
[console]

=== PAUSE ===                                                            
(10/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 38 ms before pause

(10/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 42 ms before resume
                                                                           
 
#+                                                 | 00%
=== PAUSE ===                                                            
(11/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 45 ms before pause

(11/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 44 ms before resume
                                                                           
 aplay: pcm_write:2086: write error: Input/output error

2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 Deep Buffer with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] Check expect exit status

[lgirdwood]

@lyakh could be a duplicate or the same as #4414 ?

[marc-hb]

I tried for several times , IO error happened with pcm Port5 Deep Buffer aplay

@XiaoyunWu6666 can you elaborate on this? Are you saying you could reproduce easily? How often? AFAIK no other current test failures can be reproduced easily, so this would be an important regression + a bisectable regression.

[marc-hb]

@lyakh could be a duplicate or the same as #4414 ?

I had a look and the logs look quite different.

[lyakh]

@lyakh could be a duplicate or the same as #4414 ?

as @marc-hb mentioned, logs do look different, but I think the underlying reason could be the same. @XiaoyunWu6666 sorry, maybe there's still something that I cannot read properly in reports like this one - was there a reference to where to find logs and failing test results in this report? I spent minutes reading and re-reading it and couldn't find any? I found such a failing test case in the latest daily test from yesterday February 23, but this wasn't the result that you based your report on?

[lgirdwood]

(11/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 44 ms before resume

aplay: pcm_write:2086: write error: Input/output error

2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 Deep Buffer with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] Check expect exit status

@lyakh fwiw, I've seen this in CI on the deep buffer PCM (could be PCM / pipeline specific).

[plbossart]

(11/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 44 ms before resume
aplay: pcm_write:2086: write error: Input/output error
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 Deep Buffer with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] Check expect exit status

@lyakh fwiw, I've seen this in CI on the deep buffer PCM (could be PCM / pipeline specific).

FWIW, it's deep buffer in name only for now.

# TODO: Modify pipeline deadline to account for deep buffering

[lgirdwood]

(11/50) pcm'Port5 Deep Buffer' cmd'aplay' id'8': Wait for 44 ms before resume
aplay: pcm_write:2086: write error: Input/output error
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] pipeline: Port5 Deep Buffer with aplay
2022-02-22 23:34:15 UTC [REMOTE_INFO] Check expect exit status

@lyakh fwiw, I've seen this in CI on the deep buffer PCM (could be PCM / pipeline specific).

FWIW, it's deep buffer in name only for now.

# TODO: Modify pipeline deadline to account for deep buffering

@marc-hb @keqiaozhang how does "Port5" map to the PCM device number ?