kmod test hang on BSW_CYN_MAX98090

[keyonjie]

On BSW_CYN_MAX98090, running sof_insert.sh after sof_remove.sh scripts to test sof module unload/reload capability, it will hang the whole Linux system.

[keyonjie]

it looks sometimes we can't take the DSP out from stalled state at module reload, and then dsp boot fails.

[keyonjie]

I have tried ~100 kernel builds/tries, but still can't figure out fix for this, the CSR_PWAITMODE bit will have high possibility to be 1 which means we can't take the DSP out from stalled state after module unloaded/reloaded, this issue only happens on BSW but on BYT or CHT.

[keyonjie]

I also tried SST ATOM driver, which didn't support module unload/reload.

[keyonjie]

looks the PCI config register is inaccessable, I can't set the DSP to D3hot state.

[plbossart]

@keyonjie have you tried on other non-chrome CHT devices? I can't recall seeing those problems.

[keyonjie]

@plbossart no, the BSW_CYN_MAX98090 is the only BSW I have ever touched.

BTW, I have a fix for this issue now, basically I need to send IPC to FW to inform about this driver module removal, working on refining it.

[plbossart]

@plbossart no, the BSW_CYN_MAX98090 is the only BSW I have ever touched.

BTW, I have a fix for this issue now, basically I need to send IPC to FW to inform about this driver moduel removal, working on refining it.

if these tests work on MinnowBoard and other BYT devices, I am not sure why the extra IPC is needed.
For me the issues on Cyan where due to GPIO stuff.

[keyonjie]

@plbossart no, the BSW_CYN_MAX98090 is the only BSW I have ever touched.
BTW, I have a fix for this issue now, basically I need to send IPC to FW to inform about this driver moduel removal, working on refining it.

if these tests work on MinnowBoard and other BYT devices, I am not sure why the extra IPC is needed.

That's true, though I think the extra IPC sounds reasonable, but it does require many regression test efforts on all platforms as this is a core change.

For me the issues on Cyan where due to GPIO stuff.

Um, can you get some information about this? It is an old platform, might be difficult to get support or information about it.

[keyonjie]

Call for helps here, we might need to get more BSW-CYAN platforms and more developers can involve the debugging, as the issue is much more complicated than expected, basically, there are several kinds of issues behind it:

1. the system hang issue. This looks like a interrupt storm after the driver module is removed, I did several refines in byt/cht/bsw part in both FW and driver, which can fix the hang issue.
2. the CSR_PWAITMODE bit can't reset issue. either putting the whole system to S3 and return back, or sending IPC_CONTEXT_SAVE to FW, can fix this issue.
3. FW boot fail issue. the FW fails occasionally on BSW, with boot trace e.g. 0x3100, or 0x3200, we need more FW debug to root cause this.
4. Kernel oops in module removal. This happen sometimes, seeing errors like below, either with the commit from PR#1469 applied or Morimoto's commit reverted:

