Repository navigation
oops on FW boot timeout in pm_runtime_work() / sof_suspend() #372
Description
Kernel is oopsing on multiple platforms if FW boot timeouts.
[ 6.233014] sof-audio sof-audio: error: firmware boot timeout
[ 6.233030] sof-audio sof-audio: status: fw entered - code 00000005
[ 6.233036] sof-audio sof-audio: error: status = 0x00000000 panic = 0x00004000
[ 6.233042] sof-audio sof-audio: status: fw entered - code 00000005
[ 6.233046] sof-audio sof-audio: error: failed to boot DSP firmware -5
[ 6.268609] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 3
[ 6.268815] sof-audio: probe of sof-audio failed with error -5
[ 6.271422] BUG: unable to handle kernel NULL pointer dereference at 0000000000000140
[ 6.271434] PGD 0 P4D 0
[ 6.271439] Oops: 0000 [#1] SMP NOPTI
[ 6.271444] CPU: 1 PID: 18 Comm: kworker/1:0 Not tainted 4.19.0+ #19
[ 6.271447] Hardware name: AAEON UP-APL01/UP-APL01, BIOS UPA1AM16 06/07/2017
[ 6.271456] Workqueue: pm pm_runtime_work
[ 6.271466] RIP: 0010:sof_suspend+0x25/0x180 [snd_sof]
[ 6.271470] Code: 80 00 00 00 00 0f 1f 44 00 00 41 56 41 55 41 54 55 53 48 83 ec 08 48 8b 87 98 00 00 00 48 8b 40 08 48 8b a8 a8 00 00 00 31 c0 <48> 8b 95 40 01 00 00 48 83 7a 48 00 0f 84 e9 00 00 00 48 89 ef 41
[ 6.271475] RSP: 0018:ffffac28403dbd50 EFLAGS: 00010246
[ 6.271479] RAX: 0000000000000000 RBX: ffff9465b15420a8 RCX: 0000000000000000
[ 6.271482] RDX: ffffffffc0718020 RSI: 0000000000000001 RDI: ffff9465b15420a8
[ 6.271485] RBP: 0000000000000000 R08: 20c49ba5e353f7cf R09: ffffac28403dbde8
[ 6.271488] R10: 8080808080808080 R11: ffff9465b591c212 R12: ffffffffc07174a0
[ 6.271491] R13: ffff9465b1542000 R14: 0000000000000000 R15: ffffffff936c58f0
[ 6.271495] FS: 0000000000000000(0000) GS:ffff9465b1880000(0000) knlGS:0000000000000000
[ 6.271499] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.271502] CR2: 0000000000000140 CR3: 000000003589a000 CR4: 00000000003406e0
[ 6.271505] Call Trace:
[ 6.271516] ? __switch_to_asm+0x34/0x70
[ 6.271524] pci_pm_runtime_suspend+0x64/0x180
[ 6.271529] __rpm_callback+0x79/0x1d0
[ 6.271533] ? pci_has_legacy_pm_support+0x60/0x60
[ 6.271537] rpm_callback+0x1f/0x70
[ 6.271540] ? pci_has_legacy_pm_support+0x60/0x60
[ 6.271543] rpm_suspend+0x138/0x670
[ 6.271547] pm_runtime_work+0x73/0x90
[ 6.271553] process_one_work+0x206/0x400
[ 6.271557] worker_thread+0x2d/0x3e0
[ 6.271561] ? pwq_unbound_release_workfn+0xc0/0xc0
[ 6.271565] kthread+0x112/0x130
[ 6.271569] ? kthread_bind+0x30/0x30
[ 6.271572] ret_from_fork+0x35/0x40
[ 6.271577] Modules linked in: spi_pxa2xx_platform(+) 8250_dw nls_iso8859_1 intel_rapl intel_telemetry_pltdrv intel_pmc_ipc intel_punit_ipc intel_telemetry_core x86_pkg_temp_thermal coretemp kvm_intel sof_pci_dev(+) snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_sof_intel_byt kvm snd_sof_nocodec snd_sof snd_sof_xtensa_dsp snd_hda_ext_core snd_soc_acpi_intel_match irqbypass snd_soc_acpi crct10dif_pclmul snd_hda_codec crc32_pclmul snd_hda_core ghash_clmulni_intel pcbc aesni_intel snd_hwdep aes_x86_64 crypto_simd cryptd glue_helper intel_cstate intel_rapl_perf snd_soc_core snd_compress snd_pcm_dmaengine ac97_bus snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi pwm_lpss_pci lpc_ich pwm_lpss snd_seq idma64 virt_dma intel_lpss_pci intel_lpss snd_seq_device snd_timer snd mei_me mei soundcore
[ 6.271641] sch_fq_codel ip_tables x_tables autofs4 mmc_block sdhci_pci cqhci i2c_i801 sdhci i915 r8169 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops video pinctrl_broxton pinctrl_intel ahci drm libahci
[ 6.271665] CR2: 0000000000000140
[ 6.271670] ---[ end trace 25bd50f5ccfac87a ]---
[ 6.271676] RIP: 0010:sof_suspend+0x25/0x180 [snd_sof]
[ 6.271680] Code: 80 00 00 00 00 0f 1f 44 00 00 41 56 41 55 41 54 55 53 48 83 ec 08 48 8b 87 98 00 00 00 48 8b 40 08 48 8b a8 a8 00 00 00 31 c0 <48> 8b 95 40 01 00 00 48 83 7a 48 00 0f 84 e9 00 00 00 48 89 ef 41
[ 6.271685] RSP: 0018:ffffac28403dbd50 EFLAGS: 00010246
[ 6.271688] RAX: 0000000000000000 RBX: ffff9465b15420a8 RCX: 0000000000000000
[ 6.271691] RDX: ffffffffc0718020 RSI: 0000000000000001 RDI: ffff9465b15420a8
[ 6.271694] RBP: 0000000000000000 R08: 20c49ba5e353f7cf R09: ffffac28403dbde8
[ 6.271697] R10: 8080808080808080 R11: ffff9465b591c212 R12: ffffffffc07174a0
[ 6.271700] R13: ffff9465b1542000 R14: 0000000000000000 R15: ffffffff936c58f0
[ 6.271704] FS: 0000000000000000(0000) GS:ffff9465b1880000(0000) knlGS:0000000000000000
[ 6.271707] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.271710] CR2: 0000000000000140 CR3: 000000003589a000 CR4: 00000000003406e0
Activity
plbossart commentedon Dec 5, 2018
lgirdwood commentedon Dec 5, 2018
Can be reproduced by ignoring interrupts from DSP.
plbossart commentedon Dec 5, 2018
Care to elaborate or share the test code you used?
lgirdwood commentedon Dec 6, 2018
My test code is FW change, but the driver can easily pretend to handle notifications in the irq thread without passing the notification up the stack.
lgirdwood commentedon Dec 6, 2018
#385 also fixes this, but needs validation by @ranj063
mengdonglin commentedon Dec 11, 2018
Will revisit this issue after #370 is fixed
mengdonglin commentedon Jan 14, 2019
@lgirdwood @ranj063 @keyonjie @plbossart Closing this issue since it should be fixed it with issue #370. Please reopen if you still observe this issue.
printk: Fail pr_flush() if before SYSTEM_SCHEDULING
btrfs: only release the dirty pages io tree after successful writes