[BUG][SDW]Shows ipc timed out for 0x30010000 size 76 when run system boot up stress test.

[YvonneYang2]

Describe the bug
Shows ipc timed out for 0x30010000 size 76 when run system reboot stress test. Failed at 22nd time.

To Reproduce

1. Run reboot stress test via "./test-reboot.sh 100"

frequency
Run 100 times, failed at 22nd time.

Expected result
System boot up without any error

Actual result
System bootup with ipc timed out for 0x30010000 size 76

kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 661d261 + PR1359
FW: https://github.com/thesofproject/sof/commits/master commit: 0e8cf66
tplg: https://github.com/bardliao/sof/commits/soundwire-tplg (commit: 0408153), sof-cml-rt711-rt1308-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

dmesg

[    2.918676] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c1d <= 00d0
[    2.918715] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4d1d <= 0011
[    3.424814] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    3.424817] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.424821] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.425074] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.425079] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.425080] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.425083] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.425084] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.425087] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 24 name : PCM1C stream Passthrough Capture 1 reply 0
[    3.425090] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM1C
[    3.425095] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.425098] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    3.425100] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.425102] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.425107] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.425108] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.425119] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.425133] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.425176] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.425181] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    4.930394] rfkill: input handler disabled
[    4.968778] intel-sdw sdw-master-3: IO transfer timed out
[    4.968785] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e1d <= 00a1
[    4.968792] intel-sdw sdw-master-0: IO transfer timed out
[    4.968796] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7520 85a0 7420 84a0 <= 004a 201b
[    5.032778] intel-sdw sdw-master-1: SCP Msg trf timed out
[    7.017775] intel-sdw sdw-master-0: IO transfer timed out
[    7.017782] intel-sdw sdw-master-3: IO transfer timed out
[    7.017785] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4f1d <= 0081
[    7.080779] intel-sdw sdw-master-1: SCP Msg trf timed out
[    9.064823] intel-sdw sdw-master-3: IO transfer timed out
[    9.064831] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c29 <= 00d1

dmesg_failed_22.log

[plbossart]

@YvonneYang2 can you try with MSI disabled?

[YvonneYang2]

Test it 100 times with MSI disabled, issue cannot be reproduced.

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 9f1bd5b + PR1403
FW: https://github.com/thesofproject/sof/commits/master commit: 59c9338
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

[plbossart]

Thanks @YvonneYang2 this helps. @bardliao I think this is an indication we do need to have a single handler for the shared interrupt, we still have 3 (IPC, stream, soundwire).

[YvonneYang2]

@plbossart
Test it 45 times with MSI disabled again on Ubuntu19.04, issue is reproduced once at 20th time. I Will test more times on Ubuntu18.04 next week.

Add options snd_sof_intel_hda_common use_msi=0 in /etc/modprobe.d/alsa-base.conf to disable MSI.

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 9f1bd5b + PR1403
FW: https://github.com/thesofproject/sof/commits/master commit: fe321d6
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

dmesg

[    2.788612] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[    2.788632] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e13 <= 00a1
[    2.788670] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4f13 <= 0081
[    2.955667] urandom_read: 5 callbacks suppressed
[    2.955669] random: unattended-upgr: uninitialized urandom read (24 bytes read)
[    3.010336] random: plymouthd: uninitialized urandom read (8 bytes read)
[    3.079915] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.079942] usbcore: registered new interface driver asix
[    3.089022] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.296352] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    3.296361] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.296371] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.296628] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.296638] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.296642] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.296649] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.296652] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.296662] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 24 name : PCM1C stream Passthrough Capture 1 reply 0
[    3.296672] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM1C
[    3.296685] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.296692] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[    3.296696] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.296704] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.296721] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.296725] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.296760] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.296797] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.296940] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.296951] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    4.234039] random: crng init done
[    4.298149] broken atomic modeset userspace detected, disabling atomic
[    4.840038] intel-sdw sdw-master-3: IO transfer timed out
[    4.840045] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c1d <= 00d0
[    4.840051] intel-sdw sdw-master-0: IO transfer timed out
[    4.840054] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7309 8389 <= 6080
[    4.904091] intel-sdw sdw-master-1: SCP Msg trf timed out
[    6.476229] rfkill: input handler disabled
[    6.888045] intel-sdw sdw-master-0: IO transfer timed out
[    6.888056] intel-sdw sdw-master-3: IO transfer timed out
[    6.888059] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4d1d <= 0011
[    6.952073] intel-sdw sdw-master-1: SCP Msg trf timed out
[    8.936348] intel-sdw sdw-master-3: IO transfer timed out
[    8.936366] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e1d <= 00a1

dmesg_failed_20.log

[YvonneYang2]

Tested it 53 times with MSI interrupt mode, occurred "error: ipc timed out for 0x90030000 size 80", then occurred "ipc timed out for 0x30010000 size 76". Error dmesg is as below :

