Skip to contentSkip to conversation

Bluetooth: hci_release_dev: disable delayed devcoredump work

PATCH In review Aby Sam Ross 3 participants 5 messages Mar 22 – Apr 9

Subsystems (2)
Bluetooth drivers Bluetooth
lore
Share & tools
lore

Aby Sam Ross

author
#0 lore raw

PATCH 1/1 Bluetooth: hci_release_dev: disable delayed devcoredump work

It is not necessary that the pending delayed hci devcoredump timeout work, hdev->dump.dump_timeout, submitted to the hdev->workqueue by the bluetooth devcoredump state machine,

	hci_devcd_rx()
		hci_devcd_handle_pkt_init()

will be reset by it or by the timeout func hci_devcd_timeout(), using hci_devcd_reset(), before destroying the workqueue or before the hci device is freed up in hci_release_dev().

In this bug the active delayed devcoredump timeout work's timer object is active when the memory associated with the hci device is freed up in hci_release_dev() causing the ODEBUG WARNING.

Make sure that the delayed devcoredump timeout work is disabled before the hdev->workqueue is destroyed and before the hdev memory is freed in hci_release_dev().

Tested the change with the syzbot reproducer that uses vhci device locally on x86_64 and on syzbot portal as well. Ran kselftest with net target.

Fixes 9695ef876fd1 ("Bluetooth: Add support for hci devcoredump")
Reported-by [email protected]
Closes https://syzkaller.appspot.com/bug?extid=b170dbf55520ebf5969a
Tested-by [email protected]
Signed-off-by Aby Sam Ross <[email protected]>
---
 net/bluetooth/hci_core.c | 3 +++
 1 file changed, 3 insertions(+)
net/bluetooth/hci_core.c +3 -0
index 01f8ceeb1c0c..1c7ee2a33337 100644
@@ -2747,6 +2747,9 @@ void hci_release_dev(struct hci_dev *hdev)
 	kfree_const(hdev->hw_info);
 	kfree_const(hdev->fw_info);
 
+	if (hdev->dump.supported)
+		disable_delayed_work_sync(&hdev->dump.dump_timeout);
+
 	destroy_workqueue(hdev->workqueue);
 	destroy_workqueue(hdev->req_workqueue);
Signature · 1 line
2.53.0
#1 lore raw

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list. This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=1070558

---Test result---

Test Summary:

CheckPatch                    PENDING   0.39 seconds
GitLint                       PENDING   0.25 seconds
SubjectPrefix                 PASS      0.12 seconds
BuildKernel                   PASS      26.40 seconds
CheckAllWarning               PASS      28.76 seconds
CheckSparse                   PASS      30.08 seconds
BuildKernel32                 PASS      25.51 seconds
TestRunnerSetup               PASS      569.23 seconds
TestRunner_l2cap-tester       PASS      28.00 seconds
TestRunner_iso-tester         FAIL      32.58 seconds
TestRunner_bnep-tester        PASS      6.38 seconds
TestRunner_mgmt-tester        FAIL      115.69 seconds
TestRunner_rfcomm-tester      PASS      9.48 seconds
TestRunner_sco-tester         FAIL      14.16 seconds
TestRunner_ioctl-tester       PASS      10.13 seconds
TestRunner_mesh-tester        FAIL      12.48 seconds
TestRunner_smp-tester         PASS      8.47 seconds
TestRunner_userchan-tester    PASS      6.71 seconds
IncrementalBuild              PENDING   0.48 seconds

Details
##############################
Test: CheckPatch - PENDING
Desc: Run checkpatch.pl script
Output:

##############################
Test: GitLint - PENDING
Desc: Run gitlint
Output:

##############################
Test: TestRunner_iso-tester - FAIL
Desc: Run iso-tester with test-runner
Output:

BUG: KASAN: slab-use-after-free in le_read_features_complete+0x7e/0x2b0

Total: 141, Passed: 141 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner_mgmt-tester - FAIL
Desc: Run mgmt-tester with test-runner
Output:
Total: 494, Passed: 489 (99.0%), Failed: 1, Not Run: 4

Failed Test Cases
Read Exp Feature - Success Failed 0.107 seconds
##############################
Test: TestRunner_sco-tester - FAIL
Desc: Run sco-tester with test-runner
Output:
WARNING: possible circular locking dependency detected

BUG: sleeping function called from invalid context at net/core/sock.c:3782

Total: 30, Passed: 30 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner_mesh-tester - FAIL
Desc: Run mesh-tester with test-runner Output:
Total: 10, Passed: 8 (80.0%), Failed: 2, Not Run: 0

