[BUG][IPC4] ipc error 7 for msg 0x13040004|GLB_SET_PIPELINE_STATE when testing multiple pipeline capture

[keqiaozhang]

Describe the bug This issue happens when testing multiple pipelines with SOF IPC4, we had a similar issue https://github.com/thesofproject/sof/issues/6118 before, but only happens when testing with playback, so I file this new one to track the issue with capture.

[ 1144.198899] kernel: snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 4 state 3
[ 1144.198901] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x13040003|0x0: GLB_SET_PIPELINE_STATE
[ 1144.198986] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 1144.198999] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13040003|0x0: GLB_SET_PIPELINE_STATE
[ 1144.199000] kernel: snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 4 state 4
[ 1144.199008] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x13040004|0x0: GLB_SET_PIPELINE_STATE
[ 1144.199157] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000007|0x0: GLB_SET_PIPELINE_STATE
[ 1144.199159] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 7 - Unsupported operation requested
[ 1144.199170] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x13040004|0x0
[ 1144.199171] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to set state 4 for pipeline 4
[ 1144.199172] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
[ 1144.199174] kernel:  Jack in: ASoC: trigger FE cmd: 1 failed: -22
[ 1144.199176] kernel: snd_sof:sof_pcm_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 1 dir 1 cmd 0
[ 1144.199182] kernel: snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x140000 successful
[ 1144.199194] kernel: snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 4 state 2

To Reproduce TPLG=/lib/firmware/intel/avs-tplg/cavs-sdw.tplg MODEL=TGLU_RVP_SDW_IPC4ZPH ~/sof-test/test-case/multiple-pipeline.sh -f c -l 50

Reproduction Rate almost 100%

TPLG

Environment Kernel Branch: topic/sof-dev Kernel Commit: 4e6ca75f7357

SOF Branch: main SOF Commit: 130ea515be76

Zephyr Commit: zephyr-v3.1.0-3042-g8e55e59c5917 2) Name of the topology file * Topology: cavs-sdw.tplg 3) Name of the platform(s) on which the bug is observed. * Platform: TGLU_RVP_SDW_IPC4ZPH

dmesg.txt

[kv2019i]

Caught one case of "error 7" with FW logs that show:

[   79.985000] <inf> pipe: pipe prepare
[   79.985000] <err> volume: volume_prepare(): invalid cd->ramp_func
[   79.985000] <err> module_adapter: module_prepare() error -22: module specific prepare failed, comp_id 393217
[   79.985000] <err> module_adapter: module_adapter_prepare() error ffffffea: module prepare failed
[   79.985000] <err> pipe: pipeline_prepare(): ret = -5, dev->comp.id = 196608
[   79.985000] <err> ipc: ipc: pipe 2 comp 0 prepare failed -5
[   79.985000] <inf> pipe: pipe reset
[   79.985000] <inf> component: comp_set_state(), state already set to 1
[   79.985000] <err> ipc: failed to process msg 19 status 7
[   79.985000] <err> ipc: ipc4: 0 failed err 7

Let's see if we can link more occurences of "invalid cd->ramp_func" to this bug.

[lgirdwood]

@kv2019i @mwasko just wondering since these are not POSIX, can we have a small look up via a macro that can also stringify the IPC4 error codes and use the dictionary ? e.g. [ 79.985000] <err> ipc: ipc4: 0 failed err 7: unsupported copier endpoint (I've just make up an example error code 7)

[kv2019i]

@lgirdwood I've been tempted to add this but I'm a bit worried about the overhead. The kernel does stringify the errors in kernel dmesg, so we have that already.

[lgirdwood]

I'm good as long as kernel can stringify.

[kv2019i]

Lot of hits in IPC4 testing for: [ 79.985000] volume: volume_prepare(): invalid cd->ramp_func [ 79.985000] module_adapter: module_prepare() error -22: module specific prepare failed, comp_id 393217 [ 79.985000] module_adapter: module_adapter_prepare() error ffffffea: module prepare failed

Potential bugfix https://github.com/thesofproject/sof/pull/6414

[ranj063]

potential fix in #6435

[lgirdwood]

potential fix in #6435

Now merged, can we close @keqiaozhang ?

[keqiaozhang]

This issue still can be reproduced on TGLU_UP_HDA_IPC4ZPH.

http://sof-ci.sh.intel.com/#/result/planresultdetail/16530?model=TGLU_UP_HDA_IPC4ZPH&testcase=multiple-pipeline-all-50 dmesg

[  913.755183] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x130a0004|0x0: GLB_SET_PIPELINE_STATE
[  913.755645] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000007|0x0: GLB_SET_PIPELINE_STATE
[  913.755648] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 7 - Unsupported operation requested
[  913.755671] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x130a0004|0x0
[  913.755676] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to set state 4 for pipeline 3
[  913.755679] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -22
[  913.755684] kernel:  HDA Analog: ASoC: trigger FE cmd: 1 failed: -22

mtrace

[    0.202000] <inf> ipc: rx	: 0xc5090004|0x30006
[    0.202000] <inf> ipc: buffer new size 0x300 id 9.0 flags 0x0
[    0.202000] <inf> pipe: comp:9 0x40009 connect buffer 0 as sink
[    0.202000] <inf> pipe: comp:9 0x60003 connect buffer 0 as source
[    0.207000] <inf> ipc: rx	: 0x930a0003|0x0
[    0.207000] <wrn> ipc: ipc_pipeline_complete(): no scheduling component specified, use comp 262154
[    0.207000] <inf> pipe: pipe:10 0x0 pipeline complete, clock freq 400000000Hz
[    0.207000] <inf> ipc: rx	: 0x930a0004|0x0
[    0.207000] <err> hda_dma: hda-dmac: 5 invalid channel 9
[    0.207000] <err> host: comp:10 0x4000a host_params(): hd->chan is NULL
[    0.207000] <err> ipc: ipc: pipe 10 comp 0 params failed -19
[    0.207000] <inf> pipe: pipe:10 0x0 pipe reset
[    0.207000] <inf> component: comp:10 0x30001 comp_set_state(), state already set to 1
[    0.207000] <inf> component: comp:10 0x60004 comp_set_state(), state already set to 1
[    0.207000] <err> ipc: failed to process msg 19 status 7
[    0.207000] <err> ipc: ipc4: 0 failed err 7

[keqiaozhang]

Closing this one, since this issue is not reproducible on TGLU_RVP_SDW_IPC4ZPH. Let's track the similar issue IPC error in https://github.com/thesofproject/sof/issues/6466 for TGLU_UP_HDA_IPC4ZPH.