Repository navigation
[BUG] DSP panic when initializing the DMA trace #4676
Description
Describe the bug
This is a firmware regression. This issue occurs when initializing the DMA trace after sof firmware reloaded.
IPC info: ipc tx: 0x90030000: GLB_TRACE_MSG
This is a common issue and happens on different platforms when triggering the firmware reloading process, like runtime PM test, kmod test and suspend/resume test.
To Reproduce
Run such cases: suspend-resume, kmod-load-unload, or runtime-pm-check.
eg. run 'TPLG=/lib/firmware/intel/sof-tplg/sof-adl-rt711-4ch.tplg ~/sof-test/test-case/check-runtime-pm-status.sh -l 15' on adlp-rvp-sdw
Reproduction Rate
100%
Environment
Kernel Branch: topic/sof-dev
Kernel Commit: eb558167
SOF Branch: main
SOF Commit: 7df3674
Platform: TGLH/ADLP/TGLU/ICL/CML/GLK
Screenshots or console output
[dmesg]
[ 5390.222509] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: firmware boot complete
[ 5390.222535] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Debug PCIR: 00000000 at 00000048
[ 5390.222541] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Debug PCIW: 00000002 at 00000048
[ 5390.222582] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Debug PCIR: 00000004 at 00000044
[ 5390.222587] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: Debug PCIW: 00000000 at 00000044
[ 5390.222607] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x40000 successful
[ 5390.222639] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x40000 successful
[ 5390.222644] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda_dsp_stream_setup_bdl: period_bytes:0x0
[ 5390.222647] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda_dsp_stream_setup_bdl: periods:1
[ 5390.222670] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: snd_sof_init_trace_ipc: stream_tag: 1
[ 5390.222680] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x90030000: GLB_TRACE_MSG
[ 5390.223046] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error : DSP panic!
[ 5390.223050] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: panic: dsp_oops_offset 788480 offset 788480
[ 5390.223053] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump start ]------------
[ 5390.223064] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: status: fw entered - code 00000005
[ 5390.223277] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: runtime exception
[ 5390.223279] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: trace point 00004000
[ 5390.223281] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: panic at :0
[ 5390.223284] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: DSP Firmware Oops
[ 5390.223286] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[ 5390.223288] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: EXCCAUSE 0x0000000d EXCVADDR 0x00000000 PS 0x00060725 SAR 0x00000000
[ 5390.223291] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: EPC1 0xbe031345 EPC2 0xbe053596 EPC3 0x00000000 EPC4 0x00000000
[ 5390.223293] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: EPC5 0x00000000 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 5390.223295] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: EPS2 0x00060f20 EPS3 0x00000000 EPS4 0x00000000 EPS5 0x00000000
[ 5390.223297] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x00000000 INTERRU 0x00000222
[ 5390.223299] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: stack dump from 0xbe07feb0
[ 5390.223302] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07feb0: 00000000 00000000 00000000 00000000
[ 5390.223305] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07feb4: 7e031345 be07ff30 00000020 000003e8
[ 5390.223307] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07feb8: 4e351800 55a6dc8e 70d09028 ffff9e91
[ 5390.223309] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07febc: 000c0800 00000000 70d09028 ffff9e91
[ 5390.223312] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07fec0: 70d09028 ffff9e91 00000091 00000000
[ 5390.223314] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07fec4: 9d0cfe28 ffffffff 70e4a200 ffff9e91
[ 5390.223316] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07fec8: 9d0cff20 ffffffff 4e351800 55a6dc8e
[ 5390.223318] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: 0xbe07fecc: 9d08d851 ffffffff 4d85f480 ffff9e91
[ 5390.223320] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump end ]------------
[ 5390.726844] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x90030000 (msg/reply size: 80/12)
[ 5390.726851] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: preventing DSP entering D3 state to preserve context
[ 5390.726854] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump start ]------------
[ 5390.726872] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0xc0000000 rirb 00
[ 5390.726875] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 5390.726885] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 5390.726887] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump end ]------------
[ 5390.726890] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: can't set params for DMA for trace -110
[ 5390.726911] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: warning: failed to init trace after resume -110
[ 5390.726921] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 5391.230860] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x30100000 (msg/reply size: 48/20)
[ 5391.230869] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to load widget PIPELINE.8.HDA2.OUT
[ 5391.230872] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed to restore pipeline after resume -110
Activity
[-][BUG] DSP panic when the FW reload or initialize the trace on the TGLH/ADLP/TGLU/ICL/CML/GLK[/-][+][BUG] DSP panic when initializing the DMA trace[/+]keyonjie commentedon Aug 25, 2021
Thanks for reporting, looks there is deference to NULL pointer issue in the DMA trace part.
keyonjie commentedon Aug 25, 2021
@1994lwz can you please help to check if the PR #4678 help?
plbossart commentedon Aug 25, 2021
This was detected in Intel daily test #6047
This can be root-caused to #4636
The question is: how come this wasn't found in CI tests? there's a post-mortem analysis needed on such a regression.
lgirdwood commentedon Aug 25, 2021
Not sure why CI missed this as it tests the trace on all platforms (jenkins and Internal), the reload part is also tested on the PM tests. @keyonjie are we good to close ?
1994lwz commentedon Aug 26, 2021
The bug is not reproduce on the daily #6090, and verify it by test the suspend-resume 200 times, runtime-pm-status 100 times, kmod-load-unload 100 times on the ADLP/TGLU/CML/ICL/TGLH.
This bug is fixed by the PR #4678 and #4636 so close it.
marc-hb commentedon Sep 13, 2021
I spent some time looking at the test results of daily run 6047 and the reason this escaped PR testing is because even in the longer daily run 6047 this particular crash is relatively rare (there is a number of other, unrelated failures in that run). Only a few platforms have experienced it, not on every test and even when it happens it's not immediately but only after a fair number of test iterations. Confirmed by comment #4678 (comment)
Revert "trace: enable trace after it is ready"
Revert "trace: enable trace after it is ready"
Revert "trace: enable trace after it is ready"