[BUG][GLK]"DSP panic" when do module load/unload test

[Liviali155]

Describe the bug
"DSP panic" when do module load/unload test,Seems only a error message,has no imapct on function
After error occured,all the pipeline can work normally

To Reproduce
1.sudo reboot
2. cd sof-test
3.cd test-case
4.export TPLG=/lib/firmware/intel/sof-glk-da7219.tplg
5../check-kmod-load-unload.sh(https://github.com/thesofproject/sof-test/blob/master/test-case/check-kmod-load-unload.sh)

Reproduction Rate
10/10

Expected behavior
There is no DSP panic when do module load/unload

Impact
"DSP panic" showed in kernel log

Environment
* Kernel: {a272777} /sof/dev
* SOF: {9b1b615} master
2) Name of the topology file
* Topology: {sof-glk-da7219.tplg}
3) Name of the platform(s) on which the bug is observed.
* Platform: {GLK Chrome with onboard codec DA7219 in I2S mode}

dmesg_error.log

[   92.559577] sof-audio-pci 0000:00:0e.0: periods:1
[   92.560193] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3030303 successful
[   92.560221] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3030302 successful
[   92.560223] sof-audio-pci 0000:00:0e.0: unstall/run core: core_mask = 1
[   92.560226] sof-audio-pci 0000:00:0e.0: DSP core(s) enabled? 1 : core_mask 1
[   92.562330] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x40000000 successful
[   92.562347] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3010202 successful
[   92.591822] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5000001 successful
[   92.608163] sof-audio-pci 0000:00:0e.0: error : DSP panic!
[   92.608170] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
[   92.608172] sof-audio-pci 0000:00:0e.0: error: status = 0x0dead000 panic = 0x00000220
[   92.608192] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
[   92.608815] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5 successful
[   92.609313] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x140000 successful
[   92.609316] sof-audio-pci 0000:00:0e.0: Firmware download successful, booting...
[   92.612338] sof-audio-pci 0000:00:0e.0: ipc rx: 0x70000000: FW_READY
[   92.612341] sof-audio-pci 0000:00:0e.0: ipc: DSP is ready 0x70000000 offset 0x81000
[   92.612358] sof-audio-pci 0000:00:0e.0: Firmware info: version 1:4:1-9b1b6
[   92.612360] sof-audio-pci 0000:00:0e.0: Firmware: ABI 3:14:0 Kernel ABI 3:13:0
[   92.612361] sof-audio-pci 0000:00:0e.0: warn: FW ABI is more recent than kernel
[   92.612362] sof-audio-pci 0000:00:0e.0: Firmware debug build 1 on Mar 27 2020-05:17:14 - options:
                GDB: disabled
                lock debug: disabled
                lock vdebug: disabled
[   92.612390] sof-audio-pci 0000:00:0e.0: found ext header type 1 size 0xb8
[   92.612403] sof-audio-pci 0000:00:0e.0: found ext header type 2 size 0x50
[   92.612405] sof-audio-pci 0000:00:0e.0: Firmware info: used compiler XCC 12:0:8 RG-2017.8-linux� used optimization flags O2
[   92.612420] sof-audio-pci 0000:00:0e.0: found ext header type 3 size 0x1c
[   92.612422] sof-audio-pci 0000:00:0e.0: warning: unknown ext header type 3 size 0x1c
[   92.612426] sof-audio-pci 0000:00:0e.0: found ext header type 4 size 0x10
[   92.612427] sof-audio-pci 0000:00:0e.0: warning: unknown ext header type 4 size 0x10
[   92.612457] sof-audio-pci 0000:00:0e.0:  mailbox upstream 0x81000 - size 0x1000
[   92.612459] sof-audio-pci 0000:00:0e.0:  mailbox downstream 0xa0000 - size 0x2000
[   92.612460] sof-audio-pci 0000:00:0e.0:  stream region 0xc1000 - size 0x1000
[   92.612464] sof-audio-pci 0000:00:0e.0: ipc rx done: 0x70000000: FW_READY
[   92.612469] sof-audio-pci 0000:00:0e.0: firmware boot complete
[   92.612475] sof-audio-pci 0000:00:0e.0: Debug PCIR: 00000000 at  00000048

No sof_errortrace
sof_trace0317.log

dmesg0327.log

[Liviali155]

Changed the Firmware to 20191201(feb9e2b) also has this problem

[Liviali155]

On below platforms has no this issue
CML Chrome with onboard codec RT5682 and RT1011 in I2S mode
TGL-U RVP with onboard codec ALC711 in HDA mode
CML laptop with onboard codec ALC3204 in HDA mode