Failed Test Cases

Mesh - Send cancel - 1                               Timed out    2.773 seconds
Mesh - Send cancel - 2                               Timed out    1.993 seconds

##############################
Test: IncrementalBuild - PENDING
Desc: Incremental build with the patches in the series Output:

---
Regards,
Linux Bluetooth

maintainer
#2 lore raw
In reply to Aby Sam Ross

Hi Aby,

Quoted 46 lines · Aby Sam Ross

It is not necessary that the pending delayed hci devcoredump timeout work, hdev->dump.dump_timeout, submitted to the hdev->workqueue by the bluetooth devcoredump state machine,

        hci_devcd_rx()
                hci_devcd_handle_pkt_init()

will be reset by it or by the timeout func hci_devcd_timeout(), using hci_devcd_reset(), before destroying the workqueue or before the hci device is freed up in hci_release_dev().

In this bug the active delayed devcoredump timeout work's timer object is active when the memory associated with the hci device is freed up in hci_release_dev() causing the ODEBUG WARNING.

Make sure that the delayed devcoredump timeout work is disabled before the hdev->workqueue is destroyed and before the hdev memory is freed in hci_release_dev().

Tested the change with the syzbot reproducer that uses vhci device locally on x86_64 and on syzbot portal as well. Ran kselftest with net target.

Fixes 9695ef876fd1 ("Bluetooth: Add support for hci devcoredump")
Reported-by [email protected]
Closes https://syzkaller.appspot.com/bug?extid=b170dbf55520ebf5969a
Tested-by [email protected]
Signed-off-by Aby Sam Ross <[email protected]>
---
 net/bluetooth/hci_core.c | 3 +++
 1 file changed, 3 insertions(+)
net/bluetooth/hci_core.c +3 -1
index 01f8ceeb1c0c..1c7ee2a33337 100644
@@ -2747,6 +2747,9 @@ void hci_release_dev(struct hci_dev *hdev)
        kfree_const(hdev->hw_info);
        kfree_const(hdev->fw_info);
 
+       if (hdev->dump.supported)
+               disable_delayed_work_sync(&hdev->dump.dump_timeout);
+
        destroy_workqueue(hdev->workqueue);
        destroy_workqueue(hdev->req_workqueue);
 
--
Quoted 2 lines

2.53.0

https://sashiko.dev/#/patchset/20260322210849.68743-1-abysamross%40gmail.com

Both points seems valid, that perhaps the dump shouldn't be attached to hdev object since it maybe necessary to unregister the hdev as part of devcoredump handling, anyway if it is required then upon unregister it shall actually cleanup the dump object as well.

Signature · 1 line
Luiz Augusto von Dentz
author
#3 lore raw
Quoted 54 lines · Luiz Augusto von Dentz

Hi Aby,

Quoted 46 lines · Aby Sam Ross

It is not necessary that the pending delayed hci devcoredump timeout work, hdev->dump.dump_timeout, submitted to the hdev->workqueue by the bluetooth devcoredump state machine,

        hci_devcd_rx()
                hci_devcd_handle_pkt_init()

will be reset by it or by the timeout func hci_devcd_timeout(), using hci_devcd_reset(), before destroying the workqueue or before the hci device is freed up in hci_release_dev().

In this bug the active delayed devcoredump timeout work's timer object is active when the memory associated with the hci device is freed up in hci_release_dev() causing the ODEBUG WARNING.

Make sure that the delayed devcoredump timeout work is disabled before the hdev->workqueue is destroyed and before the hdev memory is freed in hci_release_dev().

Tested the change with the syzbot reproducer that uses vhci device locally on x86_64 and on syzbot portal as well. Ran kselftest with net target.

Fixes 9695ef876fd1 ("Bluetooth: Add support for hci devcoredump")
Reported-by [email protected]
Closes https://syzkaller.appspot.com/bug?extid=b170dbf55520ebf5969a
Tested-by [email protected]
Signed-off-by Aby Sam Ross <[email protected]>
---
 net/bluetooth/hci_core.c | 3 +++
 1 file changed, 3 insertions(+)
net/bluetooth/hci_core.c +3 -1
index 01f8ceeb1c0c..1c7ee2a33337 100644
@@ -2747,6 +2747,9 @@ void hci_release_dev(struct hci_dev *hdev)
        kfree_const(hdev->hw_info);
        kfree_const(hdev->fw_info);
 
+       if (hdev->dump.supported)
+               disable_delayed_work_sync(&hdev->dump.dump_timeout);
+
        destroy_workqueue(hdev->workqueue);
        destroy_workqueue(hdev->req_workqueue);
 
