[Bug][WHL-i2s]System freeze after module unload/reload

Describe the bug
System freeze after reload module.

To Reproduce
1.sudo ./sof_remove.sh
2. sudo ./sof_insert.sh

Actual result
System freeze.

linux (topic/sof-dev): 8b8f437
sof (master): f837e57
tplg: sof-whl-rt5682.tplg
Platform: WHL RVP with ALC5682 connected via I2S

Dmesg:

[   41.783905] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.783916] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[   41.786975] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.786986] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.787284] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.787322] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.787518] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   41.787526] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[   41.787608] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[   42.284080] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[   42.284119] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[   42.284946] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[   42.285201] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[   42.285215] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[   42.285222] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285246] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285258] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285265] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285286] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285298] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285304] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285325] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285337] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285343] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285365] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285377] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285383] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285398] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285410] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285416] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.285433] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285445] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.285451] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   42.320187] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.320193] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   42.320197] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[   42.320273] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power off
[   42.539699] BUG: unable to handle page fault for address: ffffffffc05b9060
[   42.546587] #PF: supervisor instruction fetch in kernel mode
[   42.552254] #PF: error_code(0x0010) - not-present page
[   42.557394] PGD 1dc00c067 P4D 1dc00c067 PUD 1dc00e067 PMD 455318067 PTE 0
[   42.564192] Oops: 0010 [#1] SMP NOPTI
[   42.567856] CPU: 3 PID: 172 Comm: kworker/3:3 Not tainted 5.3.0-rc1-daily-20190805 #1
[   42.575679] Hardware name: Intel Corporation WhiskeyLake Client Platform/WhiskeyLake U DDR4 ERB, BIOS CNLSFWR1.R00.X181.B00.1812130202 12/13/2018
[   42.588708] Workqueue: events_power_efficient 0xffffffffc05b9060
[   42.594712] RIP: 0010:0xffffffffc05b9060
[   42.598636] Code: Bad RIP value.
[   42.601862] RSP: 0000:ffffa27380417e98 EFLAGS: 00010282
[   42.607082] RAX: ffffffffc05b9060 RBX: ffff936b584e4c98 RCX: ffff936b5bba8260
[   42.614214] RDX: ffff936b5bba8260 RSI: 00000000000000c0 RDI: ffff936b584e4c98
[   42.621341] RBP: ffff936b5bba8240 R08: 0000746e65696369 R09: 8080808080808080
[   42.628466] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff936b5bbac500
[   42.635594] R13: 0000000000000000 R14: ffff936b55c6bd80 R15: 0ffff936b5bbac50
[   42.642724] FS:  0000000000000000(0000) GS:ffff936b5bb80000(0000) knlGS:0000000000000000
[   42.650807] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   42.656547] CR2: ffffffffc05b9036 CR3: 0000000437430005 CR4: 00000000003606e0
[   42.663673] Call Trace:
[   42.666121]  ? process_one_work+0x1e3/0x3d0
[   42.670301]  ? worker_thread+0x28/0x3c0
[   42.674132]  ? cancel_delayed_work+0x80/0x80
[   42.678399]  ? kthread+0x10e/0x130
[   42.681803]  ? kthread_park+0xa0/0xa0
[   42.685462]  ? ret_from_fork+0x35/0x40
[   42.689210] Modules linked in: snd_hda_core snd_soc_core snd_pcm x86_pkg_temp_thermal intel_powerclamp snd_seq_midi snd_seq_midi_event ax88179_178a usbnet snd_rawmidi snd_seq mei_me mei intel_lpss_pci intel_lpss mfd_core snd_seq_device snd_timer intel_pch_thermal processor_thermal_device int340x_thermal_zone intel_soc_dts_iosf snd soundcore efivarfs i915 sdhci_pci cqhci i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops xhci_pci sdhci drm xhci_hcd [last unloaded: snd_hda_ext_core]
[   42.733710] CR2: ffffffffc05b9060
[   42.737023] ---[ end trace 4ec79628994ba8a1 ]---
[   42.741638] RIP: 0010:0xffffffffc05b9060
[   42.745557] Code: Bad RIP value.
[   42.748783] RSP: 0000:ffffa27380417e98 EFLAGS: 00010282
[   42.754003] RAX: ffffffffc05b9060 RBX: ffff936b584e4c98 RCX: ffff936b5bba8260
[   42.761133] RDX: ffff936b5bba8260 RSI: 00000000000000c0 RDI: ffff936b584e4c98
[   42.768258] RBP: ffff936b5bba8240 R08: 0000746e65696369 R09: 8080808080808080
[   42.775384] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff936b5bbac500
[   42.782514] R13: 0000000000000000 R14: ffff936b55c6bd80 R15: 0ffff936b5bbac50
[   42.789641] FS:  0000000000000000(0000) GS:ffff936b5bb80000(0000) knlGS:0000000000000000
[   42.797724] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   42.803471] CR2: ffffffffc05b9036 CR3: 0000000437430005 CR4: 00000000003606e0

