| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20250313193057.GA7784@willie-the-truck>
Date: Thu, 13 Mar 2025 19:30:58 +0000
From: Will Deacon <will@...nel.org>
To: Tejun Heo <tj@...nel.org>
Cc: syzbot <syzbot+e13e654d315d4da1277c@...kaller.appspotmail.com>,
catalin.marinas@....com, linux-arm-kernel@...ts.infradead.org,
linux-kernel@...r.kernel.org, syzkaller-bugs@...glegroups.com,
maz@...nel.org, mark.rutland@....com, richard.xnu.clark@...il.com,
jiangshanlai@...il.com, marcel@...tmann.org,
johan.hedberg@...il.com, luiz.dentz@...il.com,
linux-bluetooth@...r.kernel.org
Subject: Re: [syzbot] [arm?] WARNING in delayed_work_timer_fn
On Fri, Feb 14, 2025 at 04:45:57PM +0000, Will Deacon wrote:
> On Tue, Feb 11, 2025 at 10:59:30AM -1000, Tejun Heo wrote:
> > On Tue, Feb 11, 2025 at 11:10:46AM +0000, Will Deacon wrote:
> > > Given that this seems to explode a few times a month, I wonder if it's
> > > worth adding some instrumentation to e.g. dump the name of the workqueue?
> >
> > It's usually most useful to print out the work function when identifying the
> > culprit. I'd be happy to take the patch.
>
> Thanks, Tejun. I sent a patch adding some more diagnostics:
>
> https://lore.kernel.org/r/20250214164349.13694-1-will@kernel.org
Ok, we have our first crash [1] with the new debug information:
[ 77.133818][ T10] Bluetooth: hci3: Opcode 0x0c1a failed: -110
[ 77.135329][ T10] Bluetooth: hci3: Error when powering off device on rfkill (-110)
[ 77.143656][ C1] ------------[ cut here ]------------
[ 77.145336][ C1] workqueue: cannot queue hci_cmd_timeout on wq hci3
[ 77.147101][ C1] WARNING: CPU: 1 PID: 7433 at kernel/workqueue.c:2258 __queue_work+0xe94/0x1324
[ 77.149301][ C1] Modules linked in:
[ 77.150287][ C1] CPU: 1 UID: 0 PID: 7433 Comm: syz.2.193 Not tainted 6.14.0-rc5-syzkaller-g77c95b8c7a16 #0
[ 77.152960][ C1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/12/2025
[ 77.155583][ C1] pstate: 604000c5 (nZCv daIF +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 77.157546][ C1] pc : __queue_work+0xe94/0x1324
[ 77.158811][ C1] lr : __queue_work+0xe94/0x1324
[ 77.160114][ C1] sp : ffff800080017b40
[ 77.161145][ C1] x29: ffff800080017b90 x28: dfff800000000000 x27: ffff700010002f88
[ 77.163285][ C1] x26: ffff80008fbbd600 x25: ffff0000dacac800 x24: 0000000000000008
[ 77.165326][ C1] x23: ffff0000dacac9c0 x22: 0000000000000100 x21: 1fffe0001b595938
[ 77.167421][ C1] x20: ffff800092f09000 x19: ffff0000ecf20948 x18: 0000000000000008
[ 77.169356][ C1] x17: 0000000000000000 x16: ffff80008b72ce6c x15: ffff700011f87b38
[ 77.171279][ C1] x14: 1ffff00011f87b38 x13: 0000000000000004 x12: ffffffffffffffff
[ 77.173271][ C1] x11: 0000000000000103 x10: 0000000000ff0100 x9 : d5bcdc7e4519df00
[ 77.175255][ C1] x8 : d5bcdc7e4519df00 x7 : 0000000000000001 x6 : 0000000000000001
[ 77.177277][ C1] x5 : ffff8000800172f8 x4 : ffff80008fcaf7c0 x3 : ffff8000804a7bb4
[ 77.179372][ C1] x2 : 0000000000000000 x1 : 0000000100000101 x0 : 0000000000000000
[ 77.181374][ C1] Call trace:
[ 77.182230][ C1] __queue_work+0xe94/0x1324 (P)
[ 77.183476][ C1] delayed_work_timer_fn+0x74/0x90
[ 77.184755][ C1] call_timer_fn+0x1b4/0x8b8
[ 77.185932][ C1] __run_timer_base+0x59c/0x7b4
[ 77.187119][ C1] run_timer_softirq+0xcc/0x194
[ 77.188360][ C1] handle_softirqs+0x320/0xd34
[ 77.189576][ C1] __do_softirq+0x14/0x20
[ 77.190672][ C1] ____do_softirq+0x14/0x20
[ 77.191884][ C1] call_on_irq_stack+0x24/0x4c
[ 77.193050][ C1] do_softirq_own_stack+0x20/0x2c
[ 77.194311][ C1] __irq_exit_rcu+0x1d8/0x544
[ 77.195550][ C1] irq_exit_rcu+0x14/0x84
[ 77.196669][ C1] el1_interrupt+0x38/0x68
[ 77.197818][ C1] el1h_64_irq_handler+0x18/0x24
[ 77.199152][ C1] el1h_64_irq+0x6c/0x70
[ 77.200245][ C1] lock_acquire+0x278/0x724 (P)
[ 77.201520][ C1] rcu_lock_acquire+0x44/0x54
[ 77.202722][ C1] page_ext_get+0x2c/0x2e8
[ 77.203908][ C1] page_table_check_set+0xa0/0x408
[ 77.205117][ C1] __page_table_check_ptes_set+0x2d0/0x398
[ 77.206601][ C1] set_pte_range+0x618/0x644
[ 77.207792][ C1] finish_fault+0x968/0xd6c
[ 77.208968][ C1] handle_pte_fault+0x3528/0x57b0
[ 77.210314][ C1] handle_mm_fault+0xfa8/0x188c
[ 77.211592][ C1] __get_user_pages+0x1878/0x3400
[ 77.212967][ C1] populate_vma_page_range+0x220/0x2f0
[ 77.214435][ C1] __mm_populate+0x240/0x3d8
[ 77.215600][ C1] vm_mmap_pgoff+0x304/0x3c4
[ 77.216833][ C1] ksys_mmap_pgoff+0xd0/0x5c8
[ 77.218066][ C1] __arm64_sys_mmap+0xf8/0x110
[ 77.219195][ C1] invoke_syscall+0x98/0x2b8
[ 77.220453][ C1] el0_svc_common+0x130/0x23c
[ 77.221747][ C1] do_el0_svc+0x48/0x58
[ 77.222881][ C1] el0_svc+0x54/0x168
[ 77.223946][ C1] el0t_64_sync_handler+0x84/0x108
[ 77.225305][ C1] el0t_64_sync+0x198/0x19c
[ 77.226425][ C1] irq event stamp: 3967
[ 77.227573][ C1] hardirqs last enabled at (3966): [<ffff80008b7ec538>] _raw_spin_unlock_irqrestore+0x38/0x98
[ 77.230143][ C1] hardirqs last disabled at (3967): [<ffff80008b7ec3e0>] _raw_spin_lock_irq+0x28/0x70
[ 77.232639][ C1] softirqs last enabled at (2318): [<ffff800080311b48>] handle_softirqs+0xb44/0xd34
[ 77.235151][ C1] softirqs last disabled at (3923): [<ffff800080020dbc>] __do_softirq+0x14/0x20
[ 77.237528][ C1] ---[ end trace 0000000000000000 ]---
So it looks like I was right about bluetooth (the work function is
"hci_cmd_timeout") but, unfortunately, "hci3" doesn't tell us much about
the client.
Perhaps the failed power-off right before the warning suggests that
we're not tearing down the wq properly on that error path? Let's see...
hci_rfkill_set_block() calls hci_dev_do_close() if the power-off fails.
That in turn cancels the delayed 'cmd_timer' work but only if HCI_UP is
not set in the device flags. But if hci_dev_do_poweroff() failed, HCI_UP
may well still be set. Then somehow the workqueue is destroyed, I guess
via hci_unregister_dev() setting HCI_UNREGISTER which enables
hci_release_dev() but at that point it's hard to know which bluetooth
driver is responsible.
Assuming hci_unregister_dev() is triggered via hci_dev_do_close()
closing the device, then unconditionally cancelling the delayed cmd work
when clearing HCI_UP sounds like a reasonable starter for ten?
Dunno, this is all guesswork in code that I'm not familiar with, so I'm
hoping somebody can tell me why I'm wrong :)
Will
--->8
diff --git a/net/bluetooth/hci_sync.c b/net/bluetooth/hci_sync.c
index dd770ef5ec36..d2623f6d0593 100644
--- a/net/bluetooth/hci_sync.c
+++ b/net/bluetooth/hci_sync.c
@@ -5147,11 +5147,9 @@ int hci_dev_close_sync(struct hci_dev *hdev)
}
err = hci_dev_shutdown(hdev);
-
- if (!test_and_clear_bit(HCI_UP, &hdev->flags)) {
- cancel_delayed_work_sync(&hdev->cmd_timer);
+ cancel_delayed_work_sync(&hdev->cmd_timer);
+ if (!test_and_clear_bit(HCI_UP, &hdev->flags))
return err;
- }
hci_leds_update_powered(hdev, false);
Powered by blists - more mailing lists