--
Quoted 2 lines

2.53.0

https://sashiko.dev/#/patchset/20260322210849.68743-1-abysamross%40gmail.com

Quoted 7 lines

Both points seems valid, that perhaps the dump shouldn't be attached to hdev object since it maybe necessary to unregister the hdev as part of devcoredump handling, anyway if it is required then upon unregister it shall actually cleanup the dump object as well.

Signature · 1 line
Luiz Augusto von Dentz

Hi Luiz,

From what I see hci_unregister_dev() is called by all bluetooth drivers that use hci_devcd_init(). Please correct me if I am wrong.

So we can either make hci_devcd_free() non-static and then call it from hci_unregister_dev()
OR
Do vfree(hdev->dump.head) followed by disabling the delayed devcoredump timeout work in hci_unregister_dev()

And then destroy the workqueue(dump_rx)?

#4 lore raw
In reply to Aby Sam Ross

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list. This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=1070558

---Test result---

Test Summary:

CheckPatch                    PENDING   0.45 seconds
GitLint                       PENDING   0.25 seconds
SubjectPrefix                 PASS      0.12 seconds
BuildKernel                   PASS      25.33 seconds
CheckAllWarning               PASS      27.93 seconds
CheckSparse                   PASS      27.17 seconds
BuildKernel32                 PASS      25.03 seconds
TestRunnerSetup               PASS      530.15 seconds
TestRunner_l2cap-tester       PASS      27.92 seconds
TestRunner_iso-tester         PASS      39.73 seconds
TestRunner_bnep-tester        PASS      6.37 seconds
TestRunner_mgmt-tester        FAIL      111.81 seconds
TestRunner_rfcomm-tester      PASS      10.84 seconds
TestRunner_sco-tester         FAIL      14.51 seconds
TestRunner_ioctl-tester       PASS      10.38 seconds
TestRunner_mesh-tester        FAIL      12.58 seconds
TestRunner_smp-tester         PASS      8.77 seconds
TestRunner_userchan-tester    PASS      6.72 seconds
TestRunner_6lowpan-tester     FAIL      8.77 seconds
IncrementalBuild              PENDING   0.26 seconds

Details
##############################
Test: CheckPatch - PENDING
Desc: Run checkpatch.pl script
Output:

##############################
Test: GitLint - PENDING
Desc: Run gitlint
Output:

##############################
Test: TestRunner_mgmt-tester - FAIL
Desc: Run mgmt-tester with test-runner Output:
Total: 494, Passed: 489 (99.0%), Failed: 1, Not Run: 4

Failed Test Cases
Read Exp Feature - Success Failed 0.103 seconds
##############################
Test: TestRunner_sco-tester - FAIL
Desc: Run sco-tester with test-runner
Output:
WARNING: possible circular locking dependency detected
7.0.0-rc2-g58df065202ea #1 Not tainted
------------------------------------------------------
kworker/u5:2/117 is trying to acquire lock:
ffff888001abe240 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}, at: sco_connect_cfm+0x358/0x8d0

but task is already holding lock:
ffff888002094c20 (&conn->lock){+.+.}-{3:3}, at: sco_connect_cfm+0x22d/0x8d0

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #1 (&conn->lock){+.+.}-{3:3}:

       lock_acquire+0xf7/0x2c0
       _raw_spin_lock+0x2a/0x40
       sco_sock_connect+0x4d7/0x1280
       __sys_connect+0x1a3/0x260
       __x64_sys_connect+0x6e/0xb0
       do_syscall_64+0xa0/0x570
       entry_SYSCALL_64_after_hwframe+0x74/0x7c

-> #0 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}:

       check_prev_add+0xe9/0xc70
       __lock_acquire+0x1457/0x1df0
       lock_acquire+0xf7/0x2c0
       lock_sock_nested+0x36/0xd0
       sco_connect_cfm+0x358/0x8d0
       hci_sync_conn_complete_evt+0x3d3/0x8e0
       hci_event_packet+0x74f/0xb10
       hci_rx_work+0x398/0xd00
       process_scheduled_works+0xb16/0x1ac0
       worker_thread+0x4ff/0xba0
       kthread+0x368/0x490
       ret_from_fork+0x498/0x7e0
       ret_from_fork_asm+0x19/0x30

other info that might help us debug this:

...

BUG: sleeping function called from invalid context at net/core/sock.c:3782

in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 117, name: kworker/u5:2
preempt_count: 1, expected: 0
RCU nest depth: 0, expected: 0
INFO: lockdep is turned off.