MSI interrupt mode error dmesg

[    3.004132] intel-sdw sdw-master-1: in sdw_assign_device_num
[    3.004132] intel-sdw sdw-master-1: in sdw_assign_device_num, writing dev_num 1
[    3.247067] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.247161] usbcore: registered new interface driver asix
[    3.254287] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.311596] systemd-udevd (278) used greatest stack depth: 11816 bytes left
[    3.511668] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x90030000 size 80
[    3.511671] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.511676] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.511962] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.511973] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000000 rirb 00
[    3.511974] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.511980] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.511981] sof-audio-pci 0000:00:1f.3: error: can't set params for DMA for trace -110
[    3.511991] sof-audio-pci 0000:00:1f.3: warning: failed to initialize trace -110
[    3.511995] sof-audio-pci 0000:00:1f.3: ASoC: dai register 0000:00:1f.3 #14
[    3.511996] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511997] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP0 Pin'
[    3.511997] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511998] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP1 Pin'
[    3.511999] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511999] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP2 Pin'
[    3.512000] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512000] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP3 Pin'
[    3.512001] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512001] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP4 Pin'
[    3.512002] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512002] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP5 Pin'
[    3.512003] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512004] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'DMIC01 Pin'
[    3.512004] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512005] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'DMIC16k Pin'
[    3.512005] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512006] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp1 Pin'
[    3.512006] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512007] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp2 Pin'
[    3.512007] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512008] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp3 Pin'
[    3.512009] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512011] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Analog CPU DAI'
[    3.512011] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512012] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Digital CPU DAI'
[    3.512012] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512013] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Alt Analog CPU DAI'
[    3.512057] sof-audio-pci 0000:00:1f.3: created machine sdw_rt711_rt1308_rt715
[    3.512058] sof-audio-pci 0000:00:1f.3: Completing SOF PCI probe
[    3.513830] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: Entry mc_probe
[    3.513836] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW0-Playback
[    3.513836] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW0-Capture
[    3.513837] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW1-Playback
[    3.513838] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW3-Capture
[    3.513838] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp1
[    3.513839] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp2
[    3.513839] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp3
[    3.513841] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW0-Playback
[    3.513852] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW0-Capture
[    3.513857] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW1-Playback
[    3.513862] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW3-Capture
[    3.513866] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp1
[    3.513870] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp2
[    3.513874] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp3
[    3.513906] rt711 sdw:0:25d:711:0: ASoC: adding DP3 Playback widget
[    3.513907] rt711 sdw:0:25d:711:0: ASoC: adding DP4 Capture widget
[    3.513908] rt711 sdw:0:25d:711:0: ASoC: adding DP2 Capture widget
[    3.513926] sof-audio-pci 0000:00:1f.3: loading topology:intel/sof-tplg/sof-cml-rt711-rt1308-mono-rt715.tplg
[    3.514661] sof-audio-pci 0000:00:1f.3: Topology: ABI 3:11:0 Kernel ABI 3:11:0
[    3.514663] sof-audio-pci 0000:00:1f.3: ASoC: adding 6 DAPM widgets
[    3.514665] sof-audio-pci 0000:00:1f.3: ASoC: creating DAPM widget PCM0P id 11
[    3.514667] sof-audio-pci 0000:00:1f.3: tplg: ready widget id 0 pipe 1 type 23 name : PCM0P stream Passthrough Playback 0
[    3.514668] sof-audio-pci 0000:00:1f.3: loaded host PCM0P
[    3.514669] sof-audio-pci 0000:00:1f.3:  config: periods snk 2 src 0 fmt 0
[    3.514673] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[    4.015659] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    4.015663] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    4.015668] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    4.015973] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    4.015984] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000000 rirb 00
[    4.015985] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    4.015991] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[    4.015994] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 23 name : PCM0P stream Passthrough Playback 0 reply 0
[    4.015998] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM0P
[    4.015999] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    4.016004] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    4.016006] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    4.016016] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    4.016030] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    4.016072] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    4.016076] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    5.032618] intel-sdw sdw-master-1: IO transfer timed out
[    5.032624] intel-sdw sdw-master-0: IO transfer timed out
[    5.170870] rfkill: input handler disabled
[    6.714481] intel-sdw sdw-master-1: intel_suspend_runtime start

logs:
dmesg_failed_53.log

Tested it 300 times with MSI disabled mode, original issue didn't occur. But occurred " platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 ". Failed at 141th and 203th time. Reproduced rate is 2/300. Error dmesg is as below:

MSI disabled error dmesg

