[BUG] [TGL] runtime-pm-status: dsp is not suspended after 15s, end test #6735
Description
Describe the bug
check-kmod-load-unload and check-kmod-load-unload-after-playback fail like this:
https://sof-ci.01.org/sofpr/PR6733/build2695/devicetest/index.html
2022-12-06 21:45:39 UTC Sub-Test: [REMOTE_INFO] Test Result: PASS!
2022-12-06 21:45:39 UTC [REMOTE_INFO] ===== Starting iteration 1 of 2 =====
2022-12-06 21:45:39 UTC Sub-Test: [REMOTE_INFO] ===== Starting iteration 1 of 1 =====
2022-12-06 21:45:39 UTC Sub-Test: [REMOTE_INFO] wait dsp power status to become suspended
2022-12-06 21:46:01 UTC Sub-Test: [REMOTE_ERROR] dsp is not suspended after 15s, end test
2022-12-06 21:46:01 UTC Sub-Test: [REMOTE_ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2022-12-06 21:46:01 UTC Sub-Test: [REMOTE_ERROR] die() @ /home/ubuntu/sof-test/case-lib/lib.sh
2022-12-06 21:46:01 UTC Sub-Test: [REMOTE_ERROR] main() @ /home/ubuntu/sof-test/test-case/check-kmod-load-unload.sh:72
2022-12-06 21:46:02 UTC Sub-Test: [REMOTE_INFO] pkill -TERM -f mtrace-reader.py
2022-12-06 21:46:02 UTC Sub-Test: [REMOTE_INFO] Test Result: FAIL!
2022-12-06 21:46:02 UTC [REMOTE_ERROR] kmod reload failed
2022-12-06 21:46:02 UTC [REMOTE_ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2022-12-06 21:46:02 UTC [REMOTE_ERROR] die() @ /home/ubuntu/sof-test/test-case/../case-lib/lib.sh
2022-12-06 21:46:02 UTC [REMOTE_ERROR] main() @ /home/ubuntu/sof-test/test-case/check-kmod-load-unload-after-playback.sh:76
2022-12-06 21:46:02 UTC [REMOTE_INFO] pkill -TERM -f mtrace-reader.py
2022-12-06 21:46:02 UTC [REMOTE_INFO] ktime=69 sof-test PID=1435: ending
2022-12-06 21:46:02 UTC [REMOTE_INFO] Test Result: FAIL!
Impact
Affects PR testing, examples:
- https://sof-ci.01.org/sofpr/PR6733/build2695/devicetest/index.html
- https://sof-ci.01.org/sofpr/PR6733/build2695/devicetest/index.html?model=TGLU_RVP_NOCODEC_IPC4ZPH&testcase=check-runtime-pm-status
- https://sof-ci.01.org/linuxpr/PR4080/build2383/devicetest/index.html?model=TGLU_RVP_NOCODEC_IPC4ZPH&testcase=check-kmod-load-unload-after-playback
- https://sof-ci.01.org/linuxpr/PR4080/build2383/devicetest/index.html?model=TGLU_RVP_NOCODEC_IPC4ZPH&testcase=check-runtime-pm-status
Reproduction Rate
Reproduction is high but probably not deterministic, here's a recent run passing:
https://sof-ci.01.org/sofpr/PR6732/build2684/devicetest/index.html
Environment
- Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
2022-12-06 is the first daily run where I found it. It seems to occur in most daily IPC4 test runs after that
Daily IPC4 18618?model=TGLU_RVP_NOCODEC_CAVSIPC4&testcase=check-kmod-load-unload-after-playback-5
Kernel Branch: topic/sof-dev
Kernel Commit: c78e584e7704
SOF Branch: main
SOF Commit: 4a9a99aeb24a
Zephyr Commit: ffed8388e7cb
- Name of the platform(s) on which the bug is observed.
- Platform: TGL IPC4