[BUG][MTL] MOD_SET_DX causes DSP exception (very recent regression)

[fredoh9]

Describe the bug

[   75.070388] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x44000000|0x3060004c: MOD_LARGE_CONFIG_SET [data size: 76]
[   75.070781] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x64000000|0x3060004c: MOD_LARGE_CONFIG_SET
[   75.070825] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0x44000000|0x3060004c: MOD_LARGE_CONFIG_SET [data size: 76]
[   75.070838] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x47000000|0x0: MOD_SET_DX [data size: 8]
[   75.072688] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc rx      : 0x1b0a0000|0x0: GLB_NOTIFICATION|EXCEPTION_CAUGHT
[   75.072697] kernel: snd_sof:sof_ipc4_rx_msg: sof-audio-pci-intel-mtl 0000:00:1f.3: Unhandled DSP message: 0x1b0a0000|0x0
[   75.072702] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc rx done : 0x1b0a0000|0x0: GLB_NOTIFICATION|EXCEPTION_CAUGHT
[   75.576913] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc timed out for 0x47000000|0x0
[   75.576968] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Attempting to prevent DSP from entering D3 state to preserve context
[   75.576977] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ IPC dump start ]------------
[   75.577049] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: Host IPC initiator: 0xc7000000|0x0|0x0, target: 0x1b0a0000|0x0|0x0, ctl: 0x3
[   75.577094] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ IPC dump end ]------------
[   75.577209] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ DSP dump start ]------------
[   75.577265] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: IPC timeout
[   75.577307] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: fw_state: SOF_FW_BOOT_COMPLETE (7)
[   75.577387] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ROM status: 0x5, ROM error: 0x0
[   75.577442] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ROM debug status: 0x50000005, ROM debug error: 0x0
[   75.577508] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ROM feature bit enabled
[   75.577542] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ------------[ DSP dump end ]------------
[   75.577570] kernel: sof-audio-pci-intel-mtl 0000:00:1f.3: ctx_save IPC error: -110, proceeding with suspend

To Reproduce
Either checking just booting dmesg or
running runtime pm test by (below is example of MTL NOCODEC)

TPLG=/lib/firmware/intel/sof-ace-tplg/sof-mtl-nocodec.tplg MODEL=MTLP_RVP_NOCODEC ~/sof-test/test-case/check-runtime-pm-status.sh -d 10

Reproduction Rate
100%

Expected behavior
No exception.

Reverting pr7857 and pr7325 is submitted, It looks working fine:

• [DRAFT] Revert/pr7857 pr7325 test #7873

The manifest change in #7857 moved Zephyr about 100 commits forward.

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 5fc4e9175191
SOF Branch: main
SOF Commit: 2cef521c3672

Screenshots or console output
mtl-nocodec-dmesg.txt
mtl-nocodec-mtrace.txt

[marc-hb]

Quoting @fredoh9 in a revert draft PR:

#7857 was daily tested. It alone doesn't create the crash.

Yesterday's daily test link: planresultdetail/28254 == PASS
Start Time: 2023-06-27 10:32:56 UTC
SOF Branch: main
SOF Commit: 73cd960e0ed4 == #7857 exactly

[marc-hb]

https://sof-ci.01.org/sofpr/PR7700/build10102/devicetest/index.html has only verify-kernel-log.sh, check-runtime-pm.sh and checks-suspend-resume-*.sh always failing which is why 7700 is also a suspect.

The next daily test run planresultdetail/28309 fails the same tests and again it has only #7700 on top:

Start Time: 2023-06-28 10:34:13 UTC
Kernel Branch: topic/sof-dev
Kernel Commit: 5fc4e9175191
SOF Branch: main
SOF Commit: 2cef521c3672

Yet reverting only 7857 and 7325 seems to fix it... It's like ALL these are needed together to reproduce.

https://sof-ci.01.org/softestpr/PR1071/build516/devicetest/index.html is consistencly failing all PM tests with daily SOF build with commit 2cef521 = zephyr uprev + TDFB but no 7325 yet.

EDIT: and now totally unrelated and newer https://sof-ci.01.org/sofpr/PR7824/build10195/devicetest is passing... this is madness.

[fredoh9]

Today's daily build/test are fine. Can we explain this is as PR dependency problem?
#7325 has a dependency on #7857.
#7325 merged after the daily build, that’s why PR#7869 helped?

[marc-hb]

#7325 has a dependency on #7857.

I recommended these two to be separate. Maybe they shouldn't have been? Maybe the dependency is somehow "both ways".

Lowering priority because it's not reproducing anymore. Leaving open because there are still unexplained mysteries.