[    0.913333] printk: console [netcon0] enabled
[    0.913333] netconsole: network logging started
[    0.913361] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    0.914635] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    0.914662] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    0.914662] cfg80211: failed to load regulatory.db
[    1.072605] nvme nvme0: missing or invalid SUBNQN field.
[    1.074475] nvme nvme0: 8/0/0 default/read/poll queues
[    1.077015]  nvme0n1: p1 p2
[    1.077629] Freeing unused kernel image memory: 1308K
[    1.086186] Write protecting the kernel read-only data: 18432k
[    1.086583] Freeing unused kernel image memory: 2008K
[    1.086742] Freeing unused kernel image memory: 1124K
[    1.086744] Run /init as init process
[    1.127264] udevadm (165) used greatest stack depth: 13776 bytes left
[    1.132127] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.132166] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
[    1.133259] xhci_hcd 0000:00:14.0: hcc params 0x200077c1 hci version 0x110 quirks 0x0000000000009810
[    1.133264] xhci_hcd 0000:00:14.0: cache line size of 64 is not supported
[    1.133523] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.133524] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.133526] usb usb1: Product: xHCI Host Controller
[    1.133527] usb usb1: Manufacturer: Linux 5.4.0-rc4-sdw-validation-20191104-olyp-v2-0-0e6065c xhci-hcd
[    1.133528] usb usb1: SerialNumber: 0000:00:14.0
[    1.133694] hub 1-0:1.0: USB hub found
[    1.133711] hub 1-0:1.0: 12 ports detected
[    1.134950] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.134988] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2

logs:
dmesg_failed_141.log
logger_failed_203.log

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 9f1bd5b + PR1403
FW: https://github.com/thesofproject/sof/commits/master commit: e5fe2ca
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

[plbossart]

Thanks @YvonneYang2

I think we can assume for now that the MSI mode is still problematic. The issue with MSI disabled has nothing to do with SOF so we can ignore it.

@bardliao can you work with @YvonneYang2 to see if your interrupt rework works better with MSI enabled? Thanks!

[YvonneYang2]

Tested it with latest integration/soundwire-latest + #1412 , issue can still be reproduced.

Tested it 300 times, original issue occurred 4 times.

ipc timed out for 0x30010000 size 84 dmesg log

[    3.270400] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.270422] usbcore: registered new interface driver asix
[    3.271950] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.528375] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 84
[    3.528378] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.528382] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.528635] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.528641] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.528642] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.528645] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.528646] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.528648] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 6 name : PGA2.0 stream none reply 0
[    3.528651] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PGA2.0
[    3.528657] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.528660] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    3.528662] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.528664] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.528669] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.528670] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.528680] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.528695] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.528737] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.528742] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    3.529604] systemd-udevd (268) used greatest stack depth: 12280 bytes left
[    3.530243] systemd-udevd (269) used greatest stack depth: 11608 bytes left
[    5.031401] intel-sdw sdw-master-0: IO transfer timed out
[    5.126618] rfkill: input handler disabled
[    5.159346] intel-sdw sdw-master-1: SCP Msg trf timed out
[    6.716006] intel-sdw sdw-master-3: intel_suspend_runtime start
[    6.716018] intel-sdw sdw-master-3: intel_suspend_runtime done
[    7.079448] intel-sdw sdw-master-0: IO transfer timed out

dmesg_failed_54.log

Beside, occurred 3 times "ipc timed out for 0x30200000 size 36"

ipc timed out for 0x30200000 size 36 dmesg log

[    3.277592] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.277629] usbcore: registered new interface driver asix
[    3.279548] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.550745] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30200000 size 36
[    3.550754] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.550763] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.551020] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.551030] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.551034] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.551041] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.551045] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.551051] sof-audio-pci 0000:00:1f.3: error: buffer BUF1.0 load failed
[    3.551058] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 31 name : BUF1.0 stream none reply 0
[    3.551067] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget BUF1.0
[    3.551075] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.551091] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.551095] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.551129] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.551167] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.551314] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.551325] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    3.554367] systemd-udevd (279) used greatest stack depth: 12280 bytes left
[    3.555067] systemd-udevd (282) used greatest stack depth: 11576 bytes left
[    4.961855] rfkill: input handler disabled
[    5.094460] intel-sdw sdw-master-3: IO transfer timed out
[    5.094467] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e29 <= 00a1
[    5.094476] intel-sdw sdw-master-0: IO transfer timed out
[    5.158462] intel-sdw sdw-master-1: SCP Msg trf timed out
[    7.142501] intel-sdw sdw-master-0: IO transfer timed out
[    7.142511] intel-sdw sdw-master-3: IO transfer timed out

dmesg_failed_115.log

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 085b4bf + PR1403
FW: https://github.com/thesofproject/sof/commits/master commit: 0b7fd03
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

[YvonneYang2]

Issue cannot be reproduced in 120 times test-reboot stress test with #1451

kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: fb40b85 + PR1451
FW: https://github.com/thesofproject/sof/commits/master commit: 835d876
tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715