dmesg_reload_freez.txt

Behavior is changed on latest build. "No sound card" is after reload modules.

linux (topic/sof-dev): 53d7754
sof (master): 9e2aa3d

nosoundcard.txt

Scripts:
sof_insert.txt
sof_remove.txt

[   81.163950] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[   81.163952] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   81.163984] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[   81.164188] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[   81.164202] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[   81.164302] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[   81.164912] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[   81.165125] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[   81.165138] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[   81.165146] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165170] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165182] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165189] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165211] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165224] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165230] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165253] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165265] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165271] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165294] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165307] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165313] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165329] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165341] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165347] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.165370] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165383] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.165389] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[   81.234934] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.234941] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[   81.234944] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[   81.235054] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power off
[   81.420586] BUG: unable to handle page fault for address: ffffffffc0535060
[   81.427437] #PF: supervisor instruction fetch in kernel mode
[   81.433068] #PF: error_code(0x0010) - not-present page
[   81.438182] PGD 23900c067 P4D 23900c067 PUD 23900e067 PMD 4553c7067 PTE 0
[   81.444938] Oops: 0010 [#1] SMP NOPTI
[   81.448587] CPU: 0 PID: 115 Comm: kworker/0:2 Not tainted 5.3.0-rc1-daily-20190807 #53d77540
[   81.456980] Hardware name: Intel Corporation WhiskeyLake Client Platform/WhiskeyLake U DDR4 ERB, BIOS CNLSFWR1.R00.X181.B00.1812130202 12/13/2018
[   81.469955] Workqueue: events_power_efficient 0xffffffffc0535060
[   81.475929] RIP: 0010:0xffffffffc0535060
[   81.479835] Code: Bad RIP value.
[   81.483047] RSP: 0018:ffffa39940357e98 EFLAGS: 00010282
[   81.488248] RAX: ffffffffc0535060 RBX: ffff9f3154c68298 RCX: ffff9f315ba28260
[   81.495343] RDX: ffff9f315ba28260 RSI: 0000000000000000 RDI: ffff9f3154c68298
[   81.502443] RBP: ffff9f315ba28240 R08: 0000746e65696369 R09: 8080808080808080
[   81.509557] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff9f315ba2c500
[   81.516654] R13: 0000000000000000 R14: ffff9f31565c1900 R15: 0ffff9f315ba2c50
[   81.523752] FS:  0000000000000000(0000) GS:ffff9f315ba00000(0000) knlGS:0000000000000000
[   81.531798] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   81.537533] CR2: ffffffffc0535036 CR3: 0000000437888002 CR4: 00000000003606f0
[   81.544645] Call Trace:
[   81.547085]  ? process_one_work+0x1e3/0x3d0
[   81.551251]  ? worker_thread+0x28/0x3c0
[   81.555067]  ? cancel_delayed_work+0x80/0x80
[   81.559320]  ? kthread+0x10e/0x130
[   81.562705]  ? kthread_park+0xa0/0xa0
[   81.566352]  ? ret_from_fork+0x35/0x40
[   81.570086] Modules linked in: snd_seq_midi snd_seq_midi_event snd_hda_core snd_rawmidi snd_soc_core x86_pkg_temp_thermal ax88179_178a snd_seq intel_powerclamp usbnet snd_pcm snd_seq_device snd_timer snd mei_me mei intel_lpss_pci intel_lpss mfd_core soundcore processor_thermal_device int340x_thermal_zone intel_soc_dts_iosf intel_pch_thermal efivarfs i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm xhci_pci sdhci_pci cqhci xhci_hcd sdhci [last unloaded: snd_hda_ext_core]
[   81.614410] CR2: ffffffffc0535060
[   81.617712] ---[ end trace f5465a770677c152 ]---
[   81.622307] RIP: 0010:0xffffffffc0535060
[   81.626212] Code: Bad RIP value.
[   81.629427] RSP: 0018:ffffa39940357e98 EFLAGS: 00010282
[   81.634627] RAX: ffffffffc0535060 RBX: ffff9f3154c68298 RCX: ffff9f315ba28260
[   81.641725] RDX: ffff9f315ba28260 RSI: 0000000000000000 RDI: ffff9f3154c68298
[   81.648825] RBP: ffff9f315ba28240 R08: 0000746e65696369 R09: 8080808080808080
[   81.655924] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff9f315ba2c500
[   81.663024] R13: 0000000000000000 R14: ffff9f31565c1900 R15: 0ffff9f315ba2c50
[   81.670121] FS:  0000000000000000(0000) GS:ffff9f315ba00000(0000) knlGS:0000000000000000
[   81.678168] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   81.683887] CR2: ffffffffc0535036 CR3: 0000000437888002 CR4: 00000000003606f0
[   94.761538] sof-audio-pci 0000:00:1f.3: PCI DSP detected