[lgirdwood]

I see this twice in the logs before the FW boots. Could this be left over from a previous FW crash or @lbetlej is it a ROM error ?

[xiulipan]

@lgirdwood the pattern is quite wired, I think there is a DSP panic happen before the FW load success. log from a PR CI test: https://sof-ci.01.org/sofpr/PR2680/build5647/devicetest/GLK_BOB_DA7219/check-kmod-load-unload/dmesg.txt

0x0dead000 => SOF_IPC_PANIC_MEM

sh-glk-bob-da7219-01 kernel: [  612.917441] sof-audio-pci 0000:00:0e.0: Debug PCIR: 00000002 at  00000048
sh-glk-bob-da7219-01 kernel: [  612.917456] sof-audio-pci 0000:00:0e.0: Debug PCIW: 00000000 at  00000048
sh-glk-bob-da7219-01 kernel: [  612.917460] sof-audio-pci 0000:00:0e.0: Debug PCIR: 00000000 at  00000044
sh-glk-bob-da7219-01 kernel: [  612.917463] sof-audio-pci 0000:00:0e.0: Debug PCIW: 00000004 at  00000044
sh-glk-bob-da7219-01 kernel: [  612.917464] sof-audio-pci 0000:00:0e.0: booting DSP firmware
sh-glk-bob-da7219-01 kernel: [  612.917530] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x40000 successful
sh-glk-bob-da7219-01 kernel: [  612.917544] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x40000 successful
sh-glk-bob-da7219-01 kernel: [  612.917548] sof-audio-pci 0000:00:0e.0: period_bytes:0x0
sh-glk-bob-da7219-01 kernel: [  612.917549] sof-audio-pci 0000:00:0e.0: periods:1
sh-glk-bob-da7219-01 kernel: [  612.918139] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3030303 successful
sh-glk-bob-da7219-01 kernel: [  612.918191] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3030302 successful
sh-glk-bob-da7219-01 kernel: [  612.918194] sof-audio-pci 0000:00:0e.0: unstall/run core: core_mask = 1
sh-glk-bob-da7219-01 kernel: [  612.918210] sof-audio-pci 0000:00:0e.0: DSP core(s) enabled? 1 : core_mask 1
sh-glk-bob-da7219-01 kernel: [  612.920168] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x40000000 successful
sh-glk-bob-da7219-01 kernel: [  612.920172] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3010202 successful
sh-glk-bob-da7219-01 kernel: [  612.951182] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5000001 successful
sh-glk-bob-da7219-01 kernel: [  612.967873] sof-audio-pci 0000:00:0e.0: error : DSP panic!
sh-glk-bob-da7219-01 kernel: [  612.967881] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
sh-glk-bob-da7219-01 kernel: [  612.967884] sof-audio-pci 0000:00:0e.0: error: status = 0x0dead000 panic = 0x00000220
sh-glk-bob-da7219-01 kernel: [  612.967886] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
sh-glk-bob-da7219-01 kernel: [  612.968155] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5 successful
sh-glk-bob-da7219-01 kernel: [  612.968158] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x140000 successful
sh-glk-bob-da7219-01 kernel: [  612.968160] sof-audio-pci 0000:00:0e.0: Firmware download successful, booting...
sh-glk-bob-da7219-01 kernel: [  612.971951] sof-audio-pci 0000:00:0e.0: ipc rx: 0x70000000: FW_READY
sh-glk-bob-da7219-01 kernel: [  612.971954] sof-audio-pci 0000:00:0e.0: ipc: DSP is ready 0x70000000 offset 0x81000
sh-glk-bob-da7219-01 kernel: [  612.971983] sof-audio-pci 0000:00:0e.0: Firmware info: version 1:4:1-90a74
sh-glk-bob-da7219-01 kernel: [  612.971985] sof-audio-pci 0000:00:0e.0: Firmware: ABI 3:16:0 Kernel ABI 3:15:0
sh-glk-bob-da7219-01 kernel: [  612.971986] sof-audio-pci 0000:00:0e.0: warn: FW ABI is more recent than kernel
sh-glk-bob-da7219-01 kernel: [  612.971988] sof-audio-pci 0000:00:0e.0: Firmware debug build 1 on Apr  1 2020-14:57:14 - options:

[wenqingfu]

from CI results in a timeline, this is a regression started happening in the last two days.

[lgirdwood]

@xiulipan panic does a while(1) so should not get any further.
@Liviali155 can you bisect given it's only started to happen in last 2 days.

[Liviali155]

@xiulipan panic does a while(1) so should not get any further.
@Liviali155 can you bisect given it's only started to happen in last 2 days.

