* [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
@ 2021-05-14 7:14 Kai-Heng Feng
2021-05-14 8:12 ` [v2] " bluez.test.bot
` (2 more replies)
0 siblings, 3 replies; 20+ messages in thread
From: Kai-Heng Feng @ 2021-05-14 7:14 UTC (permalink / raw)
To: marcel, johan.hedberg
Cc: Kai-Heng Feng, Luiz Augusto von Dentz, David S. Miller,
Jakub Kicinski, open list:BLUETOOTH SUBSYSTEM,
open list:NETWORKING [GENERAL],
open list
Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
stops working:
[ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
[ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
[ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
[ 545.660350] usb 3-10: device descriptor read/64, error -110
[ 561.283530] usb 3-10: device descriptor read/64, error -110
[ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
[ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
[ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
[ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
[ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
[ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
Or kernel panics because other workqueues already freed skb:
[ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
[ 2048.663775] #PF: supervisor read access in kernel mode
[ 2048.663779] #PF: error_code(0x0000) - not-present page
[ 2048.663782] PGD 0 P4D 0
[ 2048.663787] Oops: 0000 [#1] SMP NOPTI
[ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
[ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
[ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
[ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
07 83 f8 01
[ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
[ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
[ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
[ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
[ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
[ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
[ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
[ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
[ 2048.663856] PKRU: 55555554
[ 2048.663859] Call Trace:
[ 2048.663865] ? skb_release_head_state+0x5e/0x80
[ 2048.663873] kfree_skb+0x2f/0xb0
[ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
[ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
[ 2048.663954] ? __cond_resched+0x1a/0x50
[ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
[ 2048.664007] rfkill_set_block+0x98/0x170
[ 2048.664016] rfkill_fop_write+0x136/0x1e0
[ 2048.664022] vfs_write+0xc7/0x260
[ 2048.664030] ksys_write+0xb1/0xe0
[ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
[ 2048.664042] __x64_sys_write+0x1a/0x20
[ 2048.664048] do_syscall_64+0x40/0xb0
[ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 2048.664060] RIP: 0033:0x7fe02ac23c27
[ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
[ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
[ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
[ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
[ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
So move the shutdown callback to a place where workqueues are either
flushed or cancelled to resolve the issue.
Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
---
v2:
- Rebased on bluetooth-next.
net/bluetooth/hci_core.c | 16 ++++++++--------
1 file changed, 8 insertions(+), 8 deletions(-)
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 7baf93eda936..6eedf334f943 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -1716,14 +1716,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
BT_DBG("%s %p", hdev->name, hdev);
- if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
- !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
- test_bit(HCI_UP, &hdev->flags)) {
- /* Execute vendor specific shutdown routine */
- if (hdev->shutdown)
- hdev->shutdown(hdev);
- }
-
cancel_delayed_work(&hdev->power_off);
cancel_delayed_work(&hdev->ncmd_timer);
@@ -1801,6 +1793,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
clear_bit(HCI_INIT, &hdev->flags);
}
+ if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
+ !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
+ test_bit(HCI_UP, &hdev->flags)) {
+ /* Execute vendor specific shutdown routine */
+ if (hdev->shutdown)
+ hdev->shutdown(hdev);
+ }
+
/* flush cmd work */
flush_work(&hdev->cmd_work);
--
2.30.2
^ permalink raw reply related [flat|nested] 20+ messages in thread
* RE: [v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-05-14 7:14 [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled Kai-Heng Feng
@ 2021-05-14 8:12 ` bluez.test.bot
2021-05-14 18:15 ` [PATCH v2] " Marcel Holtmann
[not found] ` <20210802030538.2023-1-hdanton@sina.com>
2 siblings, 0 replies; 20+ messages in thread
From: bluez.test.bot @ 2021-05-14 8:12 UTC (permalink / raw)
To: linux-bluetooth, kai.heng.feng
[-- Attachment #1: Type: text/plain, Size: 3763 bytes --]
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=482277
---Test result---
Test Summary:
CheckPatch PASS 0.75 seconds
GitLint FAIL 0.11 seconds
BuildKernel PASS 523.24 seconds
TestRunner: Setup PASS 352.71 seconds
TestRunner: l2cap-tester PASS 2.68 seconds
TestRunner: bnep-tester PASS 1.88 seconds
TestRunner: mgmt-tester PASS 27.21 seconds
TestRunner: rfcomm-tester PASS 2.03 seconds
TestRunner: sco-tester PASS 2.04 seconds
TestRunner: smp-tester PASS 2.18 seconds
TestRunner: userchan-tester PASS 1.90 seconds
Details
##############################
Test: CheckPatch - PASS - 0.75 seconds
Run checkpatch.pl script with rule in .checkpatch.conf
##############################
Test: GitLint - FAIL - 0.11 seconds
Run gitlint with rule in .gitlint
Bluetooth: Shutdown controller after workqueues are flushed or cancelled
23: B1 Line exceeds max length (102>80): "[ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20"
24: B1 Line exceeds max length (104>80): "[ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020"
26: B1 Line exceeds max length (202>80): "[ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1"
34: B1 Line exceeds max length (91>80): "[ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000"
54: B1 Line exceeds max length (214>80): "[ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24"
55: B1 Line exceeds max length (85>80): "[ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001"
##############################
Test: BuildKernel - PASS - 523.24 seconds
Build Kernel with minimal configuration supports Bluetooth
##############################
Test: TestRunner: Setup - PASS - 352.71 seconds
Setup environment for running Test Runner
##############################
Test: TestRunner: l2cap-tester - PASS - 2.68 seconds
Run test-runner with l2cap-tester
Total: 40, Passed: 40 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner: bnep-tester - PASS - 1.88 seconds
Run test-runner with bnep-tester
Total: 1, Passed: 1 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner: mgmt-tester - PASS - 27.21 seconds
Run test-runner with mgmt-tester
Total: 416, Passed: 401 (96.4%), Failed: 0, Not Run: 15
##############################
Test: TestRunner: rfcomm-tester - PASS - 2.03 seconds
Run test-runner with rfcomm-tester
Total: 9, Passed: 9 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner: sco-tester - PASS - 2.04 seconds
Run test-runner with sco-tester
Total: 8, Passed: 8 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner: smp-tester - PASS - 2.18 seconds
Run test-runner with smp-tester
Total: 8, Passed: 8 (100.0%), Failed: 0, Not Run: 0
##############################
Test: TestRunner: userchan-tester - PASS - 1.90 seconds
Run test-runner with userchan-tester
Total: 3, Passed: 3 (100.0%), Failed: 0, Not Run: 0
---
Regards,
Linux Bluetooth
[-- Attachment #2: l2cap-tester.log --]
[-- Type: application/octet-stream, Size: 44230 bytes --]
[-- Attachment #3: bnep-tester.log --]
[-- Type: application/octet-stream, Size: 3557 bytes --]
[-- Attachment #4: mgmt-tester.log --]
[-- Type: application/octet-stream, Size: 546295 bytes --]
[-- Attachment #5: rfcomm-tester.log --]
[-- Type: application/octet-stream, Size: 11677 bytes --]
[-- Attachment #6: sco-tester.log --]
[-- Type: application/octet-stream, Size: 9912 bytes --]
[-- Attachment #7: smp-tester.log --]
[-- Type: application/octet-stream, Size: 11822 bytes --]
[-- Attachment #8: userchan-tester.log --]
[-- Type: application/octet-stream, Size: 5454 bytes --]
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-05-14 7:14 [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled Kai-Heng Feng
2021-05-14 8:12 ` [v2] " bluez.test.bot
@ 2021-05-14 18:15 ` Marcel Holtmann
2021-07-28 13:50 ` Mattijs Korpershoek
[not found] ` <20210802030538.2023-1-hdanton@sina.com>
2 siblings, 1 reply; 20+ messages in thread
From: Marcel Holtmann @ 2021-05-14 18:15 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Johan Hedberg, Luiz Augusto von Dentz, David S. Miller,
Jakub Kicinski, open list:BLUETOOTH SUBSYSTEM,
open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
> Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
> stops working:
> [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
> [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
> [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> [ 545.660350] usb 3-10: device descriptor read/64, error -110
> [ 561.283530] usb 3-10: device descriptor read/64, error -110
> [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
> [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
> [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
> [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
>
> Or kernel panics because other workqueues already freed skb:
> [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
> [ 2048.663775] #PF: supervisor read access in kernel mode
> [ 2048.663779] #PF: error_code(0x0000) - not-present page
> [ 2048.663782] PGD 0 P4D 0
> [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
> [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
> [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
> [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
> [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
> 07 83 f8 01
> [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
> [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
> [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
> [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
> [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
> [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
> [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
> [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
> [ 2048.663856] PKRU: 55555554
> [ 2048.663859] Call Trace:
> [ 2048.663865] ? skb_release_head_state+0x5e/0x80
> [ 2048.663873] kfree_skb+0x2f/0xb0
> [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
> [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
> [ 2048.663954] ? __cond_resched+0x1a/0x50
> [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
> [ 2048.664007] rfkill_set_block+0x98/0x170
> [ 2048.664016] rfkill_fop_write+0x136/0x1e0
> [ 2048.664022] vfs_write+0xc7/0x260
> [ 2048.664030] ksys_write+0xb1/0xe0
> [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
> [ 2048.664042] __x64_sys_write+0x1a/0x20
> [ 2048.664048] do_syscall_64+0x40/0xb0
> [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2048.664060] RIP: 0033:0x7fe02ac23c27
> [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
> [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
> [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
> [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
> [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
>
> So move the shutdown callback to a place where workqueues are either
> flushed or cancelled to resolve the issue.
>
> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> ---
> v2:
> - Rebased on bluetooth-next.
>
> net/bluetooth/hci_core.c | 16 ++++++++--------
> 1 file changed, 8 insertions(+), 8 deletions(-)
patch has been applied to bluetooth-next tree.
Regards
Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-05-14 18:15 ` [PATCH v2] " Marcel Holtmann
@ 2021-07-28 13:50 ` Mattijs Korpershoek
2021-07-28 15:25 ` Kai-Heng Feng
0 siblings, 1 reply; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-07-28 13:50 UTC (permalink / raw)
To: Marcel Holtmann, Kai-Heng Feng
Cc: Johan Hedberg, Luiz Augusto von Dentz, David S. Miller,
Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng, Marcel,
Marcel Holtmann <marcel@holtmann.org> writes:
> Hi Kai-Heng,
>
>> Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
>> stops working:
>> [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
>> [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
>> [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
>> [ 545.660350] usb 3-10: device descriptor read/64, error -110
>> [ 561.283530] usb 3-10: device descriptor read/64, error -110
>> [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
>> [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
>> [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
>> [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
>> [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
>> [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
>>
>> Or kernel panics because other workqueues already freed skb:
>> [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
>> [ 2048.663775] #PF: supervisor read access in kernel mode
>> [ 2048.663779] #PF: error_code(0x0000) - not-present page
>> [ 2048.663782] PGD 0 P4D 0
>> [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
>> [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
>> [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
>> [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
>> [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
>> 07 83 f8 01
>> [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
>> [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
>> [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
>> [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
>> [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
>> [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
>> [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
>> [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
>> [ 2048.663856] PKRU: 55555554
>> [ 2048.663859] Call Trace:
>> [ 2048.663865] ? skb_release_head_state+0x5e/0x80
>> [ 2048.663873] kfree_skb+0x2f/0xb0
>> [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
>> [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
>> [ 2048.663954] ? __cond_resched+0x1a/0x50
>> [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
>> [ 2048.664007] rfkill_set_block+0x98/0x170
>> [ 2048.664016] rfkill_fop_write+0x136/0x1e0
>> [ 2048.664022] vfs_write+0xc7/0x260
>> [ 2048.664030] ksys_write+0xb1/0xe0
>> [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
>> [ 2048.664042] __x64_sys_write+0x1a/0x20
>> [ 2048.664048] do_syscall_64+0x40/0xb0
>> [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
>> [ 2048.664060] RIP: 0033:0x7fe02ac23c27
>> [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
>> [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
>> [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
>> [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
>> [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
>> [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
>> [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
>>
>> So move the shutdown callback to a place where workqueues are either
>> flushed or cancelled to resolve the issue.
>>
>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>> ---
>> v2:
>> - Rebased on bluetooth-next.
>>
>> net/bluetooth/hci_core.c | 16 ++++++++--------
>> 1 file changed, 8 insertions(+), 8 deletions(-)
>
> patch has been applied to bluetooth-next tree.
This patch seems to introduce a regression in the btmtksdio driver.
With this patch applied, I can't enable the hci0 interface anymore on mt8183-pumpkin:
i500-pumpkin login: root
root@i500-pumpkin:~# uname -a
Linux i500-pumpkin 5.14.0-rc3 #94 SMP PREEMPT Wed Jul 28 11:58:20 CEST 2021 aarch64 aarch64 aarch64 GNU/Linux
root@i500-pumpkin:~# hciconfig hci0 up
Can't init device hci0: Connection timed out (110)
root@i500-pumpkin:~# hciconfig hci0 down
root@i500-pumpkin:~# hciconfig hci0 up
Can't init device hci0: Input/output error (5)
Reverting it fixes the above issue.
Any suggestion on how to fix this without touching hci_core ?
Maybe the btmtksdio driver needs some rework. As I'm not familiar with the code, I would appreciate any tips.
Thanks,
Mattijs Korpershoek
>
> Regards
>
> Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-07-28 13:50 ` Mattijs Korpershoek
@ 2021-07-28 15:25 ` Kai-Heng Feng
2021-07-30 11:40 ` Mattijs Korpershoek
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-07-28 15:25 UTC (permalink / raw)
To: Mattijs Korpershoek
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
On Wed, Jul 28, 2021 at 9:50 PM Mattijs Korpershoek
<mkorpershoek@baylibre.com> wrote:
>
> Hi Kai-Heng, Marcel,
>
> Marcel Holtmann <marcel@holtmann.org> writes:
>
> > Hi Kai-Heng,
> >
> >> Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
> >> stops working:
> >> [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
> >> [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
> >> [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> >> [ 545.660350] usb 3-10: device descriptor read/64, error -110
> >> [ 561.283530] usb 3-10: device descriptor read/64, error -110
> >> [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> >> [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
> >> [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
> >> [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> >> [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
> >> [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> >>
> >> Or kernel panics because other workqueues already freed skb:
> >> [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
> >> [ 2048.663775] #PF: supervisor read access in kernel mode
> >> [ 2048.663779] #PF: error_code(0x0000) - not-present page
> >> [ 2048.663782] PGD 0 P4D 0
> >> [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
> >> [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
> >> [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
> >> [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
> >> [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
> >> 07 83 f8 01
> >> [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
> >> [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
> >> [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
> >> [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
> >> [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
> >> [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
> >> [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
> >> [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >> [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
> >> [ 2048.663856] PKRU: 55555554
> >> [ 2048.663859] Call Trace:
> >> [ 2048.663865] ? skb_release_head_state+0x5e/0x80
> >> [ 2048.663873] kfree_skb+0x2f/0xb0
> >> [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
> >> [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
> >> [ 2048.663954] ? __cond_resched+0x1a/0x50
> >> [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
> >> [ 2048.664007] rfkill_set_block+0x98/0x170
> >> [ 2048.664016] rfkill_fop_write+0x136/0x1e0
> >> [ 2048.664022] vfs_write+0xc7/0x260
> >> [ 2048.664030] ksys_write+0xb1/0xe0
> >> [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
> >> [ 2048.664042] __x64_sys_write+0x1a/0x20
> >> [ 2048.664048] do_syscall_64+0x40/0xb0
> >> [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
> >> [ 2048.664060] RIP: 0033:0x7fe02ac23c27
> >> [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> >> [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> >> [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
> >> [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
> >> [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
> >> [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
> >> [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
> >>
> >> So move the shutdown callback to a place where workqueues are either
> >> flushed or cancelled to resolve the issue.
> >>
> >> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> >> ---
> >> v2:
> >> - Rebased on bluetooth-next.
> >>
> >> net/bluetooth/hci_core.c | 16 ++++++++--------
> >> 1 file changed, 8 insertions(+), 8 deletions(-)
> >
> > patch has been applied to bluetooth-next tree.
>
> This patch seems to introduce a regression in the btmtksdio driver.
> With this patch applied, I can't enable the hci0 interface anymore on mt8183-pumpkin:
>
> i500-pumpkin login: root
> root@i500-pumpkin:~# uname -a
> Linux i500-pumpkin 5.14.0-rc3 #94 SMP PREEMPT Wed Jul 28 11:58:20 CEST 2021 aarch64 aarch64 aarch64 GNU/Linux
> root@i500-pumpkin:~# hciconfig hci0 up
> Can't init device hci0: Connection timed out (110)
> root@i500-pumpkin:~# hciconfig hci0 down
> root@i500-pumpkin:~# hciconfig hci0 up
> Can't init device hci0: Input/output error (5)
>
> Reverting it fixes the above issue.
> Any suggestion on how to fix this without touching hci_core ?
> Maybe the btmtksdio driver needs some rework. As I'm not familiar with the code, I would appreciate any tips.
Can you please attach dmesg? Also, full ftrace log on btmtksdio can
also be helpful.
Kai-Heng
>
> Thanks,
> Mattijs Korpershoek
>
>
> >
> > Regards
> >
> > Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-07-28 15:25 ` Kai-Heng Feng
@ 2021-07-30 11:40 ` Mattijs Korpershoek
2021-08-03 6:42 ` Kai-Heng Feng
0 siblings, 1 reply; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-07-30 11:40 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> On Wed, Jul 28, 2021 at 9:50 PM Mattijs Korpershoek
> <mkorpershoek@baylibre.com> wrote:
>>
>> Hi Kai-Heng, Marcel,
>>
>> Marcel Holtmann <marcel@holtmann.org> writes:
>>
>> > Hi Kai-Heng,
>> >
>> >> Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
>> >> stops working:
>> >> [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
>> >> [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
>> >> [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
>> >> [ 545.660350] usb 3-10: device descriptor read/64, error -110
>> >> [ 561.283530] usb 3-10: device descriptor read/64, error -110
>> >> [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
>> >> [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
>> >> [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
>> >> [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
>> >> [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
>> >> [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
>> >>
>> >> Or kernel panics because other workqueues already freed skb:
>> >> [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
>> >> [ 2048.663775] #PF: supervisor read access in kernel mode
>> >> [ 2048.663779] #PF: error_code(0x0000) - not-present page
>> >> [ 2048.663782] PGD 0 P4D 0
>> >> [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
>> >> [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
>> >> [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
>> >> [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
>> >> [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
>> >> 07 83 f8 01
>> >> [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
>> >> [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
>> >> [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
>> >> [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
>> >> [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
>> >> [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
>> >> [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
>> >> [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> >> [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
>> >> [ 2048.663856] PKRU: 55555554
>> >> [ 2048.663859] Call Trace:
>> >> [ 2048.663865] ? skb_release_head_state+0x5e/0x80
>> >> [ 2048.663873] kfree_skb+0x2f/0xb0
>> >> [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
>> >> [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
>> >> [ 2048.663954] ? __cond_resched+0x1a/0x50
>> >> [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
>> >> [ 2048.664007] rfkill_set_block+0x98/0x170
>> >> [ 2048.664016] rfkill_fop_write+0x136/0x1e0
>> >> [ 2048.664022] vfs_write+0xc7/0x260
>> >> [ 2048.664030] ksys_write+0xb1/0xe0
>> >> [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
>> >> [ 2048.664042] __x64_sys_write+0x1a/0x20
>> >> [ 2048.664048] do_syscall_64+0x40/0xb0
>> >> [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
>> >> [ 2048.664060] RIP: 0033:0x7fe02ac23c27
>> >> [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
>> >> [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
>> >> [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
>> >> [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
>> >> [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
>> >> [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
>> >> [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
>> >>
>> >> So move the shutdown callback to a place where workqueues are either
>> >> flushed or cancelled to resolve the issue.
>> >>
>> >> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>> >> ---
>> >> v2:
>> >> - Rebased on bluetooth-next.
>> >>
>> >> net/bluetooth/hci_core.c | 16 ++++++++--------
>> >> 1 file changed, 8 insertions(+), 8 deletions(-)
>> >
>> > patch has been applied to bluetooth-next tree.
>>
>> This patch seems to introduce a regression in the btmtksdio driver.
>> With this patch applied, I can't enable the hci0 interface anymore on mt8183-pumpkin:
>>
>> i500-pumpkin login: root
>> root@i500-pumpkin:~# uname -a
>> Linux i500-pumpkin 5.14.0-rc3 #94 SMP PREEMPT Wed Jul 28 11:58:20 CEST 2021 aarch64 aarch64 aarch64 GNU/Linux
>> root@i500-pumpkin:~# hciconfig hci0 up
>> Can't init device hci0: Connection timed out (110)
>> root@i500-pumpkin:~# hciconfig hci0 down
>> root@i500-pumpkin:~# hciconfig hci0 up
>> Can't init device hci0: Input/output error (5)
>>
>> Reverting it fixes the above issue.
>> Any suggestion on how to fix this without touching hci_core ?
>> Maybe the btmtksdio driver needs some rework. As I'm not familiar with the code, I would appreciate any tips.
>
> Can you please attach dmesg? Also, full ftrace log on btmtksdio can
> also be helpful.
Thank you for your help. Sorry I did not post the logs previously.
dmesg: https://pastebin.com/tpWDNyQr
ftrace on btmtksdio: https://pastebin.com/jmhvmwUw
Mattijs
>
> Kai-Heng
>
>>
>> Thanks,
>> Mattijs Korpershoek
>>
>>
>> >
>> > Regards
>> >
>> > Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-07-30 11:40 ` Mattijs Korpershoek
@ 2021-08-03 6:42 ` Kai-Heng Feng
2021-08-03 8:21 ` Mattijs Korpershoek
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-03 6:42 UTC (permalink / raw)
To: Mattijs Korpershoek
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Mattijs,
On Fri, Jul 30, 2021 at 7:40 PM Mattijs Korpershoek
<mkorpershoek@baylibre.com> wrote:
>
> Hi Kai-Heng,
[snipped]
> Thank you for your help. Sorry I did not post the logs previously.
>
> dmesg: https://pastebin.com/tpWDNyQr
> ftrace on btmtksdio: https://pastebin.com/jmhvmwUw
Seems like btmtksdio needs shudown() to be called before flush().
Since the order was there for a very long time, changing the calling
order indeed can break what driver expects.
Can you please test the following patch:
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 2560ed2f144d..a61e610a400c 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
aosp_do_close(hdev);
msft_do_close(hdev);
+ if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
+ !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
+ test_bit(HCI_UP, &hdev->flags)) {
+ /* Execute vendor specific shutdown routine */
+ if (hdev->shutdown)
+ hdev->shutdown(hdev);
+ }
+
if (hdev->flush)
hdev->flush(hdev);
@@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
clear_bit(HCI_INIT, &hdev->flags);
}
- if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
- !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
- test_bit(HCI_UP, &hdev->flags)) {
- /* Execute vendor specific shutdown routine */
- if (hdev->shutdown)
- hdev->shutdown(hdev);
- }
-
/* flush cmd work */
flush_work(&hdev->cmd_work);
Kai-Heng
>
> Mattijs
> >
> > Kai-Heng
> >
> >>
> >> Thanks,
> >> Mattijs Korpershoek
> >>
> >>
> >> >
> >> > Regards
> >> >
> >> > Marcel
^ permalink raw reply related [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
[not found] ` <20210802030538.2023-1-hdanton@sina.com>
@ 2021-08-03 6:45 ` Kai-Heng Feng
[not found] ` <20210803074722.2383-1-hdanton@sina.com>
2021-08-05 6:12 ` Hsin-Yi Wang
0 siblings, 2 replies; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-03 6:45 UTC (permalink / raw)
To: Hillf Danton
Cc: Marcel Holtmann, Johan Hedberg, Mattijs Korpershoek,
Luiz Augusto von Dentz,
bluez mailin list (linux-bluetooth@vger.kernel.org),
Linux Netdev List, LKML
On Mon, Aug 2, 2021 at 11:05 AM Hillf Danton <hdanton@sina.com> wrote:
>
> On Fri, 14 May 2021 15:14:52 +0800 Kai-Heng Feng wrote:
> > Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
> > stops working:
> > [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
> > [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
> > [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> > [ 545.660350] usb 3-10: device descriptor read/64, error -110
> > [ 561.283530] usb 3-10: device descriptor read/64, error -110
> > [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> > [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
> > [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
> > [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> > [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
> > [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> >
> > Or kernel panics because other workqueues already freed skb:
> > [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
> > [ 2048.663775] #PF: supervisor read access in kernel mode
> > [ 2048.663779] #PF: error_code(0x0000) - not-present page
> > [ 2048.663782] PGD 0 P4D 0
> > [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
> > [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
> > [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
> > [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
> > [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
> > 07 83 f8 01
> > [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
> > [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
> > [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
> > [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
> > [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
> > [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
> > [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
> > [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
> > [ 2048.663856] PKRU: 55555554
> > [ 2048.663859] Call Trace:
> > [ 2048.663865] ? skb_release_head_state+0x5e/0x80
> > [ 2048.663873] kfree_skb+0x2f/0xb0
> > [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
> > [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
> > [ 2048.663954] ? __cond_resched+0x1a/0x50
> > [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
> > [ 2048.664007] rfkill_set_block+0x98/0x170
> > [ 2048.664016] rfkill_fop_write+0x136/0x1e0
> > [ 2048.664022] vfs_write+0xc7/0x260
> > [ 2048.664030] ksys_write+0xb1/0xe0
> > [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
> > [ 2048.664042] __x64_sys_write+0x1a/0x20
> > [ 2048.664048] do_syscall_64+0x40/0xb0
> > [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > [ 2048.664060] RIP: 0033:0x7fe02ac23c27
> > [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> > [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> > [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
> > [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
> > [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
> > [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
> > [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
> >
> > So move the shutdown callback to a place where workqueues are either
> > flushed or cancelled to resolve the issue.
> >
> > Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> > ---
> > v2:
> > - Rebased on bluetooth-next.
> >
> > net/bluetooth/hci_core.c | 16 ++++++++--------
> > 1 file changed, 8 insertions(+), 8 deletions(-)
> >
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index 7baf93eda936..6eedf334f943 100644
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -1716,14 +1716,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> >
> > BT_DBG("%s %p", hdev->name, hdev);
> >
> > - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > - test_bit(HCI_UP, &hdev->flags)) {
> > - /* Execute vendor specific shutdown routine */
> > - if (hdev->shutdown)
> > - hdev->shutdown(hdev);
> > - }
> > -
> > cancel_delayed_work(&hdev->power_off);
> > cancel_delayed_work(&hdev->ncmd_timer);
> >
> > @@ -1801,6 +1793,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > clear_bit(HCI_INIT, &hdev->flags);
> > }
> >
> > + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > + test_bit(HCI_UP, &hdev->flags)) {
> > + /* Execute vendor specific shutdown routine */
> > + if (hdev->shutdown)
> > + hdev->shutdown(hdev);
> > + }
> > +
> > /* flush cmd work */
> > flush_work(&hdev->cmd_work);
> >
> > --
> > 2.30.2
>
> btusb_shutdown_intel_new
> __hci_cmd_sync(hdev, HCI_OP_RESET, 0, NULL, HCI_INIT_TIMEOUT);
> __hci_cmd_sync_ev(hdev, opcode, plen, param, 0, timeout);
> hci_req_run_skb(&req, hci_req_sync_complete);
>
> hci_req_sync_complete
> if (skb)
> hdev->req_skb = skb_get(skb);
>
> Given the skb_get in hci_req_sync_complete makes it safe to free skb on
> driver side, I doubt this patch is the correct fix as it is.
Some workqueues are still active.
The shutdown() should be called at least after hci_request_cancel_all().
Kai-Heng
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-03 6:42 ` Kai-Heng Feng
@ 2021-08-03 8:21 ` Mattijs Korpershoek
2021-08-04 14:42 ` Kai-Heng Feng
0 siblings, 1 reply; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-08-03 8:21 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> Hi Mattijs,
>
> On Fri, Jul 30, 2021 at 7:40 PM Mattijs Korpershoek
> <mkorpershoek@baylibre.com> wrote:
>>
>> Hi Kai-Heng,
>
> [snipped]
>
>> Thank you for your help. Sorry I did not post the logs previously.
>>
>> dmesg: https://pastebin.com/tpWDNyQr
>> ftrace on btmtksdio: https://pastebin.com/jmhvmwUw
>
> Seems like btmtksdio needs shudown() to be called before flush().
> Since the order was there for a very long time, changing the calling
> order indeed can break what driver expects.
> Can you please test the following patch:
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index 2560ed2f144d..a61e610a400c 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> aosp_do_close(hdev);
> msft_do_close(hdev);
>
> + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> + test_bit(HCI_UP, &hdev->flags)) {
> + /* Execute vendor specific shutdown routine */
> + if (hdev->shutdown)
> + hdev->shutdown(hdev);
> + }
> +
> if (hdev->flush)
> hdev->flush(hdev);
>
> @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> clear_bit(HCI_INIT, &hdev->flags);
> }
>
> - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> - test_bit(HCI_UP, &hdev->flags)) {
> - /* Execute vendor specific shutdown routine */
> - if (hdev->shutdown)
> - hdev->shutdown(hdev);
> - }
> -
> /* flush cmd work */
> flush_work(&hdev->cmd_work);
Thanks for the patch and your help.
I've tried it, but it seems that it does not improve for me.
I'm still observing:
i500-pumpkin login: root
root@i500-pumpkin:~# hciconfig hci0 up
Can't init device hci0: Connection timed out (110)
Logs for this session:
dmesg: https://pastebin.com/iAFk5Tzi
ftrace: https://pastebin.com/kEMWSYrE
>
> Kai-Heng
>
>>
>> Mattijs
>> >
>> > Kai-Heng
>> >
>> >>
>> >> Thanks,
>> >> Mattijs Korpershoek
>> >>
>> >>
>> >> >
>> >> > Regards
>> >> >
>> >> > Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
[not found] ` <20210803074722.2383-1-hdanton@sina.com>
@ 2021-08-04 14:35 ` Kai-Heng Feng
[not found] ` <20210805030024.2603-1-hdanton@sina.com>
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-04 14:35 UTC (permalink / raw)
To: Hillf Danton
Cc: Marcel Holtmann, Johan Hedberg, Mattijs Korpershoek,
Luiz Augusto von Dentz,
bluez mailin list (linux-bluetooth@vger.kernel.org),
Linux Netdev List, LKML
On Tue, Aug 3, 2021 at 3:47 PM Hillf Danton <hdanton@sina.com> wrote:
>
> On Tue, 3 Aug 2021 14:45:07 +0800 Kai-Heng Feng wrote:
> >On Mon, Aug 2, 2021 at 11:05 AM Hillf Danton <hdanton@sina.com> wrote:
> >>
> >> Given the skb_get in hci_req_sync_complete makes it safe to free skb on
> >> driver side, I doubt this patch is the correct fix as it is.
> >
> >Some workqueues are still active.
> >The shutdown() should be called at least after hci_request_cancel_all().
>
> What is muddy then is how active workqueues prevent skb_get from protecting
> kfree_skb. Can you spot what workqueue it is?
I managed to reproduce the issue with another kernel splat:
------------[ cut here ]------------
kernel BUG at mm/slub.c:321!
invalid opcode: 0000 [#1] SMP NOPTI
CPU: 2 PID: 2208 Comm: kworker/u9:3 Not tainted 5.14.0-rc4+ #16
Hardware name: HP HP ProBook 650 G8 Notebook PC/87ED, BIOS T74 Ver.
01.03.04 01/07/2021
Workqueue: hci0 discov_update [bluetooth]
RIP: 0010:__slab_free+0x20c/0x3a0
Code: 00 44 0f b6 54 24 1a 8b 74 24 14 44 0f b6 4c 24 1b 44 8b 44 24
1c 48 89 44 24 08 48 8b 54 24 20 48 8b 7c 24 28 e9 ad fe ff ff <0f> 0b
49 3b 54 24 28 0f 85 6b ff ff ff 49 89 5c 24 20 49 89 4c 24
RSP: 0018:ffffaa0e4164fc50 EFLAGS: 00010246
RAX: ffff9cc9a217e668 RBX: ffff9cc9a217e600 RCX: ffff9cc9a217e600
RDX: 000000008010000e RSI: ffffd09044885f80 RDI: ffff9cc980e96500
RBP: ffffaa0e4164fd00 R08: 0000000000000001 R09: ffffffff885b3a4e
R10: ffff9cc999aab800 R11: ffff9cc9a217e600 R12: ffffd09044885f80
R13: ffff9cc9a217e600 R14: ffff9cc980e96500 R15: ffff9cc9a217e600
FS: 0000000000000000(0000) GS:ffff9cca2b900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffe164d5b98 CR3: 000000013f410002 CR4: 0000000000770ee0
PKRU: 55555554
Call Trace:
? psi_task_switch+0xc3/0x1e0
? __switch_to_asm+0x36/0x70
? skb_free_head+0x67/0x80
kmem_cache_free+0x370/0x3d0
? kfree_skbmem+0x4e/0x90
kfree_skbmem+0x4e/0x90
kfree_skb+0x47/0xb0
__hci_req_sync+0x134/0x2a0 [bluetooth]
? wait_woken+0x70/0x70
discov_update+0x2ae/0x310 [bluetooth]
process_one_work+0x21d/0x3c0
worker_thread+0x53/0x420
? process_one_work+0x3c0/0x3c0
kthread+0x127/0x150
? set_kthread_struct+0x50/0x50
ret_from_fork+0x1f/0x30
Modules linked in: rfcomm cmac algif_hash algif_skcipher af_alg bnep
nls_iso8859_1 snd_soc_skl_hda_dsp snd_soc_intel_hda_dsp_common
snd_soc_hdac_hdmi snd_hda_codec_hdmi snd_hda_codec_realtek
snd_hda_codec_generic snd_soc_dmic snd_sof_pci_intel_tgl
snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_pci snd_sof
snd_sof_xtensa_dsp snd_sof_intel_hda snd_hda_ext_core
snd_soc_acpi_intel_match snd_soc_acpi ledtrig_audio snd_soc_core
snd_hda_intel snd_intel_dspcfg snd_hda_codec snd_hwdep snd_hda_core
snd_pcm snd_seq i915 snd_seq_device snd_timer hp_wmi intel_tcc_cooling
x86_pkg_temp_thermal intel_powerclamp i2c_algo_bit coretemp joydev
kvm_intel ttm mei_hdcp intel_rapl_msr platform_profile wmi_bmof kvm
uvcvideo crct10dif_pclmul btusb videobuf2_vmalloc videobuf2_memops
drm_kms_helper btrtl videobuf2_v4l2 crc32_pclmul btbcm
ghash_clmulni_intel input_leds videobuf2_common btintel snd videodev
syscopyarea sysfillrect sysimgblt aesni_intel mc serio_raw fb_sys_fops
bluetooth crypto_simd
cec cryptd intel_cstate ecdh_generic efi_pstore ecc rc_core
hid_multitouch processor_thermal_device_pci_legacy mei_me
intel_soc_dts_iosf processor_thermal_device mei soundcore
processor_thermal_rfim ee1004 processor_thermal_mbox
processor_thermal_rapl intel_pmt_telemetry intel_rapl_common
intel_pmt_class ucsi_acpi typec_ucsi typec wmi soc_button_array
int3403_thermal int340x_thermal_zone video int3400_thermal
acpi_thermal_rel acpi_pad mac_hid intel_hid sparse_keymap sch_fq_codel
msr parport_pc ppdev lp drm parport ip_tables x_tables autofs4
hid_generic nvme nvme_core intel_lpss_pci e1000e intel_lpss i2c_i801
idma64 i2c_smbus xhci_pci xhci_pci_renesas vmd intel_pmt i2c_hid_acpi
i2c_hid hid pinctrl_tigerlake
---[ end trace c09445d4697039ed ]---
So hci_request_cancel_all() -> cancel_work_sync(&hdev->discov_update)
and can prevent the race from happening.
And the kernel splat is just one symptom of the issue, most of the
time it's just "Bluetooth: hci0: HCI reset during shutdown failed" in
dmesg.
Kai-Heng
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-03 8:21 ` Mattijs Korpershoek
@ 2021-08-04 14:42 ` Kai-Heng Feng
2021-08-05 6:55 ` Mattijs Korpershoek
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-04 14:42 UTC (permalink / raw)
To: Mattijs Korpershoek
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
On Tue, Aug 3, 2021 at 4:21 PM Mattijs Korpershoek
<mkorpershoek@baylibre.com> wrote:
>
> Hi Kai-Heng,
>
> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
>
> > Hi Mattijs,
> >
> > On Fri, Jul 30, 2021 at 7:40 PM Mattijs Korpershoek
> > <mkorpershoek@baylibre.com> wrote:
> >>
> >> Hi Kai-Heng,
> >
> > [snipped]
> >
> >> Thank you for your help. Sorry I did not post the logs previously.
> >>
> >> dmesg: https://pastebin.com/tpWDNyQr
> >> ftrace on btmtksdio: https://pastebin.com/jmhvmwUw
> >
> > Seems like btmtksdio needs shudown() to be called before flush().
> > Since the order was there for a very long time, changing the calling
> > order indeed can break what driver expects.
> > Can you please test the following patch:
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index 2560ed2f144d..a61e610a400c 100644
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > aosp_do_close(hdev);
> > msft_do_close(hdev);
> >
> > + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > + test_bit(HCI_UP, &hdev->flags)) {
> > + /* Execute vendor specific shutdown routine */
> > + if (hdev->shutdown)
> > + hdev->shutdown(hdev);
> > + }
> > +
> > if (hdev->flush)
> > hdev->flush(hdev);
> >
> > @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > clear_bit(HCI_INIT, &hdev->flags);
> > }
> >
> > - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > - test_bit(HCI_UP, &hdev->flags)) {
> > - /* Execute vendor specific shutdown routine */
> > - if (hdev->shutdown)
> > - hdev->shutdown(hdev);
> > - }
> > -
> > /* flush cmd work */
> > flush_work(&hdev->cmd_work);
>
> Thanks for the patch and your help.
> I've tried it, but it seems that it does not improve for me.
> I'm still observing:
>
> i500-pumpkin login: root
> root@i500-pumpkin:~# hciconfig hci0 up
> Can't init device hci0: Connection timed out (110)
>
> Logs for this session:
> dmesg: https://pastebin.com/iAFk5Tzi
> ftrace: https://pastebin.com/kEMWSYrE
Thanks for the testing!
What about moving the shutdown() part right after hci_req_sync_lock()
so tx/rx can still work:
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 2560ed2f144d4..be3113fb7d4b0 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -1727,6 +1727,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
hci_request_cancel_all(hdev);
hci_req_sync_lock(hdev);
+ if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
+ !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
+ test_bit(HCI_UP, &hdev->flags)) {
+ /* Execute vendor specific shutdown routine */
+ if (hdev->shutdown)
+ hdev->shutdown(hdev);
+ }
+
if (!test_and_clear_bit(HCI_UP, &hdev->flags)) {
cancel_delayed_work_sync(&hdev->cmd_timer);
hci_req_sync_unlock(hdev);
@@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
clear_bit(HCI_INIT, &hdev->flags);
}
- if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
- !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
- test_bit(HCI_UP, &hdev->flags)) {
- /* Execute vendor specific shutdown routine */
- if (hdev->shutdown)
- hdev->shutdown(hdev);
- }
-
/* flush cmd work */
flush_work(&hdev->cmd_work);
>
>
> >
> > Kai-Heng
> >
> >>
> >> Mattijs
> >> >
> >> > Kai-Heng
> >> >
> >> >>
> >> >> Thanks,
> >> >> Mattijs Korpershoek
> >> >>
> >> >>
> >> >> >
> >> >> > Regards
> >> >> >
> >> >> > Marcel
^ permalink raw reply related [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
[not found] ` <20210805030024.2603-1-hdanton@sina.com>
@ 2021-08-05 3:44 ` Kai-Heng Feng
[not found] ` <20210805063536.2698-1-hdanton@sina.com>
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-05 3:44 UTC (permalink / raw)
To: Hillf Danton
Cc: Marcel Holtmann, Johan Hedberg, Mattijs Korpershoek,
Luiz Augusto von Dentz, Bluez, LKML
On Thu, Aug 5, 2021 at 11:00 AM Hillf Danton <hdanton@sina.com> wrote:
>
> On Wed, 4 Aug 2021 22:35:43 +0800 Kai-Heng Feng wrote:
> >On Tue, Aug 3, 2021 at 3:47 PM Hillf Danton <hdanton@sina.com> wrote:
> >>
> >> On Tue, 3 Aug 2021 14:45:07 +0800 Kai-Heng Feng wrote:
> >> >On Mon, Aug 2, 2021 at 11:05 AM Hillf Danton <hdanton@sina.com> wrote:
> >> >>
> >> >> Given the skb_get in hci_req_sync_complete makes it safe to free skb on
> >> >> driver side, I doubt this patch is the correct fix as it is.
> >> >
> >> >Some workqueues are still active.
> >> >The shutdown() should be called at least after hci_request_cancel_all().
> >>
> >> What is muddy then is how active workqueues prevent skb_get from protecting
> >> kfree_skb. Can you spot what workqueue it is?
> >
> >I managed to reproduce the issue with another kernel splat:
> >------------[ cut here ]------------
> >kernel BUG at mm/slub.c:321!
> >invalid opcode: 0000 [#1] SMP NOPTI
> >CPU: 2 PID: 2208 Comm: kworker/u9:3 Not tainted 5.14.0-rc4+ #16
> >Hardware name: HP HP ProBook 650 G8 Notebook PC/87ED, BIOS T74 Ver.
> >01.03.04 01/07/2021
> >Workqueue: hci0 discov_update [bluetooth]
> >RIP: 0010:__slab_free+0x20c/0x3a0
> >Code: 00 44 0f b6 54 24 1a 8b 74 24 14 44 0f b6 4c 24 1b 44 8b 44 24
> >1c 48 89 44 24 08 48 8b 54 24 20 48 8b 7c 24 28 e9 ad fe ff ff <0f> 0b
> >49 3b 54 24 28 0f 85 6b ff ff ff 49 89 5c 24 20 49 89 4c 24
> >RSP: 0018:ffffaa0e4164fc50 EFLAGS: 00010246
> >RAX: ffff9cc9a217e668 RBX: ffff9cc9a217e600 RCX: ffff9cc9a217e600
> >RDX: 000000008010000e RSI: ffffd09044885f80 RDI: ffff9cc980e96500
> >RBP: ffffaa0e4164fd00 R08: 0000000000000001 R09: ffffffff885b3a4e
> >R10: ffff9cc999aab800 R11: ffff9cc9a217e600 R12: ffffd09044885f80
> >R13: ffff9cc9a217e600 R14: ffff9cc980e96500 R15: ffff9cc9a217e600
> >FS: 0000000000000000(0000) GS:ffff9cca2b900000(0000) knlGS:0000000000000000
> >CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >CR2: 00007ffe164d5b98 CR3: 000000013f410002 CR4: 0000000000770ee0
> >PKRU: 55555554
> >Call Trace:
> > ? psi_task_switch+0xc3/0x1e0
> > ? __switch_to_asm+0x36/0x70
> > ? skb_free_head+0x67/0x80
> > kmem_cache_free+0x370/0x3d0
> > ? kfree_skbmem+0x4e/0x90
> > kfree_skbmem+0x4e/0x90
> > kfree_skb+0x47/0xb0
> > __hci_req_sync+0x134/0x2a0 [bluetooth]
> > ? wait_woken+0x70/0x70
> > discov_update+0x2ae/0x310 [bluetooth]
> > process_one_work+0x21d/0x3c0
> > worker_thread+0x53/0x420
> > ? process_one_work+0x3c0/0x3c0
> > kthread+0x127/0x150
> > ? set_kthread_struct+0x50/0x50
> > ret_from_fork+0x1f/0x30
>
> [...]
>
> >
> >So hci_request_cancel_all() -> cancel_work_sync(&hdev->discov_update)
> >and can prevent the race from happening.
>
> Given
>
> __hci_req_sync
> err = hci_req_run_skb(&req, hci_req_sync_complete);
> kfree_skb(hdev->req_skb);
>
> hci_req_sync_complete
> if (skb)
> hdev->req_skb = skb_get(skb);
>
> once more skb_get makes the above race hard to understand, though it should
> better check error before freeing skb there to avoid blind free.
>
> >
> >And the kernel splat is just one symptom of the issue, most of the
>
> It fails to support your reasoning so far.
How? Most of the time the BT controller can't be brought up again
after shutdown(), and we need to stop other activities before that.
What other reasoning is expected?
Kai-Heng
>
> >time it's just "Bluetooth: hci0: HCI reset during shutdown failed" in
> >dmesg.
> >
> >Kai-Heng
>
>
> +++ x/net/bluetooth/hci_request.c
> @@ -257,8 +257,10 @@ int __hci_req_sync(struct hci_dev *hdev,
> break;
> }
>
> - kfree_skb(hdev->req_skb);
> - hdev->req_skb = NULL;
> + if (!err) {
> + kfree_skb(hdev->req_skb);
> + hdev->req_skb = NULL;
> + }
> hdev->req_status = hdev->req_result = 0;
>
> bt_dev_dbg(hdev, "end: err %d", err);
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-03 6:45 ` Kai-Heng Feng
[not found] ` <20210803074722.2383-1-hdanton@sina.com>
@ 2021-08-05 6:12 ` Hsin-Yi Wang
[not found] ` <20210805070114.2803-1-hdanton@sina.com>
1 sibling, 1 reply; 20+ messages in thread
From: Hsin-Yi Wang @ 2021-08-05 6:12 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Hillf Danton, Marcel Holtmann, Johan Hedberg,
Mattijs Korpershoek, Luiz Augusto von Dentz,
bluez mailin list (linux-bluetooth@vger.kernel.org),
Linux Netdev List, LKML
On Tue, Aug 3, 2021 at 2:45 PM Kai-Heng Feng
<kai.heng.feng@canonical.com> wrote:
>
> On Mon, Aug 2, 2021 at 11:05 AM Hillf Danton <hdanton@sina.com> wrote:
> >
> > On Fri, 14 May 2021 15:14:52 +0800 Kai-Heng Feng wrote:
> > > Rfkill block and unblock Intel USB Bluetooth [8087:0026] may make it
> > > stops working:
> > > [ 509.691509] Bluetooth: hci0: HCI reset during shutdown failed
> > > [ 514.897584] Bluetooth: hci0: MSFT filter_enable is already on
> > > [ 530.044751] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> > > [ 545.660350] usb 3-10: device descriptor read/64, error -110
> > > [ 561.283530] usb 3-10: device descriptor read/64, error -110
> > > [ 561.519682] usb 3-10: reset full-speed USB device number 5 using xhci_hcd
> > > [ 566.686650] Bluetooth: hci0: unexpected event for opcode 0x0500
> > > [ 568.752452] Bluetooth: hci0: urb 0000000096cd309b failed to resubmit (113)
> > > [ 578.797955] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> > > [ 586.286565] Bluetooth: hci0: urb 00000000c522f633 failed to resubmit (113)
> > > [ 596.215302] Bluetooth: hci0: Failed to read MSFT supported features (-110)
> > >
> > > Or kernel panics because other workqueues already freed skb:
> > > [ 2048.663763] BUG: kernel NULL pointer dereference, address: 0000000000000000
> > > [ 2048.663775] #PF: supervisor read access in kernel mode
> > > [ 2048.663779] #PF: error_code(0x0000) - not-present page
> > > [ 2048.663782] PGD 0 P4D 0
> > > [ 2048.663787] Oops: 0000 [#1] SMP NOPTI
> > > [ 2048.663793] CPU: 3 PID: 4491 Comm: rfkill Tainted: G W 5.13.0-rc1-next-20210510+ #20
> > > [ 2048.663799] Hardware name: HP HP EliteBook 850 G8 Notebook PC/8846, BIOS T76 Ver. 01.01.04 12/02/2020
> > > [ 2048.663801] RIP: 0010:__skb_ext_put+0x6/0x50
> > > [ 2048.663814] Code: 8b 1b 48 85 db 75 db 5b 41 5c 5d c3 be 01 00 00 00 e8 de 13 c0 ff eb e7 be 02 00 00 00 e8 d2 13 c0 ff eb db 0f 1f 44 00 00 55 <8b> 07 48 89 e5 83 f8 01 74 14 b8 ff ff ff ff f0 0f c1
> > > 07 83 f8 01
> > > [ 2048.663819] RSP: 0018:ffffc1d105b6fd80 EFLAGS: 00010286
> > > [ 2048.663824] RAX: 0000000000000000 RBX: ffff9d9ac5649000 RCX: 0000000000000000
> > > [ 2048.663827] RDX: ffffffffc0d1daf6 RSI: 0000000000000206 RDI: 0000000000000000
> > > [ 2048.663830] RBP: ffffc1d105b6fd98 R08: 0000000000000001 R09: ffff9d9ace8ceac0
> > > [ 2048.663834] R10: ffff9d9ace8ceac0 R11: 0000000000000001 R12: ffff9d9ac5649000
> > > [ 2048.663838] R13: 0000000000000000 R14: 00007ffe0354d650 R15: 0000000000000000
> > > [ 2048.663843] FS: 00007fe02ab19740(0000) GS:ffff9d9e5f8c0000(0000) knlGS:0000000000000000
> > > [ 2048.663849] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [ 2048.663853] CR2: 0000000000000000 CR3: 0000000111a52004 CR4: 0000000000770ee0
> > > [ 2048.663856] PKRU: 55555554
> > > [ 2048.663859] Call Trace:
> > > [ 2048.663865] ? skb_release_head_state+0x5e/0x80
> > > [ 2048.663873] kfree_skb+0x2f/0xb0
> > > [ 2048.663881] btusb_shutdown_intel_new+0x36/0x60 [btusb]
> > > [ 2048.663905] hci_dev_do_close+0x48c/0x5e0 [bluetooth]
> > > [ 2048.663954] ? __cond_resched+0x1a/0x50
> > > [ 2048.663962] hci_rfkill_set_block+0x56/0xa0 [bluetooth]
> > > [ 2048.664007] rfkill_set_block+0x98/0x170
> > > [ 2048.664016] rfkill_fop_write+0x136/0x1e0
> > > [ 2048.664022] vfs_write+0xc7/0x260
> > > [ 2048.664030] ksys_write+0xb1/0xe0
> > > [ 2048.664035] ? exit_to_user_mode_prepare+0x37/0x1c0
> > > [ 2048.664042] __x64_sys_write+0x1a/0x20
> > > [ 2048.664048] do_syscall_64+0x40/0xb0
> > > [ 2048.664055] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > > [ 2048.664060] RIP: 0033:0x7fe02ac23c27
> > > [ 2048.664066] Code: 0d 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> > > [ 2048.664070] RSP: 002b:00007ffe0354d638 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> > > [ 2048.664075] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fe02ac23c27
> > > [ 2048.664078] RDX: 0000000000000008 RSI: 00007ffe0354d650 RDI: 0000000000000003
> > > [ 2048.664081] RBP: 0000000000000000 R08: 0000559b05998440 R09: 0000559b05998440
> > > [ 2048.664084] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
> > > [ 2048.664086] R13: 0000000000000000 R14: ffffffff00000000 R15: 00000000ffffffff
> > >
> > > So move the shutdown callback to a place where workqueues are either
> > > flushed or cancelled to resolve the issue.
> > >
> > > Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> > > ---
> > > v2:
> > > - Rebased on bluetooth-next.
> > >
> > > net/bluetooth/hci_core.c | 16 ++++++++--------
> > > 1 file changed, 8 insertions(+), 8 deletions(-)
> > >
> > > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > > index 7baf93eda936..6eedf334f943 100644
> > > --- a/net/bluetooth/hci_core.c
> > > +++ b/net/bluetooth/hci_core.c
> > > @@ -1716,14 +1716,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > >
> > > BT_DBG("%s %p", hdev->name, hdev);
> > >
> > > - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > > - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > > - test_bit(HCI_UP, &hdev->flags)) {
> > > - /* Execute vendor specific shutdown routine */
> > > - if (hdev->shutdown)
> > > - hdev->shutdown(hdev);
> > > - }
> > > -
> > > cancel_delayed_work(&hdev->power_off);
> > > cancel_delayed_work(&hdev->ncmd_timer);
> > >
> > > @@ -1801,6 +1793,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > > clear_bit(HCI_INIT, &hdev->flags);
> > > }
> > >
> > > + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > > + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > > + test_bit(HCI_UP, &hdev->flags)) {
> > > + /* Execute vendor specific shutdown routine */
> > > + if (hdev->shutdown)
> > > + hdev->shutdown(hdev);
> > > + }
> > > +
> > > /* flush cmd work */
> > > flush_work(&hdev->cmd_work);
> > >
> > > --
> > > 2.30.2
> >
> > btusb_shutdown_intel_new
> > __hci_cmd_sync(hdev, HCI_OP_RESET, 0, NULL, HCI_INIT_TIMEOUT);
> > __hci_cmd_sync_ev(hdev, opcode, plen, param, 0, timeout);
> > hci_req_run_skb(&req, hci_req_sync_complete);
> >
> > hci_req_sync_complete
> > if (skb)
> > hdev->req_skb = skb_get(skb);
> >
> > Given the skb_get in hci_req_sync_complete makes it safe to free skb on
> > driver side, I doubt this patch is the correct fix as it is.
>
> Some workqueues are still active.
> The shutdown() should be called at least after hci_request_cancel_all().
>
Hello,
The original patch 60789afc02f592b8d91217b60930e7a76271ae07
("Bluetooth: Shutdown controller after workqueues are flushed or
cancelled") is causing the tx fail when downloading fw on mediatek
mt8183 device using QCA bluetooth:
[ 225.205061] Bluetooth: qca_download_firmware() hci0: QCA
Downloading qca/rampatch_00440302.bin
[ 227.252653] Bluetooth: hci_cmd_timeout() hci0: command 0xfc00 tx timeout
...
follows by a lot of:
[ 223.604971] Bluetooth: qca_recv() hci0: Frame reassembly failed (-84)
[ 223.605027] Bluetooth: qca_recv() hci0: Frame reassembly failed (-84)
After applying the fixup to allow tx, the issue is solved.
> Kai-Heng
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-04 14:42 ` Kai-Heng Feng
@ 2021-08-05 6:55 ` Mattijs Korpershoek
2021-08-05 15:50 ` Kai-Heng Feng
0 siblings, 1 reply; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-08-05 6:55 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
Thanks for your patch,
Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> On Tue, Aug 3, 2021 at 4:21 PM Mattijs Korpershoek
> <mkorpershoek@baylibre.com> wrote:
>>
>> Hi Kai-Heng,
>>
>> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
>>
>> > Hi Mattijs,
>> >
>> > On Fri, Jul 30, 2021 at 7:40 PM Mattijs Korpershoek
>> > <mkorpershoek@baylibre.com> wrote:
>> >>
>> >> Hi Kai-Heng,
>> >
>> > [snipped]
>> >
>> >> Thank you for your help. Sorry I did not post the logs previously.
>> >>
>> >> dmesg: https://pastebin.com/tpWDNyQr
>> >> ftrace on btmtksdio: https://pastebin.com/jmhvmwUw
>> >
>> > Seems like btmtksdio needs shudown() to be called before flush().
>> > Since the order was there for a very long time, changing the calling
>> > order indeed can break what driver expects.
>> > Can you please test the following patch:
>> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
>> > index 2560ed2f144d..a61e610a400c 100644
>> > --- a/net/bluetooth/hci_core.c
>> > +++ b/net/bluetooth/hci_core.c
>> > @@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
>> > aosp_do_close(hdev);
>> > msft_do_close(hdev);
>> >
>> > + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
>> > + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
>> > + test_bit(HCI_UP, &hdev->flags)) {
>> > + /* Execute vendor specific shutdown routine */
>> > + if (hdev->shutdown)
>> > + hdev->shutdown(hdev);
>> > + }
>> > +
>> > if (hdev->flush)
>> > hdev->flush(hdev);
>> >
>> > @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
>> > clear_bit(HCI_INIT, &hdev->flags);
>> > }
>> >
>> > - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
>> > - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
>> > - test_bit(HCI_UP, &hdev->flags)) {
>> > - /* Execute vendor specific shutdown routine */
>> > - if (hdev->shutdown)
>> > - hdev->shutdown(hdev);
>> > - }
>> > -
>> > /* flush cmd work */
>> > flush_work(&hdev->cmd_work);
>>
>> Thanks for the patch and your help.
>> I've tried it, but it seems that it does not improve for me.
>> I'm still observing:
>>
>> i500-pumpkin login: root
>> root@i500-pumpkin:~# hciconfig hci0 up
>> Can't init device hci0: Connection timed out (110)
>>
>> Logs for this session:
>> dmesg: https://pastebin.com/iAFk5Tzi
>> ftrace: https://pastebin.com/kEMWSYrE
>
> Thanks for the testing!
> What about moving the shutdown() part right after hci_req_sync_lock()
> so tx/rx can still work:
>
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index 2560ed2f144d4..be3113fb7d4b0 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -1727,6 +1727,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> hci_request_cancel_all(hdev);
> hci_req_sync_lock(hdev);
>
> + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> + test_bit(HCI_UP, &hdev->flags)) {
> + /* Execute vendor specific shutdown routine */
> + if (hdev->shutdown)
> + hdev->shutdown(hdev);
> + }
> +
> if (!test_and_clear_bit(HCI_UP, &hdev->flags)) {
> cancel_delayed_work_sync(&hdev->cmd_timer);
> hci_req_sync_unlock(hdev);
> @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> clear_bit(HCI_INIT, &hdev->flags);
> }
>
> - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> - test_bit(HCI_UP, &hdev->flags)) {
> - /* Execute vendor specific shutdown routine */
> - if (hdev->shutdown)
> - hdev->shutdown(hdev);
> - }
> -
> /* flush cmd work */
> flush_work(&hdev->cmd_work);
I confirm this diff works for me:
root@i500-pumpkin:~# hciconfig hci0 up
root@i500-pumpkin:~# hciconfig hci0 down
root@i500-pumpkin:~# hciconfig hci0 up
root@i500-pumpkin:~# hciconfig hci0
hci0: Type: Primary Bus: SDIO
BD Address: 00:0C:E7:55:FF:12 ACL MTU: 1021:8 SCO MTU: 244:4
UP RUNNING
RX bytes:11268 acl:0 sco:0 events:829 errors:0
TX bytes:182569 acl:0 sco:0 commands:829 errors:0
root@i500-pumpkin:~# hcitool scan
Scanning ...
<redacted> Pixel 3 XL
Tested-by: Mattijs Korpershoek <mkorpershoek@baylibre.com>
>
>
>
>
>
>>
>>
>> >
>> > Kai-Heng
>> >
>> >>
>> >> Mattijs
>> >> >
>> >> > Kai-Heng
>> >> >
>> >> >>
>> >> >> Thanks,
>> >> >> Mattijs Korpershoek
>> >> >>
>> >> >>
>> >> >> >
>> >> >> > Regards
>> >> >> >
>> >> >> > Marcel
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
[not found] ` <20210805070114.2803-1-hdanton@sina.com>
@ 2021-08-05 7:04 ` Hsin-Yi Wang
0 siblings, 0 replies; 20+ messages in thread
From: Hsin-Yi Wang @ 2021-08-05 7:04 UTC (permalink / raw)
To: Hillf Danton
Cc: Kai-Heng Feng, Marcel Holtmann, Mattijs Korpershoek, Bluez, LKML
On Thu, Aug 5, 2021 at 3:01 PM Hillf Danton <hdanton@sina.com> wrote:
>
> On Thu, 5 Aug 2021 14:12:10 +0800 Hsin-Yi Wang wrote:
> >
> >The original patch 60789afc02f592b8d91217b60930e7a76271ae07
> >("Bluetooth: Shutdown controller after workqueues are flushed or
> >cancelled") is causing the tx fail when downloading fw on mediatek
> >mt8183 device using QCA bluetooth:
>
> Want to know if reverting 60789afc02f59 is a cure.
Reverting 60789afc02f592b8d91217b60930e7a76271ae07 can also fixed the issue.
>
> >
> >[ 225.205061] Bluetooth: qca_download_firmware() hci0: QCA
> >Downloading qca/rampatch_00440302.bin
> >[ 227.252653] Bluetooth: hci_cmd_timeout() hci0: command 0xfc00 tx timeout
> >...
> >follows by a lot of:
> >[ 223.604971] Bluetooth: qca_recv() hci0: Frame reassembly failed (-84)
> >[ 223.605027] Bluetooth: qca_recv() hci0: Frame reassembly failed (-84)
> >
> >After applying the fixup to allow tx, the issue is solved.
>
> Feel free to specify the fixup and its link to 60789afc02f59.
The fixup is pasted by Kai-Heng here:
https://lkml.org/lkml/2021/8/3/103
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
[not found] ` <20210805063536.2698-1-hdanton@sina.com>
@ 2021-08-05 7:19 ` Kai-Heng Feng
0 siblings, 0 replies; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-05 7:19 UTC (permalink / raw)
To: Hillf Danton
Cc: Marcel Holtmann, Johan Hedberg, Mattijs Korpershoek,
Luiz Augusto von Dentz, Bluez, LKML
[snipped]
> >How? Most of the time the BT controller can't be brought up again
> >after shutdown(), and we need to stop other activities before that.
> >What other reasoning is expected?
>
> See below.
> >
> >Kai-Heng
> >
> >>
> >> >time it's just "Bluetooth: hci0: HCI reset during shutdown failed" in
> >> >dmesg.
>
> In drivers/bluetooth/btusb.c, there are three cases of
>
> bt_dev_err(hdev, "HCI reset during shutdown failed");
>
> and in btusb_shutdown_intel_new() it has nothing to do with kfree_skb()
> because of IS_ERR(skb).
No, kfree_skb() doesn't gets called in this case. But when that
happens the BT controller won't work anymore.
>
> Feel free to specify why an skb error links to the race you are trying to fix.
The race here is that the btusb_shutdown_intel_new() is trying to
reset the controller while other works like scanning or discovering
are still underway.
So the patch is to ensure that shutdown() callback is invoked after
other works are cancelled.
I think I understand what you are trying to ask, you want to know
where the double kfree_skb() race happens.
I didn't really investigate that because quiesce the other activities
then call shutdown() is the right thing to do and I haven't seen the
kernel splat since.
Kai-Heng
>
> >> >
> >> >Kai-Heng
> >>
> >>
> >> +++ x/net/bluetooth/hci_request.c
> >> @@ -257,8 +257,10 @@ int __hci_req_sync(struct hci_dev *hdev,
> >> break;
> >> }
> >>
> >> - kfree_skb(hdev->req_skb);
> >> - hdev->req_skb = NULL;
> >> + if (!err) {
> >> + kfree_skb(hdev->req_skb);
> >> + hdev->req_skb = NULL;
> >> + }
> >> hdev->req_status = hdev->req_result = 0;
> >>
> >> bt_dev_dbg(hdev, "end: err %d", err);
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-05 6:55 ` Mattijs Korpershoek
@ 2021-08-05 15:50 ` Kai-Heng Feng
2021-08-06 8:51 ` Mattijs Korpershoek
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-05 15:50 UTC (permalink / raw)
To: Mattijs Korpershoek
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Mattijs,
On Thu, Aug 5, 2021 at 2:55 PM Mattijs Korpershoek
<mkorpershoek@baylibre.com> wrote:
>
> Hi Kai-Heng,
>
> Thanks for your patch,
>
> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
>
[snipped]
> I confirm this diff works for me:
>
> root@i500-pumpkin:~# hciconfig hci0 up
> root@i500-pumpkin:~# hciconfig hci0 down
> root@i500-pumpkin:~# hciconfig hci0 up
> root@i500-pumpkin:~# hciconfig hci0
> hci0: Type: Primary Bus: SDIO
> BD Address: 00:0C:E7:55:FF:12 ACL MTU: 1021:8 SCO MTU: 244:4
> UP RUNNING
> RX bytes:11268 acl:0 sco:0 events:829 errors:0
> TX bytes:182569 acl:0 sco:0 commands:829 errors:0
>
> root@i500-pumpkin:~# hcitool scan
> Scanning ...
> <redacted> Pixel 3 XL
>
> Tested-by: Mattijs Korpershoek <mkorpershoek@baylibre.com>
I found that btmtksdio_flush() only cancels the work instead of doing
flush_work(). That probably explains why putting ->shutdown right
before ->flush doesn't work.
So can you please test the following again:
diff --git a/drivers/bluetooth/btmtksdio.c b/drivers/bluetooth/btmtksdio.c
index 9872ef18f9fea..b33c05ad2150b 100644
--- a/drivers/bluetooth/btmtksdio.c
+++ b/drivers/bluetooth/btmtksdio.c
@@ -649,9 +649,9 @@ static int btmtksdio_flush(struct hci_dev *hdev)
{
struct btmtksdio_dev *bdev = hci_get_drvdata(hdev);
- skb_queue_purge(&bdev->txq);
+ flush_work(&bdev->tx_work);
- cancel_work_sync(&bdev->tx_work);
+ skb_queue_purge(&bdev->txq);
return 0;
}
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 2560ed2f144d4..a61e610a400cb 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
aosp_do_close(hdev);
msft_do_close(hdev);
+ if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
+ !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
+ test_bit(HCI_UP, &hdev->flags)) {
+ /* Execute vendor specific shutdown routine */
+ if (hdev->shutdown)
+ hdev->shutdown(hdev);
+ }
+
if (hdev->flush)
hdev->flush(hdev);
@@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
clear_bit(HCI_INIT, &hdev->flags);
}
- if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
- !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
- test_bit(HCI_UP, &hdev->flags)) {
- /* Execute vendor specific shutdown routine */
- if (hdev->shutdown)
- hdev->shutdown(hdev);
- }
-
/* flush cmd work */
flush_work(&hdev->cmd_work);
Kai-Heng
^ permalink raw reply related [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-05 15:50 ` Kai-Heng Feng
@ 2021-08-06 8:51 ` Mattijs Korpershoek
2021-08-06 15:36 ` Kai-Heng Feng
0 siblings, 1 reply; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-08-06 8:51 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> Hi Mattijs,
>
> On Thu, Aug 5, 2021 at 2:55 PM Mattijs Korpershoek
> <mkorpershoek@baylibre.com> wrote:
>>
>> Hi Kai-Heng,
>>
>> Thanks for your patch,
>>
>> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
>>
>
> [snipped]
>
>> I confirm this diff works for me:
>>
>> root@i500-pumpkin:~# hciconfig hci0 up
>> root@i500-pumpkin:~# hciconfig hci0 down
>> root@i500-pumpkin:~# hciconfig hci0 up
>> root@i500-pumpkin:~# hciconfig hci0
>> hci0: Type: Primary Bus: SDIO
>> BD Address: 00:0C:E7:55:FF:12 ACL MTU: 1021:8 SCO MTU: 244:4
>> UP RUNNING
>> RX bytes:11268 acl:0 sco:0 events:829 errors:0
>> TX bytes:182569 acl:0 sco:0 commands:829 errors:0
>>
>> root@i500-pumpkin:~# hcitool scan
>> Scanning ...
>> <redacted> Pixel 3 XL
>>
>> Tested-by: Mattijs Korpershoek <mkorpershoek@baylibre.com>
>
> I found that btmtksdio_flush() only cancels the work instead of doing
> flush_work(). That probably explains why putting ->shutdown right
> before ->flush doesn't work.
> So can you please test the following again:
> diff --git a/drivers/bluetooth/btmtksdio.c b/drivers/bluetooth/btmtksdio.c
> index 9872ef18f9fea..b33c05ad2150b 100644
> --- a/drivers/bluetooth/btmtksdio.c
> +++ b/drivers/bluetooth/btmtksdio.c
> @@ -649,9 +649,9 @@ static int btmtksdio_flush(struct hci_dev *hdev)
> {
> struct btmtksdio_dev *bdev = hci_get_drvdata(hdev);
>
> - skb_queue_purge(&bdev->txq);
> + flush_work(&bdev->tx_work);
>
> - cancel_work_sync(&bdev->tx_work);
> + skb_queue_purge(&bdev->txq);
>
> return 0;
> }
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index 2560ed2f144d4..a61e610a400cb 100644
>
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> aosp_do_close(hdev);
> msft_do_close(hdev);
>
> + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> + test_bit(HCI_UP, &hdev->flags)) {
> + /* Execute vendor specific shutdown routine */
> + if (hdev->shutdown)
> + hdev->shutdown(hdev);
> + }
> +
> if (hdev->flush)
> hdev->flush(hdev);
>
> @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> clear_bit(HCI_INIT, &hdev->flags);
> }
>
> - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> - test_bit(HCI_UP, &hdev->flags)) {
> - /* Execute vendor specific shutdown routine */
> - if (hdev->shutdown)
> - hdev->shutdown(hdev);
> - }
> -
> /* flush cmd work */
> flush_work(&hdev->cmd_work);
I've tried this but I have the same (broken) symptoms as before.
Here are some logs of v3:
dmesg: https://pastebin.com/1x4UHkzy
ftrace: https://pastebin.com/Lm1d6AWy
Mattijs
>
> Kai-Heng
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-06 8:51 ` Mattijs Korpershoek
@ 2021-08-06 15:36 ` Kai-Heng Feng
2021-08-09 9:19 ` Mattijs Korpershoek
0 siblings, 1 reply; 20+ messages in thread
From: Kai-Heng Feng @ 2021-08-06 15:36 UTC (permalink / raw)
To: Mattijs Korpershoek
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Mattijs,
On Fri, Aug 6, 2021 at 4:51 PM Mattijs Korpershoek
<mkorpershoek@baylibre.com> wrote:
>
> Hi Kai-Heng,
>
> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
>
> > Hi Mattijs,
> >
> > On Thu, Aug 5, 2021 at 2:55 PM Mattijs Korpershoek
> > <mkorpershoek@baylibre.com> wrote:
> >>
> >> Hi Kai-Heng,
> >>
> >> Thanks for your patch,
> >>
> >> Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> >>
> >
> > [snipped]
> >
> >> I confirm this diff works for me:
> >>
> >> root@i500-pumpkin:~# hciconfig hci0 up
> >> root@i500-pumpkin:~# hciconfig hci0 down
> >> root@i500-pumpkin:~# hciconfig hci0 up
> >> root@i500-pumpkin:~# hciconfig hci0
> >> hci0: Type: Primary Bus: SDIO
> >> BD Address: 00:0C:E7:55:FF:12 ACL MTU: 1021:8 SCO MTU: 244:4
> >> UP RUNNING
> >> RX bytes:11268 acl:0 sco:0 events:829 errors:0
> >> TX bytes:182569 acl:0 sco:0 commands:829 errors:0
> >>
> >> root@i500-pumpkin:~# hcitool scan
> >> Scanning ...
> >> <redacted> Pixel 3 XL
> >>
> >> Tested-by: Mattijs Korpershoek <mkorpershoek@baylibre.com>
> >
> > I found that btmtksdio_flush() only cancels the work instead of doing
> > flush_work(). That probably explains why putting ->shutdown right
> > before ->flush doesn't work.
> > So can you please test the following again:
> > diff --git a/drivers/bluetooth/btmtksdio.c b/drivers/bluetooth/btmtksdio.c
> > index 9872ef18f9fea..b33c05ad2150b 100644
> > --- a/drivers/bluetooth/btmtksdio.c
> > +++ b/drivers/bluetooth/btmtksdio.c
> > @@ -649,9 +649,9 @@ static int btmtksdio_flush(struct hci_dev *hdev)
> > {
> > struct btmtksdio_dev *bdev = hci_get_drvdata(hdev);
> >
> > - skb_queue_purge(&bdev->txq);
> > + flush_work(&bdev->tx_work);
> >
> > - cancel_work_sync(&bdev->tx_work);
> > + skb_queue_purge(&bdev->txq);
> >
> > return 0;
> > }
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index 2560ed2f144d4..a61e610a400cb 100644
> >
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -1785,6 +1785,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > aosp_do_close(hdev);
> > msft_do_close(hdev);
> >
> > + if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > + !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > + test_bit(HCI_UP, &hdev->flags)) {
> > + /* Execute vendor specific shutdown routine */
> > + if (hdev->shutdown)
> > + hdev->shutdown(hdev);
> > + }
> > +
> > if (hdev->flush)
> > hdev->flush(hdev);
> >
> > @@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
> > clear_bit(HCI_INIT, &hdev->flags);
> > }
> >
> > - if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
> > - !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
> > - test_bit(HCI_UP, &hdev->flags)) {
> > - /* Execute vendor specific shutdown routine */
> > - if (hdev->shutdown)
> > - hdev->shutdown(hdev);
> > - }
> > -
> > /* flush cmd work */
> > flush_work(&hdev->cmd_work);
> I've tried this but I have the same (broken) symptoms as before.
>
> Here are some logs of v3:
> dmesg: https://pastebin.com/1x4UHkzy
> ftrace: https://pastebin.com/Lm1d6AWy
Thanks for your testing. I think I finally got it:
btmtksdio_shutdown()
-> mtk_hci_wmt_sync()
-> __hci_cmd_send()
then waiting for BTMTKSDIO_TX_WAIT_VND_EVT, which is cleared in
btmtksdio_recv_event():
btmtksdio_recv_event()
-> hci_recv_frame()
-> queue_work(hdev->workqueue, &hdev->rx_work);
That means it has to be done before the following drain_workqueue() call.
Can you please see if moving the ->shutdown() part right before
drain_workqueue() can fix the issue?
Kai-Heng
>
> Mattijs
>
> >
> > Kai-Heng
^ permalink raw reply [flat|nested] 20+ messages in thread
* Re: [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled
2021-08-06 15:36 ` Kai-Heng Feng
@ 2021-08-09 9:19 ` Mattijs Korpershoek
0 siblings, 0 replies; 20+ messages in thread
From: Mattijs Korpershoek @ 2021-08-09 9:19 UTC (permalink / raw)
To: Kai-Heng Feng
Cc: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz,
David S. Miller, Jakub Kicinski, Fabien Parent, Sean Wang,
open list:BLUETOOTH SUBSYSTEM, open list:NETWORKING [GENERAL],
open list
Hi Kai-Heng,
Kai-Heng Feng <kai.heng.feng@canonical.com> writes:
> Hi Mattijs,
>
>> [snipped]
>
> Thanks for your testing. I think I finally got it:
> btmtksdio_shutdown()
> -> mtk_hci_wmt_sync()
> -> __hci_cmd_send()
> then waiting for BTMTKSDIO_TX_WAIT_VND_EVT, which is cleared in
> btmtksdio_recv_event():
> btmtksdio_recv_event()
> -> hci_recv_frame()
> -> queue_work(hdev->workqueue, &hdev->rx_work);
>
> That means it has to be done before the following drain_workqueue() call.
> Can you please see if moving the ->shutdown() part right before
> drain_workqueue() can fix the issue?
I've tested the following patch:
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 2560ed2f144d..131e69a9a66a 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -1757,6 +1757,14 @@ int hci_dev_do_close(struct hci_dev *hdev)
cancel_delayed_work_sync(&adv_instance->rpa_expired_cb);
}
+ if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
+ !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
+ test_bit(HCI_UP, &hdev->flags)) {
+ /* Execute vendor specific shutdown routine */
+ if (hdev->shutdown)
+ hdev->shutdown(hdev);
+ }
+
/* Avoid potential lockdep warnings from the *_flush() calls by
* ensuring the workqueue is empty up front.
*/
@@ -1798,14 +1806,6 @@ int hci_dev_do_close(struct hci_dev *hdev)
clear_bit(HCI_INIT, &hdev->flags);
}
- if (!hci_dev_test_flag(hdev, HCI_UNREGISTER) &&
- !hci_dev_test_flag(hdev, HCI_USER_CHANNEL) &&
- test_bit(HCI_UP, &hdev->flags)) {
- /* Execute vendor specific shutdown routine */
- if (hdev->shutdown)
- hdev->shutdown(hdev);
- }
-
/* flush cmd work */
flush_work(&hdev->cmd_work);
It does not seem to fix the issue.
Adding the bits in btmtksdio_flush() does not change the result of the
above patch.
Here are the logs. These are just with the above patch (not with the
btmtksdio_flush() changes.
dmesg: https://pastebin.com/FZZBkqGC
btmtksdio_ftrace: https://pastebin.com/JQ0UWenY
Mattijs
>
> Kai-Heng
>
>>
>> Mattijs
>>
>> >
>> > Kai-Heng
^ permalink raw reply related [flat|nested] 20+ messages in thread
end of thread, other threads:[~2021-08-09 9:19 UTC | newest]
Thread overview: 20+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-05-14 7:14 [PATCH v2] Bluetooth: Shutdown controller after workqueues are flushed or cancelled Kai-Heng Feng
2021-05-14 8:12 ` [v2] " bluez.test.bot
2021-05-14 18:15 ` [PATCH v2] " Marcel Holtmann
2021-07-28 13:50 ` Mattijs Korpershoek
2021-07-28 15:25 ` Kai-Heng Feng
2021-07-30 11:40 ` Mattijs Korpershoek
2021-08-03 6:42 ` Kai-Heng Feng
2021-08-03 8:21 ` Mattijs Korpershoek
2021-08-04 14:42 ` Kai-Heng Feng
2021-08-05 6:55 ` Mattijs Korpershoek
2021-08-05 15:50 ` Kai-Heng Feng
2021-08-06 8:51 ` Mattijs Korpershoek
2021-08-06 15:36 ` Kai-Heng Feng
2021-08-09 9:19 ` Mattijs Korpershoek
[not found] ` <20210802030538.2023-1-hdanton@sina.com>
2021-08-03 6:45 ` Kai-Heng Feng
[not found] ` <20210803074722.2383-1-hdanton@sina.com>
2021-08-04 14:35 ` Kai-Heng Feng
[not found] ` <20210805030024.2603-1-hdanton@sina.com>
2021-08-05 3:44 ` Kai-Heng Feng
[not found] ` <20210805063536.2698-1-hdanton@sina.com>
2021-08-05 7:19 ` Kai-Heng Feng
2021-08-05 6:12 ` Hsin-Yi Wang
[not found] ` <20210805070114.2803-1-hdanton@sina.com>
2021-08-05 7:04 ` Hsin-Yi Wang
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).