Still "No sound card" after reload
linux (topic/sof-dev):4730d842
sof (master): c6f1b08

yes this is probably because in remove we get kernel oops. insert after that will hang.
I get this log in mb-byt+rt5682:
[ 76.455294] Workqueue: events_power_efficient rt5682_jack_detect_handler [snd_soc_rt5682]
[ 76.455303] RIP: 0010:rt5682_jack_detect_handler+0x4e/0x290 [snd_soc_rt5682]

so something fishy with jack detection functions in both rt5651 and rt5682 when removing/inserting modules

@bardliao

@bardliao

commenting out the following snipped in rt5682 jack_detect_handler will make the kernel not to oops in remove modules....
/*
while (!rt5682->component)
usleep_range(10000, 15000);

    while (!rt5682->component->card->instantiated)                                                                                                                      
            usleep_range(10000, 15000);                                                                                                                                 
    */

I don't know what's the purpose of these lines and why the handler is even driven when removing modules. Anyway it helps. I tried also to cancel the handlers deferred work in "remove" (as done in hda driver by Keyon), but it didn't have any effect. Maybe the cancelling should still be done for sanity reasons.

@bardliao

rt5682->component->card

@bardliao

commenting out the following snipped in rt5682 jack_detect_handler will make the kernel not to oops in remove modules....
/*
while (!rt5682->component)
usleep_range(10000, 15000);
    while (!rt5682->component->card->instantiated)                                                                                                                      
            usleep_range(10000, 15000);                                                                                                                                 
    */
I don't know what's the purpose of these lines and why the handler is even driven when removing modules. Anyway it helps. I tried also to cancel the handlers deferred work in "remove" (as done in hda driver by Keyon), but it didn't have any effect. Maybe the cancelling should still be done for sanity reasons.

Hi @juimonen so looks rt5682->component->card here is NULL?

Can you try if this change can fix the issue?

--	while (!rt5682->component->card->instantiated)
++      while (!rt5682->component->card ||
++             !rt5682->component->card->instantiated)
		usleep_range(10000, 15000);

@Keyon

@Keyon unfortunately doesn't help.... So removing the while loop helps. I guess the delay causes the underlying card to have time to be removed, but the pointers are not checked after the while loop. I don't understand why the jack_detecthandler is even run on remove? from irq or something? Anyway we should be able to disable the handler in time, or nullify pointers and check them every time.

@keyonjie

@keyonjie @juimonen Could you implement a jack = null case in rt5682_set_jack_detect() to disable jack detection, and call snd_soc_component_set_jack(component, NULL, NULL); in sof_rt5682 remove ops (not implement yet)?
For implementing jack = null case, you can refer to
https://github.com/thesofproject/linux/blob/topic/sof-dev/sound/soc/codecs/rt274.c#L400

#1147

Test on whl I2s RVP. Issue is fixed after applying PR #1147. Passed for 200 times Module reload test.

Close for fixed by PR #1147, pass after test 300 interactions..

Navigation Menu

Repository navigation

[Bug][WHL-i2s]System freeze after module unload/reload #1110

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

[Bug][WHL-i2s]System freeze after module unload/reload #1110

Description

Activity

ClarexZhou commented on Aug 7, 2019

ClarexZhou commented on Aug 12, 2019

juimonen commented on Aug 16, 2019

juimonen commented on Aug 16, 2019

keyonjie commented on Aug 19, 2019

juimonen commented on Aug 19, 2019

bardliao commented on Aug 20, 2019

juimonen commented on Aug 21, 2019

ClarexZhou commented on Aug 22, 2019

ClarexZhou commented on Aug 28, 2019

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions