[BUG]Long-running cavstool cause random failures

[keqiaozhang]

Describe the bug I'm enabling the zephyr logging tool cavstool in sof-test to capture the etrace for Zephyr platforms. Since the cavstool can follow a ring buffer in etrace, so we start the cavstool for the whole test duration, no only at the end of the test(Please refer to https://github.com/thesofproject/sof-test/pull/897). But I found that starting BOTH sof-logger DMA trace AND cavstool for the whole test duration will introduce new IPC errors/timeouts. For example: run one test case for several times or run different cases in sequence, then we will hit the IPC errors/timeouts.

Issue happens when testing check-playback-3times(https://sof-ci.01.org/softestpr/PR897/build103/devicetest/): dmesg

[  238.474648] kernel: snd_sof:ipc3_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[  238.475009] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x30100000 (msg/reply size: 48/20): -12
[  238.475024] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to setup widget PIPELINE.30.ALH2.OUT
[  238.475030] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to set up connected widgets
[  238.475042] kernel: snd_sof:sof_ipc3_pcm_hw_params: sof-audio-pci-intel-tgl 0000:00:1f.3: stream_tag 1
[  238.475069] kernel: snd_sof:ipc3_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[  238.475356] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x60010000 (msg/reply size: 108/20): -19
[  238.475370] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: HW params ipc failed for stream 1
[  238.475374] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -19
[  238.475383] kernel:  Jack Out: ASoC: __soc_pcm_hw_params() failed (-19)
[  238.475427] kernel: sdw_deprepare_stream: subdevice #0-Playback: inconsistent state state 1
[  238.475439] kernel:  Jack Out: ASoC: dpcm_fe_dai_hw_params failed (-19)

cavstool-etrace

[00:00:00.000,000] <inf> dma_intel_adsp_gpdma: intel_adsp_gpdma_init: dma DMA_0 initialized
[00:00:00.000,000] <inf> dma_intel_adsp_gpdma: intel_adsp_gpdma_init: dma DMA_1 initialized
*** Booting Zephyr OS build c6c7dde96900  ***

[00:00:00.000,000] <inf> main: SOF on intel_adsp_cavs25
561007 zephyr_ll_scheduler_init(): unsupported domain 2

[00:00:00.000,000] <inf> main: SOF initialized
574935 zephyr_ll_scheduler_init(): unsupported domain 2

597051: SHM: FW ABI 0x3017000 DBG ABI 0x5003000 tags SOF:v2.0-rc1-1134-g4af7082ad049 zephyr:c6c7dde96900 src hash 0x0a67a15a (ldc hash 0x0a67a15a)

159822025 pipeline_new(): Out of Memory

159822915 ipc_pipeline_new(): pipeline_new() failed

159823646 ipc: pipe 30 creation failed -12

159837978 ipc: comp 60 not found

To Reproduce

1. run one test case for several times, like run check-playback-3times *5
2. run different cases in sequence like check-sof-logger.sh -> check-ipc-flood.sh -> check-playback-10sec.sh -> check-capture-10sec.sh

Reproduction Rate 1/5

[marc-hb]

Is this not a duplicate of thesofproject/sof#6042 ? (which was not an sof-test issue either)

cc: @jsarha

[marc-hb]

OK, the difference is: thesofproject/sof#6042 is not long-running. But it seems to fail the same, just more rarely.

[mengdonglin]

won't fix cavs tool issue. Will switch to new logging tool.

[marc-hb]

Maybe fixed by @kv2019i's

• https://github.com/zephyrproject-rtos/zephyr/pull/50178