CPU: 0 UID: 0 PID: 117 Comm: kworker/u5:2 Not tainted 7.0.0-rc2-g58df065202ea #1 PREEMPT(lazy) 
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-1ubuntu1.1 04/01/2014
Workqueue: hci0 hci_rx_work
Call Trace:
 <TASK>
 dump_stack_lvl+0x49/0x60
 __might_resched+0x2ea/0x500
 lock_sock_nested+0x47/0xd0
 ? sco_connect_cfm+0x358/0x8d0
 sco_connect_cfm+0x358/0x8d0
 ? hci_debugfs_create_conn+0x190/0x210
 ? __pfx_sco_connect_cfm+0x10/0x10
 hci_sync_conn_complete_evt+0x3d3/0x8e0
 hci_event_packet+0x74f/0xb10
 ? __pfx_hci_sync_conn_complete_evt+0x10/0x10
 ? __pfx_hci_event_packet+0x10/0x10
 ? mark_held_locks+0x49/0x80
 ? lockdep_hardirqs_on_prepare+0xd4/0x180
 ? _raw_spin_unlock_irqrestore+0x2c/0x50
 hci_rx_work+0x398/0xd00
 process_scheduled_works+0xb16/0x1ac0
 ? __pfx_process_scheduled_works+0x10/0x10
 ? lock_acquire+0xf7/0x2c0
 ? lock_is_held_type+0x9b/0x110
 ? __pfx_hci_rx_work+0x10/0x10
 worker_thread+0x4ff/0xba0
 ? _raw_spin_unlock_irqrestore+0x2c/0x50
 ? __pfx_worker_thread+0x10/0x10
 kthread+0x368/0x490
 ? _raw_spin_unlock_irq+0x23/0x40
 ? __pfx_kthread+0x10/0x10
 ret_from_fork+0x498/0x7e0
 ? __pfx_ret_from_fork+0x10/0x10
 ? __switch_to+0x9e4/0xe50
 ? __switch_to_asm+0x32/0x60

...
Total: 30, Passed: 30 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner_mesh-tester - FAIL
Desc: Run mesh-tester with test-runner Output:
Total: 10, Passed: 8 (80.0%), Failed: 2, Not Run: 0

Failed Test Cases

Mesh - Send cancel - 1                               Timed out    2.679 seconds
Mesh - Send cancel - 2                               Timed out    1.992 seconds

##############################
Test: TestRunner_6lowpan-tester - FAIL
Desc: Run 6lowpan-tester with test-runner
Output:
WARNING: possible circular locking dependency detected 7.0.0-rc2-g58df065202ea #1 Not tainted
------------------------------------------------------
kworker/0:0/9 is trying to acquire lock:
ffff88800275c140 ((wq_completion)hci0#2){+.+.}-{0:0}, at: touch_wq_lockdep_map+0x75/0x180

but task is already holding lock:
ffffffffb2e4d720 (rtnl_mutex){+.+.}-{4:4}, at: lowpan_unregister_netdev+0xd/0x30

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #4 (rtnl_mutex){+.+.}-{4:4}:

       lock_acquire+0xf7/0x2c0
       __mutex_lock+0x16b/0x1fc0
       lowpan_register_netdev+0x11/0x30
       chan_ready_cb+0x836/0xd00
       l2cap_recv_frame+0x6a06/0x8920
       l2cap_recv_acldata+0x790/0xdf0
       hci_rx_work+0x500/0xd00
       process_scheduled_works+0xb16/0x1ac0
       worker_thread+0x4ff/0xba0
       kthread+0x368/0x490
       ret_from_fork+0x498/0x7e0
       ret_from_fork_asm+0x19/0x30

-> #3 (&chan->lock#3/1){+.+.}-{4:4}:

       lock_acquire+0xf7/0x2c0
       __mutex_lock+0x16b/0x1fc0
       l2cap_chan_connect+0x74e/0x1980
       lowpan_control_write+0x523/0x660
       full_proxy_write+0x10b/0x190
       vfs_write+0x1c0/0xf60
       ksys_write+0xf1/0x1d0
       do_syscall_64+0xa0/0x570
       entry_SYSCALL_64_after_hwframe+0x74/0x7c

-> #2 (&conn->lock){+.+.}-{4:4}:
...
Total: 8, Passed: 8 (100.0%), Failed: 0, Not Run: 0
##############################
Test: IncrementalBuild - PENDING
Desc: Incremental build with the patches in the series Output:

https://github.com/bluez/bluetooth-next/pull/27/checks

---
Regards,
Linux Bluetooth