I check the test result of CI,it should not be a regression,the result of 20200320 has DSP panic too,because the issue thesofproject/sof-test#154, the error was not found

Inserting snd_sof_acpi
Inserting snd_sof_pci
Inserting snd_usb_audio
2020-03-19 21:40:51 UTC [REMOTE_INFO] checking for general errors after kmod insert with sof-kernel-log-check tool
Caught error: Mar 20 05:40:50 sh-glk-bob-da7219-03 kernel: [  682.562298] sof-audio-pci 0000:00:0e.0: hda_sdw_acpi_scan failed
Mar 20 05:40:50 sh-glk-bob-da7219-03 kernel: [  682.562302] sof-audio-pci 0000:00:0e.0: skipping SoundWire, ACPI scan error
Mar 20 05:40:50 sh-glk-bob-da7219-03 kernel: [  682.615243] sof-audio-pci 0000:00:0e.0: error : DSP panic!
kernel log has error(s)
2020-03-19 21:40:51 UTC [REMOTE_INFO] checking for fw_boot success
2020-03-19 21:40:51 UTC [REMOTE_INFO] ==== completed boot firmware: 2 of 2 ====
2020-03-19 21:40:52 UTC [REMOTE_INFO] Test Result: PASS!

dmesg_error.log

kernel: [  678.717400] sof-audio-pci 0000:00:0e.0: DSP core(s) enabled? 1 : core_mask 1
kernel: [  678.719687] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x40000000 successful
kernel: [  678.719704] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x3010202 successful
kernel: [  678.725638] usbcore: registered new interface driver snd-usb-audio
kernel: [  678.748028] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5000001 successful
kernel: [  678.764479] sof-audio-pci 0000:00:0e.0: error : DSP panic!
kernel: [  678.764485] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
kernel: [  678.764488] sof-audio-pci 0000:00:0e.0: error: status = 0x0dead000 panic = 0x00000220
kernel: [  678.764490] sof-audio-pci 0000:00:0e.0: unknown ROM status value 00000000
kernel: [  678.765015] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x5 successful
kernel: [  678.765018] sof-audio-pci 0000:00:0e.0: FW Poll Status: reg=0x140000 successful
kernel: [  678.765021] sof-audio-pci 0000:00:0e.0: Firmware download successful, booting...
kernel: [  678.768487] sof-audio-pci 0000:00:0e.0: ipc rx: 0x70000000: FW_READY
kernel: [  678.768489] sof-audio-pci 0000:00:0e.0: ipc: DSP is ready 0x70000000 offset 0x81000
kernel: [  678.768506] sof-audio-pci 0000:00:0e.0: Firmware info: version 1:4:1-c6398
kernel: [  678.768508] sof-audio-pci 0000:00:0e.0: Firmware: ABI 3:14:0 Kernel ABI 3:13:0
kernel: [  678.768509] sof-audio-pci 0000:00:0e.0: warn: FW ABI is more recent than kernel
kernel: [  678.768511] sof-audio-pci 0000:00:0e.0: Firmware debug build 1 on Mar 20 2020-05:16:27 - options:
kernel: [  678.768511]  GDB: disabled
kernel: [  678.768511]  lock debug: disabled
kernel: [  678.768511]  lock vdebug: disabled
kernel: [  678.768538] sof-audio-pci 0000:00:0e.0: found ext header type 1 size 0xb8
kernel: [  678.768553] sof-audio-pci 0000:00:0e.0: found ext header type 2 size 0x50
kernel: [  678.768555] sof-audio-pci 0000:00:0e.0: Firmware info: used compiler XCC 12:0:8 RG-2017.8-linux  used optimization flags O2
kernel: [  678.768569] sof-audio-pci 0000:00:0e.0: found ext header type 3 size 0x1c
kernel: [  678.768571] sof-audio-pci 0000:00:0e.0: warning: unknown ext header type 3 size 0x1c
kernel: [  678.768574] sof-audio-pci 0000:00:0e.0: found ext header type 4 size 0x10.

check-kmod-load-unload.sh.txt
cmd.txt
dmesg.txt

[Liviali155]

Tried with PR #1992 ,issue still can be reproduced

[lgirdwood]

@Liviali155 can you update which PR you tested, above PR is a bug.
Please also put a space between "PR" and "#nnnn" as GH will then automatically insert a link for you.

[Liviali155]

@Liviali155 can you update which PR you tested, above PR is a bug.
Please also put a space between "PR" and "#nnnn" as GH will then automatically insert a link for you.

OK,this PR thesofproject/linux#1992