[BUG] IPC timed out when multiple-pause-resume on TGLU-VOLT-SDW

[1994lwz]

Describe the bug
in inner daily 6885 testcase=multiple-pause-resume-25
ipc timed out when multiple-pause-resume on TGLU-VOLT-SDW

To Reproduce
TPLG=/lib/firmware/intel/sof-tplg/sof-tgl-sdw-max98373-rt5682.tplg ~/sof-test/test-case/multiple-pause-resume.sh -r 25
not 100%

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 0715e9e6
SOF Branch: main
SOF Commit: 3e260cc
Topology:/lib/firmware/intel/sof-tplg/sof-tgl-sdw-max98373-rt5682.tplg
Platform: TGLU-VOLT-SDW

Screenshots or console output
[console]

=== PAUSE ===                                                            
(6/25) pcm'Speaker' cmd'aplay' id'0': Wait for 28 ms before pause

(6/25) pcm'Speaker' cmd'aplay' id'0': Wait for 23 ms before resume

(5/25) pcm'Amplifier Reference' cmd'arecord' id'1': Wait for 49 ms before resume
    error: fetch_entry() failed with: -1, aborting
arecord: do_pause:1581: pause release error: Connection timed out
                                                                          

=== PAUSE ===                                                            arecord: do_pause:1570: pause push error: File descriptor in bad state
                                                                          

(6/25) pcm'Amplifier Reference' cmd'arecord' id'1': Wait for 25 ms before resume
 aplay: do_pause:1570: pause push error: Connection timed out
                                                                          

=== PAUSE ===                                                            
(7/25) pcm'Speaker' cmd'aplay' id'0': Wait for 38 ms before resume
 aplay: do_pause:1570: pause push error: Connection timed out

[dmesg]dmesg.txt

[dmesg.txt](https://github.com/thesofproject/sof/files/7241792/dmesg.txt)
[ 4221.638414] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[ 4221.641786] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 2 dir 0 cmd 3
[ 4221.934872] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 4221.934905] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 4222.144656] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x60070000 (msg/reply size: 12/12)
[ 4222.144673] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: preventing DSP entering D3 state to preserve context
[ 4222.144676] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump start ]------------
[ 4222.144686] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000083 rirb 00
[ 4222.144692] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 4222.144706] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 4222.144710] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump end ]------------
[ 4222.144714] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump start ]------------
[ 4222.144720] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: status: fw entered - code 00000005
[ 4222.144947] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 4222.144951] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump end ]------------
[ 4222.144968] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -110
[ 4222.144977] kernel:  Amplifier Reference: ASoC: trigger FE cmd: 4 failed: -110
[ 4222.144987] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 3 dir 1 cmd 3
[ 4222.144997] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 4222.145016] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: trace IO error
[ 4222.434915] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 4222.434933] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG

[sof-logger]

[   863784208.176299] (          20.625000) c0 ll-schedule        ./schedule/ll_schedule.c:115  INFO task complete 0xbe1c0180 pipe-task 
[   863784087.915887] (          31.979166) c0 dw-dma                 src/drivers/dw/dma.c:1114 ERROR dw_dma_get_data_size(): xrun detected
[   863784105.728387] (          17.812500) c0 dai          3.17           src/audio/dai.c:892  ERROR dai_report_xrun(): underrun due to no data available[   863784123.176303] (          17.447916) c0 dai          3.17           src/audio/dai.c:726  ERROR comp_underrun(): dev->comp.id = 17, source->avail = 0, copy_bytes = 0
[   863784168.697134] (          26.406248) c0 pipe         3.18  ....../pipeline-stream.c:205  ERROR pipeline_copy(): ret = -61, start->comp.id = 17, dir = 1
[   863784187.551300] (          18.854166) c0 pipe         3.18  ..../pipeline-schedule.c:106  ERROR pipeline_task(): xrun recovery failed! pipeline is stopped.

[bkokoszx]

@1994lwz
Is it reproduced only in inner testes?

[1994lwz]

@bkokoszx In inner daily tests after 6885, this issue does not seem to reappear, and not reproduce by manual test.

[lgirdwood]

@1994lwz please close if resolved.

[plbossart]

@1994lwz please close if resolved.

its' not resolved, it's broken by design with dependencies between pipelines.

[plbossart]

@1994lwz please close if resolved.

its' not resolved, it's broken by design with dependencies between pipelines.

I meant the functionality is not resolved, maybe the timeout is.

[ranj063]

how did this get resolved? I mean which PR fixed this issue?

[lgirdwood]

@1994lwz please close if resolved.

its' not resolved, it's broken by design with dependencies between pipelines.

right, are you meaning the mixer/demux/mux dependencies or something else ?

[plbossart]

Yes, pause_push/release on playback/capture doesn't work with this complicated topology where playback and capture are joined in multiple ways.

[plbossart]

Specifically the smart-amp should act like a mixer and keep going until all its sources are paused. Same for mux-demux, it should keep going until all its sinks are paused.

[lgirdwood]

@lyakh it seems like smart amp also need the fixes for multiple in/out streams you were looking at for mixer and mux. Worth checking the topology for any other comp with multiple in/out streams. We should also lift this logic into higher level.

[lyakh]

why is KPBM forking? And two streams joined at a PCM?..