[BUG][CML]" ipc error for 0x60060000 size 12"when do Capture-pause-release test using headset(0,0)

[Liviali155]

Describe the bug
I/O error when do Capture-pause-release test using headset (0,0)
After error occurred arecord stop,but if arecord again,it can work normally

To Reproduce
1.sudo reboot
2. ./sof-test-pause-release.sh -t pcm0c (script as attachment)

Reproduction Rate
10/10

Expected behavior
There is no I/O error,after error occurred arecord stop,but if arecord again,it can work normally

Actual result
I/O error

dmesgerror.log

[ 7739.251053] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 7739.251076] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 7739.732448] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 1 cmd 3
[ 7739.732453] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 7739.732726] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x60060000 size 12
[ 7739.733241] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20240000 successful
[ 7739.733245]  HDA Analog: ASoC: trigger FE cmd: 3 failed: -22
[ 7739.733251] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 1 cmd 4
[ 7739.733755] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x2024001e successful
[ 7739.733760] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[ 7739.733975] sof-audio-pci 0000:00:1f.3: error: ipc error for 0x60070000 size 12
[ 7739.733977]  HDA Analog: ASoC: trigger FE cmd: 4 failed: -22
[ 7739.750774] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 7739.750796] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 7740.240197] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 1 cmd 0
[ 7740.240209] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 7740.240448] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 7740.240462] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20240000 successful
[ 7740.240471] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 7740.240837] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 7740.240856] sof-audio-pci 0000:00:1f.3: In hda_link_pcm_trigger cmd=0
[ 7740.240876] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG    

Environment
Platform: CML laptop with onboard codec ALC3204 in HDA mode
Firmware: 53d35e4 https://github.com/thesofproject/sof/commits/master
Kernel: b2d9823 https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-hda-generic-2ch.tplg same as firmware

dmesg0218.log
sof_trace0218.log
sof-test-pause-release.txt

[Liviali155]

Seems a Firmware regression issue
I changed firmware to 20200110(commit:c6baa979),error not seen

[Liviali155]

Bi-sect result:
caused by Firmware commit 91fb594

[Liviali155]

Related #2280

[lgirdwood]

@Liviali155 is this fatal ? Does audio continue or do you need to restart aplay ?
@slawblauciak This looks like a race that's easy to reproduce with slower clock ?

[Liviali155]

is this fatal ? Does audio continue or do you need to restart aplay

After error occurred arecord stop,but if arecord again,it can work normally

[lgirdwood]

@slawblauciak @mmaka1 can we make the 400M clock the default for CML etc, the low power clock can then be optionally selected by user who need it until the switching is dynamic at runtime.

[slawblauciak]

Hmm, the FW log doesn't appear complete. I can see many pause/release operations being done from the dmesg, but only one in the FW trace. Is the trace you provided cut in any way? Does it always end up like that?