[  226.344251] INFO: trying to register non-static key.
[  226.344260] the code is fine but needs lockdep annotation.
[  226.344263] turning off the locking correctness validator.
[  226.344269] CPU: 0 PID: 5220 Comm: rmmod Not tainted 5.4.0-rc7+ #5
[  226.344272] Hardware name: GOOGLE Cyan/Cyan, BIOS MrChromebox-4.10 08/22/2019
[  226.344275] Call Trace:
[  226.344286]  dump_stack+0x71/0xa0
[  226.344294]  register_lock_class+0x549/0x550
[  226.344300]  __lock_acquire+0x71/0x1910
[  226.344307]  ? __mutex_lock+0xa0/0x970
[  226.344311]  lock_acquire+0x95/0x190
[  226.344317]  ? init_timer_key+0x110/0x110
[  226.344322]  del_timer_sync+0x2f/0x90
[  226.344326]  ? init_timer_key+0x110/0x110
[  226.344332]  flush_delayed_work+0x13/0x40
[  226.344355]  soc_pcm_private_free+0x17/0x20 [snd_soc_core]
[  226.344368]  snd_pcm_free+0x1a/0x50 [snd_pcm]
[  226.344379]  __snd_device_free+0x46/0x60 [snd]
[  226.344387]  snd_device_free_all+0x3a/0x70 [snd]
[  226.344395]  release_card_device+0x14/0x50 [snd]
[  226.344401]  device_release+0x23/0x80
[  226.344406]  kobject_put+0x84/0x1a0
[  226.344414]  snd_card_free+0x5b/0x90 [snd]
[  226.344430]  soc_cleanup_card_resources+0xbb/0x2c0 [snd_soc_core]
[  226.344445]  snd_soc_unbind_card+0x9f/0xe0 [snd_soc_core]
[  226.344459]  snd_soc_unregister_card+0x1f/0x60 [snd_soc_core]
[  226.344465]  release_nodes+0x1ad/0x200
[  226.344471]  device_release_driver_internal+0xef/0x1c0
[  226.344475]  bus_remove_device+0xed/0x160
[  226.344479]  device_del+0x15e/0x370
[  226.344484]  platform_device_del.part.0+0xe/0x60
[  226.344488]  platform_device_unregister+0x17/0x30
[  226.344499]  snd_sof_device_remove+0x4c/0xa0 [snd_sof]
[  226.344505]  sof_acpi_remove+0x2f/0x40 [snd_sof_acpi]
[  226.344509]  platform_drv_remove+0x1f/0x40
[  226.344514]  device_release_driver_internal+0xdf/0x1c0
[  226.344518]  driver_detach+0x42/0x80
[  226.344522]  bus_remove_driver+0x56/0xca
[  226.344527]  __x64_sys_delete_module+0x18f/0x240
[  226.344533]  ? trace_hardirqs_off_thunk+0x1a/0x20
[  226.344537]  do_syscall_64+0x4b/0x1b0
[  226.344541]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  226.344546] RIP: 0033:0x7f986e3c01b7
[  226.344551] Code: 73 01 c3 48 8b 0d d1 8c 2c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 b0 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 8c 2c 00 f7 d8 64 89 01 48
[  226.344554] RSP: 002b:00007ffde9e5a6e8 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[  226.344560] RAX: ffffffffffffffda RBX: 00007ffde9e5a748 RCX: 00007f986e3c01b7
[  226.344562] RDX: 000000000000000a RSI: 0000000000000800 RDI: 00005628ea7ec7d8
[  226.344565] RBP: 00005628ea7ec770 R08: 00007ffde9e59661 R09: 0000000000000000
[  226.344568] R10: 00007f986e43ccc0 R11: 0000000000000206 R12: 00007ffde9e5a910
[  226.344571] R13: 00007ffde9e5b620 R14: 00005628ea7ec260 R15: 00005628ea7ec770

[ranj063]

@keyonjie can you post your patches so far so we can help?

[keyonjie]

@keyonjie can you post your patches so far so we can help?

Sure, doing that this morning.

[keyonjie]

@ranj063 @wenqingfu with my PR #1489 #1490 and #1491 applied, the hang issue(the "1" issue I mentioned above) is fixed.

For the "2" issue, we need add IPC_CTX_SAVE sending at driver removal.

For "3", need debugging from FW side to see what error happened there.

For "4", need to get a good base from Pierre and Morimoto, and debugging in the driver side.

[ranj063]

For the "2" issue, we need add IPC_CTX_SAVE sending at driver removal.
@keyonjie what is it that this IPC does that allows the CSR_PWAITMODE reset? Seding the CTX_SAVE IPC during device removal is the opposite of what we do normally which is disable PM and bring the device back to full-power

[keyonjie]

For the "2" issue, we need add IPC_CTX_SAVE sending at driver removal.
@keyonjie what is it that this IPC does that allows the CSR_PWAITMODE reset? Seding the CTX_SAVE IPC during device removal is the opposite of what we do normally which is disable PM and bring the device back to full-power

We will keep the CTX_RESTORE and bring the device back to full-power, here what i mentioned has no relationship with the PM ops, it is in the module removal, e.g. snd_sof_device_remove().

But what you mentioned inspires me about why the issue happens randomly, so my guess is that if we remove the module when the device is in runtime-suspended (which means CTX_SAVE already sent to FW), we will get the CSR_PWAITMODE reset correctly, but if we remove the module when the device is in runtime-active, then we will hit this "2" issue -- CSR_PWAITMODE can't be reset to 0.