LinuxLists.cc - [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

2019-04-23 07:23:33

Subject: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

As reported previously on [1], it is currently not possible to discover
BLE devices with QCA9377 controllers. When trying to start an active
scanning procedure with this controller, three commands are queued,
LE_SET_RANDOM_ADDR, LE_SET_SCAN_PARAM and LE_SET_SCAN_ENABLE. After the
first command is sent to the controller, a command complete event for it
is received, and the second command is sent, an extra command complete
for the first command is received. At this point the kernel sends the
next command and fails to process the command complete event for the
LE_SET_SCAN_PARAM command, because when it arrives it does not match the
last command that was sent. This makes hdev->le_scan_type never be
updated and the kernel behaves as if a passive scanning procedure was
being performed, thus no device found events are sent to userspace.

[1] https://www.spinics.net/lists/linux-bluetooth/msg79102.html

I have received no replies on the previous report and on further
attempts to contact the QCA addresses that have submitted Bluetooth
firmware blobs to linux-firmware upstream. This series avoids the
problem described above, but I believe ideally the controller should not
be sending this extra command complete event.

I'm not 100% sure if the approach taken here is the best way to work
around this problem in the kernel, as I am not super familiar with the
HCI layer. I'll be happy to hear suggestions of better approaches.

Full logs from btmon can be found bellow this message, and the extra
command complete event can be seen at timestamp 27.420131.

Best regards,

João Paulo Rechi Vita (2):
Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC
Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377

drivers/bluetooth/btusb.c | 9 +++++++++
include/net/bluetooth/hci.h | 4 ++++
include/net/bluetooth/hci_core.h | 1 +
net/bluetooth/hci_core.c | 3 +++
net/bluetooth/hci_event.c | 4 ++++
5 files changed, 21 insertions(+)

--
2.20.1

Bluetooth monitor ver 5.50
= Note: Linux version 5.0.0+ (x86_64) 0.352340
= Note: Bluetooth subsystem version 2.22 0.352343
= New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
= Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
= Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
@ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
@ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
@ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
@ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
Address type: 0x06
LE Public
LE Random
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Random (0x01)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
Start Discovery (0x0023) plen 1
Status: Success (0x00)
Address type: 0x06
LE Public
LE Random
@ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
> HCI Event: LE Meta Event (0x3e) plen 39 #8 [hci0] 27.434978
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: E8:95:19:72:73:CC (Static)
Data length: 27
Name (complete): Designer Mouse
Appearance: Mouse (0x03c2)
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Human Interface Device (0x1812)
RSSI: -27 dBm (0xe5)
> HCI Event: LE Meta Event (0x3e) plen 12 #9 [hci0] 27.435993
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: E8:95:19:72:73:CC (Static)
Data length: 0
RSSI: -27 dBm (0xe5)
> HCI Event: LE Meta Event (0x3e) plen 34 #10 [hci0] 27.456126
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:42 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS 424362
RSSI: -78 dBm (0xb2)
> HCI Event: LE Meta Event (0x3e) plen 15 #11 [hci0] 27.458091
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:42 (HTC Corporation)
Data length: 3
TX power: 4 dBm
RSSI: -79 dBm (0xb1)
> HCI Event: LE Meta Event (0x3e) plen 36 #12 [hci0] 27.466127
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 88:C6:26:BC:47:E0 (Logitech, Inc)
Data length: 24
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Name (short):
128-bit Service UUIDs (complete): 1 entry
Vendor specific (72daa6c3-29c2-6283-0c4a-2818e4d37e75)
RSSI: -89 dBm (0xa7)
> HCI Event: LE Meta Event (0x3e) plen 43 #13 [hci0] 27.483060
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 3E:AA:03:39:AF:93 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 0109200205f7919173c0503f361cb0bc3065cee7253049c23c8662
RSSI: -86 dBm (0xaa)
> HCI Event: LE Meta Event (0x3e) plen 43 #14 [hci0] 27.496132
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -75 dBm (0xb5)
> HCI Event: LE Meta Event (0x3e) plen 43 #15 [hci0] 27.500136
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 25:56:82:C6:5F:D4 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092000318c08c684a9670c9e48b8594178670965955236d78ca8
RSSI: -78 dBm (0xb2)
> HCI Event: LE Meta Event (0x3e) plen 43 #16 [hci0] 27.521133
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 17:AD:7B:9D:81:0A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002bfe890ca48146f86fba1398c5baf6bd86df2f6b6b4cab3
RSSI: -80 dBm (0xb0)
> HCI Event: LE Meta Event (0x3e) plen 34 #17 [hci0] 27.524125
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -72 dBm (0xb8)
> HCI Event: LE Meta Event (0x3e) plen 15 #18 [hci0] 27.526031
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 3
TX power: 4 dBm
RSSI: -72 dBm (0xb8)
> HCI Event: LE Meta Event (0x3e) plen 26 #19 [hci0] 27.555065
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: 4C:31:90:6F:B8:ED (Resolvable)
Data length: 14
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0714add576
RSSI: -94 dBm (0xa2)
> HCI Event: LE Meta Event (0x3e) plen 40 #20 [hci0] 27.578973
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 7A:AE:04:2B:99:83 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -52 dBm (0xcc)
> HCI Event: LE Meta Event (0x3e) plen 22 #21 [hci0] 27.581128
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: 7A:AE:04:2B:99:83 (Resolvable)
Data length: 10
Company: Google (224)
Data: 0190ca3e7e6b
RSSI: -52 dBm (0xcc)
> HCI Event: LE Meta Event (0x3e) plen 26 #22 [hci0] 27.590133
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 50:32:37:8C:8E:8E (Apple, Inc.)
Data length: 14
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0114399c7d
RSSI: -88 dBm (0xa8)
> HCI Event: LE Meta Event (0x3e) plen 43 #23 [hci0] 27.604987
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 43 #24 [hci0] 27.610981
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 17:AD:7B:9D:81:0A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002bfe890ca48146f86fba1398c5baf6bd86df2f6b6b4cab3
RSSI: -82 dBm (0xae)
> HCI Event: LE Meta Event (0x3e) plen 39 #25 [hci0] 27.646058
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: E8:95:19:72:73:CC (Static)
Data length: 27
Name (complete): Designer Mouse
Appearance: Mouse (0x03c2)
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Human Interface Device (0x1812)
RSSI: -29 dBm (0xe3)
> HCI Event: LE Meta Event (0x3e) plen 27 #26 [hci0] 27.647986
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 02:95:02:1D:EC:CA (Non-Resolvable)
Data length: 15
Flags: 0x1b
LE Limited Discoverable Mode
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 03090a000098
RSSI: -82 dBm (0xae)
> HCI Event: LE Meta Event (0x3e) plen 40 #27 [hci0] 27.658984
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -76 dBm (0xb4)
> HCI Event: LE Meta Event (0x3e) plen 34 #28 [hci0] 27.669971
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:42 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS 424362
RSSI: -77 dBm (0xb3)
> HCI Event: LE Meta Event (0x3e) plen 27 #29 [hci0] 27.685062
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: B0:34:95:32:11:FA (Apple, Inc.)
Data length: 15
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 035e0a0000d2
RSSI: -89 dBm (0xa7)
> HCI Event: LE Meta Event (0x3e) plen 39 #30 [hci0] 27.697970
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: E8:95:19:72:73:CC (Static)
Data length: 27
Name (complete): Designer Mouse
Appearance: Mouse (0x03c2)
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Human Interface Device (0x1812)
RSSI: -30 dBm (0xe2)
> HCI Event: LE Meta Event (0x3e) plen 43 #31 [hci0] 27.706061
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -80 dBm (0xb0)
> HCI Event: LE Meta Event (0x3e) plen 34 #32 [hci0] 27.768055
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:42 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS 424362
RSSI: -74 dBm (0xb6)
> HCI Event: LE Meta Event (0x3e) plen 26 #33 [hci0] 27.785060
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 50:32:37:8C:8E:8E (Apple, Inc.)
Data length: 14
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0114399c7d
RSSI: -88 dBm (0xa8)
> HCI Event: LE Meta Event (0x3e) plen 40 #34 [hci0] 27.792059
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -66 dBm (0xbe)
> HCI Event: LE Meta Event (0x3e) plen 22 #35 [hci0] 27.794058
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 10
Company: Google (224)
Data: 01daca61698f
RSSI: -66 dBm (0xbe)
> HCI Event: LE Meta Event (0x3e) plen 43 #36 [hci0] 27.814973
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 33:FB:A2:A0:68:4A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002928d2b061d019431be7639a37405f42054032d52d23bb8
RSSI: -70 dBm (0xba)
> HCI Event: LE Meta Event (0x3e) plen 34 #37 [hci0] 27.830967
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -71 dBm (0xb9)
> HCI Event: LE Meta Event (0x3e) plen 40 #38 [hci0] 27.847059
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 7A:AE:04:2B:99:83 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -57 dBm (0xc7)
> HCI Event: LE Meta Event (0x3e) plen 43 #39 [hci0] 27.858061
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 0B:AC:03:90:E2:52 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028eaae368523854409d2335d8ae88bf82c1b6bc102ed5e7
RSSI: -83 dBm (0xad)
> HCI Event: LE Meta Event (0x3e) plen 27 #40 [hci0] 27.860041
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: B0:34:95:32:11:FA (Apple, Inc.)
Data length: 15
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 035e0a0000d2
RSSI: -84 dBm (0xac)
> HCI Event: LE Meta Event (0x3e) plen 26 #41 [hci0] 27.907985
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: 69:A1:40:C3:13:0A (Resolvable)
Data length: 14
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0a1ca19d89
RSSI: -90 dBm (0xa6)
> HCI Event: LE Meta Event (0x3e) plen 40 #42 [hci0] 27.916124
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 43 #43 [hci0] 27.919129
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 25:56:82:C6:5F:D4 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092000318c08c684a9670c9e48b8594178670965955236d78ca8
RSSI: -73 dBm (0xb7)
> HCI Event: LE Meta Event (0x3e) plen 34 #44 [hci0] 27.928123
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -71 dBm (0xb9)
> HCI Event: LE Meta Event (0x3e) plen 34 #45 [hci0] 27.987233
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:42 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS 424362
RSSI: -69 dBm (0xbb)
> HCI Event: LE Meta Event (0x3e) plen 43 #46 [hci0] 27.995132
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 3E:AA:03:39:AF:93 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 0109200205f7919173c0503f361cb0bc3065cee7253049c23c8662
RSSI: -85 dBm (0xab)
> HCI Event: LE Meta Event (0x3e) plen 43 #47 [hci0] 28.027133
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 27 #48 [hci0] 28.056066
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: B0:34:95:32:11:FA (Apple, Inc.)
Data length: 15
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 035e0a0000d2
RSSI: -88 dBm (0xa8)
> HCI Event: LE Meta Event (0x3e) plen 40 #49 [hci0] 28.122131
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 7A:AE:04:2B:99:83 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -56 dBm (0xc8)
> HCI Event: LE Meta Event (0x3e) plen 43 #50 [hci0] 28.131132
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 33:FB:A2:A0:68:4A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002928d2b061d019431be7639a37405f42054032d52d23bb8
RSSI: -86 dBm (0xaa)
> HCI Event: LE Meta Event (0x3e) plen 40 #51 [hci0] 28.303237
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -67 dBm (0xbd)
> HCI Event: LE Meta Event (0x3e) plen 27 #52 [hci0] 28.701239
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:34:6D:48:3C:41 (Non-Resolvable)
Data length: 15
Flags: 0x1b
LE Limited Discoverable Mode
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 030cc0a80036
RSSI: -89 dBm (0xa7)
> HCI Event: LE Meta Event (0x3e) plen 34 #53 [hci0] 28.741233
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -71 dBm (0xb9)
> HCI Event: LE Meta Event (0x3e) plen 43 #54 [hci0] 28.766131
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -77 dBm (0xb3)
> HCI Event: LE Meta Event (0x3e) plen 40 #55 [hci0] 28.829237
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -66 dBm (0xbe)
> HCI Event: LE Meta Event (0x3e) plen 43 #56 [hci0] 28.946115
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 33:FB:A2:A0:68:4A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002928d2b061d019431be7639a37405f42054032d52d23bb8
RSSI: -88 dBm (0xa8)
> HCI Event: LE Meta Event (0x3e) plen 40 #57 [hci0] 28.949131
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 22 #58 [hci0] 28.951128
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 10
Company: Google (224)
Data: 1dd9ca8e7047
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 27 #59 [hci0] 28.973131
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: B0:34:95:32:11:FA (Apple, Inc.)
Data length: 15
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Apple TV (9)
Data: 035e0a0000d2
RSSI: -84 dBm (0xac)
> HCI Event: LE Meta Event (0x3e) plen 43 #60 [hci0] 30.553238
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 3D:93:75:B8:6E:09 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028e4b82ba058f2f37e060a1fa85e8a99c750384ec897b20
RSSI: -91 dBm (0xa5)
> HCI Event: LE Meta Event (0x3e) plen 34 #61 [hci0] 30.571128
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -70 dBm (0xba)
> HCI Event: LE Meta Event (0x3e) plen 40 #62 [hci0] 30.768238
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -77 dBm (0xb3)
> HCI Event: LE Meta Event (0x3e) plen 43 #63 [hci0] 30.965238
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 33:FB:A2:A0:68:4A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002928d2b061d019431be7639a37405f42054032d52d23bb8
RSSI: -74 dBm (0xb6)
> HCI Event: LE Meta Event (0x3e) plen 40 #64 [hci0] 31.159237
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -65 dBm (0xbf)
> HCI Event: LE Meta Event (0x3e) plen 12 #65 [hci0] 31.250241
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Public (0x00)
Address: 50:32:37:8C:8E:8E (Apple, Inc.)
Data length: 0
RSSI: -82 dBm (0xae)
> HCI Event: LE Meta Event (0x3e) plen 23 #66 [hci0] 31.766241
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: 4F:E2:1C:81:96:4D (Resolvable)
Data length: 11
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0304
RSSI: -94 dBm (0xa2)
> HCI Event: LE Meta Event (0x3e) plen 34 #67 [hci0] 31.789124
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -70 dBm (0xba)
> HCI Event: LE Meta Event (0x3e) plen 40 #68 [hci0] 31.803130
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 43 #69 [hci0] 31.917135
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 2C:44:85:C3:1F:22 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 010920028a9a16c0a22049fd76e5149c66d5703368ed3663413e54
RSSI: -61 dBm (0xc3)
> HCI Event: LE Meta Event (0x3e) plen 26 #70 [hci0] 31.978239
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: 69:A1:40:C3:13:0A (Resolvable)
Data length: 14
Flags: 0x1a
LE General Discoverable Mode
Simultaneous LE and BR/EDR (Controller)
Simultaneous LE and BR/EDR (Host)
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 0a1ca19d89
RSSI: -81 dBm (0xaf)
> HCI Event: LE Meta Event (0x3e) plen 43 #71 [hci0] 32.169240
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 33:FB:A2:A0:68:4A (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002928d2b061d019431be7639a37405f42054032d52d23bb8
RSSI: -75 dBm (0xb5)
> HCI Event: LE Meta Event (0x3e) plen 40 #72 [hci0] 32.214242
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 4A:97:99:08:9E:89 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -66 dBm (0xbe)
> HCI Event: LE Meta Event (0x3e) plen 26 #73 [hci0] 34.032239
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: C2:A8:AB:46:C0:93 (Static)
Data length: 14
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (partial): 1 entry
Nest Labs Inc. (0xfeaf)
Name (complete): N0BM6
RSSI: -86 dBm (0xaa)
> HCI Event: LE Meta Event (0x3e) plen 33 #74 [hci0] 34.035125
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: C2:A8:AB:46:C0:93 (Static)
Data length: 21
Service Data (UUID 0xfeaf): 100100025a230900de1bb2000030b41800
RSSI: -85 dBm (0xab)
> HCI Event: LE Meta Event (0x3e) plen 34 #75 [hci0] 34.125232
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 80:7A:BF:E1:B7:B2 (HTC Corporation)
Data length: 22
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Unknown (0xcb00)
Name (complete): HTC BS B23CE4
RSSI: -70 dBm (0xba)
> HCI Event: LE Meta Event (0x3e) plen 40 #76 [hci0] 34.132131
LE Advertising Report (0x02)
Num reports: 1
Event type: Scannable undirected - ADV_SCAN_IND (0x02)
Address type: Random (0x01)
Address: 5B:16:F0:4E:F8:38 (Resolvable)
Data length: 28
16-bit Service UUIDs (complete): 1 entry
Google (0xfe9f)
Service Data (UUID 0xfe9f): 0000000000000000000000000000000000000000
RSSI: -78 dBm (0xb2)
> HCI Event: LE Meta Event (0x3e) plen 12 #77 [hci0] 36.036242
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: 69:A1:40:C3:13:0A (Resolvable)
Data length: 0
RSSI: -81 dBm (0xaf)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #78 [hci0] 37.737722
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #79 [hci0] 37.739124
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 37.739273
Address type: 0x06
LE Public
LE Random
Discovery: Disabled (0x00)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 37.739273
Address type: 0x06
LE Public
LE Random
Discovery: Disabled (0x00)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 37.739273
Address type: 0x06
LE Public
LE Random
Discovery: Disabled (0x00)
@ MGMT Close: btmgmt {0x0003} 37.739481

2019-04-23 07:23:18

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC

This commit creates a new quirk, HCI_QUIRK_WAIT_FOR_MATCHING_CC, which
when set makes the kernel not send the next queued HCI command until a
command complete arrives for the last HCI command sent to the
controller.

This avoids a state of confusion where the kernel believes a passive
scanning procedure is being performed while in fact controller is
performing an active scanning procedure, as requested by userspace and
the kernel.

This state of confusion is achieved when some buggy controllers send an
extra command complete event for the LE_SET_RANDOM_ADDR after the kernel
already sent the next queued command (LE_SET_SCAN_PARAM, for starting an
active scanning procedure), as shown at timestamp 27.420131 on the btmon
logs bellow.

Bluetooth monitor ver 5.50
= Note: Linux version 5.0.0+ (x86_64) 0.352340
= Note: Bluetooth subsystem version 2.22 0.352343
= New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
= Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
= Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
@ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
@ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
@ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
@ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
Address type: 0x06
LE Public
LE Random
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Random (0x01)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
Start Discovery (0x0023) plen 1
Status: Success (0x00)
Address type: 0x06
LE Public
LE Random
@ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)

In this situation the kernel ends up not processing the command complete
event for LE_SET_SCAN_PARAM, so hdev->le_scan_type is never updated to
active scanning and no device found events are generated for
ADV_SCAN_RSP PDUs. This makes impossible to discover BTLE devices with
these controllers.

Signed-off-by: João Paulo Rechi Vita <[email protected]>
---
include/net/bluetooth/hci.h | 4 ++++
include/net/bluetooth/hci_core.h | 1 +
net/bluetooth/hci_core.c | 3 +++
net/bluetooth/hci_event.c | 4 ++++
4 files changed, 12 insertions(+)

diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
index fbba43e9bef5..f100e9d566a0 100644
--- a/include/net/bluetooth/hci.h
+++ b/include/net/bluetooth/hci.h
@@ -204,6 +204,10 @@ enum {
*
*/
HCI_QUIRK_NON_PERSISTENT_SETUP,
+
+ /* When this quirk is set, no pending HCI commands will be sent until a
+ * matching command complete for the last command is received. */
+ HCI_QUIRK_WAIT_FOR_MATCHING_CC,
};

/* HCI device flags */
diff --git a/include/net/bluetooth/hci_core.h b/include/net/bluetooth/hci_core.h
index 094e61e07030..85bed4e916d3 100644
--- a/include/net/bluetooth/hci_core.h
+++ b/include/net/bluetooth/hci_core.h
@@ -364,6 +364,7 @@ struct hci_dev {
struct sk_buff_head cmd_q;

struct sk_buff *sent_cmd;
+ __u8 sent_cmd_pending_cc;

struct mutex req_lock;
wait_queue_head_t req_wait_q;
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index d6b2540ba7f8..95ab8f9f2514 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -4383,6 +4383,8 @@ void hci_req_cmd_complete(struct hci_dev *hdev, u16 opcode, u8 status,
return;
}

+ hdev->sent_cmd_pending_cc = 0;
+
/* If the command succeeded and there's still more commands in
* this request the request is not yet complete.
*/
@@ -4493,6 +4495,7 @@ static void hci_cmd_work(struct work_struct *work)

hdev->sent_cmd = skb_clone(skb, GFP_KERNEL);
if (hdev->sent_cmd) {
+ hdev->sent_cmd_pending_cc = 1;
atomic_dec(&hdev->cmd_cnt);
hci_send_frame(hdev, skb);
if (test_bit(HCI_RESET, &hdev->flags))
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 609fd6871c5a..1abbca8ce1c2 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -3404,6 +3404,10 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
hci_req_cmd_complete(hdev, *opcode, *status, req_complete,
req_complete_skb);

+ if (hdev->sent_cmd_pending_cc &&
+ test_bit(HCI_QUIRK_WAIT_FOR_MATCHING_CC, &hdev->quirks))
+ return;
+
if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
queue_work(hdev->workqueue, &hdev->cmd_work);
}
--
2.20.1

2019-04-23 07:23:21

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377

The QCA9377 devices send an extra command complete for the
LE_SET_RANDOM_ADDR when trying to start an active scanning procedure. It
has to be ignored to avoid confusing the kernel into thinking a passive
scanning procedure is being performed instead, which makes impossible to
discover BTLE devices since no device found events are generated for
passive scanning.

Signed-off-by: João Paulo Rechi Vita <[email protected]>
---
drivers/bluetooth/btusb.c | 9 +++++++++
1 file changed, 9 insertions(+)

diff --git a/drivers/bluetooth/btusb.c b/drivers/bluetooth/btusb.c
index ded198328f21..650ba4b7908a 100644
--- a/drivers/bluetooth/btusb.c
+++ b/drivers/bluetooth/btusb.c
@@ -70,6 +70,7 @@ static struct usb_driver btusb_driver;
#define BTUSB_BCM2045 0x40000
#define BTUSB_IFNUM_2 0x80000
#define BTUSB_CW6622 0x100000
+#define BTUSB_QCA9377 0x200000

static const struct usb_device_id btusb_table[] = {
/* Generic Bluetooth USB device */
@@ -394,6 +395,10 @@ static const struct usb_device_id blacklist_table[] = {
/* Silicon Wave based devices */
{ USB_DEVICE(0x0c10, 0x0000), .driver_info = BTUSB_SWAVE },

+ /* QCA9377 devices */
+ { USB_DEVICE(0x13d3, 0x3491), .driver_info = BTUSB_QCA9377 },
+ { USB_DEVICE(0x13d3, 0x3501), .driver_info = BTUSB_QCA9377 },
+
{ } /* Terminating entry */
};

@@ -3196,6 +3201,10 @@ static int btusb_probe(struct usb_interface *intf,
btusb_check_needs_reset_resume(intf);
}

+ if (id->driver_info & BTUSB_QCA9377) {
+ set_bit(HCI_QUIRK_WAIT_FOR_MATCHING_CC, &hdev->quirks);
+ }
+
#ifdef CONFIG_BT_HCIBTUSB_RTL
if (id->driver_info & BTUSB_REALTEK) {
hdev->setup = btrtl_setup_realtek;
--
2.20.1

2019-04-23 16:17:47

by Marcel Holtmann

[permalink] [raw]

Subject: Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

Hi Joao Paulo,

> As reported previously on [1], it is currently not possible to discover
> BLE devices with QCA9377 controllers. When trying to start an active
> scanning procedure with this controller, three commands are queued,
> LE_SET_RANDOM_ADDR, LE_SET_SCAN_PARAM and LE_SET_SCAN_ENABLE. After the
> first command is sent to the controller, a command complete event for it
> is received, and the second command is sent, an extra command complete
> for the first command is received. At this point the kernel sends the
> next command and fails to process the command complete event for the
> LE_SET_SCAN_PARAM command, because when it arrives it does not match the
> last command that was sent. This makes hdev->le_scan_type never be
> updated and the kernel behaves as if a passive scanning procedure was
> being performed, thus no device found events are sent to userspace.
>
> [1] https://www.spinics.net/lists/linux-bluetooth/msg79102.html
>
> I have received no replies on the previous report and on further
> attempts to contact the QCA addresses that have submitted Bluetooth
> firmware blobs to linux-firmware upstream. This series avoids the
> problem described above, but I believe ideally the controller should not
> be sending this extra command complete event.
>
> I'm not 100% sure if the approach taken here is the best way to work
> around this problem in the kernel, as I am not super familiar with the
> HCI layer. I'll be happy to hear suggestions of better approaches.
>
> Full logs from btmon can be found bellow this message, and the extra
> command complete event can be seen at timestamp 27.420131.

so can we get a fixed firmware from Qualcomm? Or at least some ROM patches for it?

> Best regards,
>
> João Paulo Rechi Vita (2):
> Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC
> Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377
>
> drivers/bluetooth/btusb.c | 9 +++++++++
> include/net/bluetooth/hci.h | 4 ++++
> include/net/bluetooth/hci_core.h | 1 +
> net/bluetooth/hci_core.c | 3 +++
> net/bluetooth/hci_event.c | 4 ++++
> 5 files changed, 21 insertions(+)
>
> --
> 2.20.1
>
> Bluetooth monitor ver 5.50
> = Note: Linux version 5.0.0+ (x86_64) 0.352340
> = Note: Bluetooth subsystem version 2.22 0.352343
> = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> Address type: 0x06
> LE Public
> LE Random
> < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> Address: 15:60:F2:91:B2:24 (Non-Resolvable)
>> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> Type: Active (0x01)
> Interval: 11.250 msec (0x0012)
> Window: 11.250 msec (0x0012)
> Own address type: Random (0x01)
> Filter policy: Accept all advertisement (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)

so we really need to ignore this command complete and not start ahead with the next command. Especially since we really only support one command at a time right now.

> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)

We need for this command complete to arrive and only then continue with LE Set Scan Enable. We don’t need a quirk for it. Just add support for dealing with unexpected command complete opcodes. And print a big error if that happens.

>> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> @ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
> Start Discovery (0x0023) plen 1
> Status: Success (0x00)
> Address type: 0x06
> LE Public
> LE Random

Regards

Marcel

2019-04-24 05:43:36

by João Paulo Rechi Vita

[permalink] [raw]

Subject: Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

Hello Marcel, thanks for the quick response.

On Wed, Apr 24, 2019 at 12:17 AM Marcel Holtmann <[email protected]> wrote:
>
> Hi Joao Paulo,
>
> > As reported previously on [1], it is currently not possible to discover
> > BLE devices with QCA9377 controllers. When trying to start an active
> > scanning procedure with this controller, three commands are queued,
> > LE_SET_RANDOM_ADDR, LE_SET_SCAN_PARAM and LE_SET_SCAN_ENABLE. After the
> > first command is sent to the controller, a command complete event for it
> > is received, and the second command is sent, an extra command complete
> > for the first command is received. At this point the kernel sends the
> > next command and fails to process the command complete event for the
> > LE_SET_SCAN_PARAM command, because when it arrives it does not match the
> > last command that was sent. This makes hdev->le_scan_type never be
> > updated and the kernel behaves as if a passive scanning procedure was
> > being performed, thus no device found events are sent to userspace.
> >
> > [1] https://www.spinics.net/lists/linux-bluetooth/msg79102.html
> >
> > I have received no replies on the previous report and on further
> > attempts to contact the QCA addresses that have submitted Bluetooth
> > firmware blobs to linux-firmware upstream. This series avoids the
> > problem described above, but I believe ideally the controller should not
> > be sending this extra command complete event.
> >
> > I'm not 100% sure if the approach taken here is the best way to work
> > around this problem in the kernel, as I am not super familiar with the
> > HCI layer. I'll be happy to hear suggestions of better approaches.
> >
> > Full logs from btmon can be found bellow this message, and the extra
> > command complete event can be seen at timestamp 27.420131.
>
> so can we get a fixed firmware from Qualcomm? Or at least some ROM patches for it?
>

That was my initial expectation as well -- maybe you can show the
problem to some Qualcomm contacts?

> > Best regards,
> >
> > João Paulo Rechi Vita (2):
> > Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC
> > Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377
> >
> > drivers/bluetooth/btusb.c | 9 +++++++++
> > include/net/bluetooth/hci.h | 4 ++++
> > include/net/bluetooth/hci_core.h | 1 +
> > net/bluetooth/hci_core.c | 3 +++
> > net/bluetooth/hci_event.c | 4 ++++
> > 5 files changed, 21 insertions(+)
> >
> > --
> > 2.20.1
> >
> > Bluetooth monitor ver 5.50
> > = Note: Linux version 5.0.0+ (x86_64) 0.352340
> > = Note: Bluetooth subsystem version 2.22 0.352343
> > = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> > = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> > = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> > @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> > @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> > @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> > @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> > Address type: 0x06
> > LE Public
> > LE Random
> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> > Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> >> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> > Type: Active (0x01)
> > Interval: 11.250 msec (0x0012)
> > Window: 11.250 msec (0x0012)
> > Own address type: Random (0x01)
> > Filter policy: Accept all advertisement (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
>
> so we really need to ignore this command complete and not start ahead with the next command. Especially since we really only support one command at a time right now.
>

Agreed.

> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> > Scanning: Enabled (0x01)
> > Filter duplicates: Enabled (0x01)
> >> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > Status: Success (0x00)
>
> We need for this command complete to arrive and only then continue with LE Set Scan Enable. We don’t need a quirk for it. Just add support for dealing with unexpected command complete opcodes. And print a big error if that happens.
>

Makes sense, I'm sending an updated version ignoring unexpected CC
events on all hardware. Looking at the code it seems the only
exception is a CC event for HCI_OP_RESET on some CSR controllers,
which is handled in hci_req_cmd_complete, so I'm letting that flow
through.

--
João Paulo Rechi Vita
http://about.me/jprvita

2019-04-24 05:44:12

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

2019-04-24 06:07:33

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

2019-04-24 06:45:45

by Marcel Holtmann

[permalink] [raw]

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Hi Joao Paulo,

> This commit makes the kernel not send the next queued HCI command until
> a command complete arrives for the last HCI command sent to the
> controller. This change avoids a problem with some buggy controllers
> (seen on two SKUs of QCA9377) that send an extra command complete event
> for the previous command after the kernel had already sent a new HCI
> command to the controller.
>
> The problem was reproduced when starting an active scanning procedure,
> where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
> command. When this happends the kernel ends up not processing the
> command complete for the following commmand, LE_SET_SCAN_PARAM, and
> ultimately behaving as if a passive scanning procedure was being
> performed, when in fact controller is performing an active scanning
> procedure. This makes it impossible to discover BLE devices as no device
> found events are sent to userspace.
>
> This problem is reproducible on 100% of the attempts on the affected
> controllers. The extra command complete event can be seen at timestamp
> 27.420131 on the btmon logs bellow.
>
> Bluetooth monitor ver 5.50
> = Note: Linux version 5.0.0+ (x86_64) 0.352340
> = Note: Bluetooth subsystem version 2.22 0.352343
> = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> Address type: 0x06
> LE Public
> LE Random
> < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> Address: 15:60:F2:91:B2:24 (Non-Resolvable)
>> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> Type: Active (0x01)
> Interval: 11.250 msec (0x0012)
> Window: 11.250 msec (0x0012)
> Own address type: Random (0x01)
> Filter policy: Accept all advertisement (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> @ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
> Start Discovery (0x0023) plen 1
> Status: Success (0x00)
> Address type: 0x06
> LE Public
> LE Random
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
>
> Signed-off-by: João Paulo Rechi Vita <[email protected]>
> ---
> net/bluetooth/hci_event.c | 13 +++++++++++++
> 1 file changed, 13 insertions(+)
>
> diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> index 609fd6871c5a..b349fc2b4123 100644
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -3071,6 +3071,19 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> *opcode = __le16_to_cpu(ev->opcode);
> *status = skb->data[sizeof(*ev)];
>
> + if (*opcode != HCI_OP_RESET && !hci_sent_cmd_data(hdev, *opcode)) {
> + /* Some buggy controllers generate an extra command complete
> + * event for the previous command after a new commend was
> + * already sent, so if the opcode does not match the last sent
> + * command we should ignore this event.
> + *
> + * HCI_OP_RESET is a special case handled in
> + * hci_req_cmd_complete.
> + */
> + bt_dev_err(hdev, "unexpected CC event opcode 0x%4.4x", *opcode);
> + return;
> + }
> +

the return; here is not going to fly. You need to go through the switch statement since it actually does bookkeeping for a lot of features even if the command is not executed by hci_req and instead comes from user space or someone else.

What is the problem with handling this in hci_req_cmd_complete. We have hci_sent_cmd_data check there already. Lets extend this to ensure that command complete for random commands don’t trigger us to continue with the request.

Regards

Marcel

2019-04-25 06:38:05

by João Paulo Rechi Vita

[permalink] [raw]

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

On Wed, Apr 24, 2019 at 2:45 PM Marcel Holtmann <[email protected]> wrote:
>
> Hi Joao Paulo,
>
> > This commit makes the kernel not send the next queued HCI command until
> > a command complete arrives for the last HCI command sent to the
> > controller. This change avoids a problem with some buggy controllers
> > (seen on two SKUs of QCA9377) that send an extra command complete event
> > for the previous command after the kernel had already sent a new HCI
> > command to the controller.
> >
> > The problem was reproduced when starting an active scanning procedure,
> > where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
> > command. When this happends the kernel ends up not processing the
> > command complete for the following commmand, LE_SET_SCAN_PARAM, and
> > ultimately behaving as if a passive scanning procedure was being
> > performed, when in fact controller is performing an active scanning
> > procedure. This makes it impossible to discover BLE devices as no device
> > found events are sent to userspace.
> >
> > This problem is reproducible on 100% of the attempts on the affected
> > controllers. The extra command complete event can be seen at timestamp
> > 27.420131 on the btmon logs bellow.
> >
> > Bluetooth monitor ver 5.50
> > = Note: Linux version 5.0.0+ (x86_64) 0.352340
> > = Note: Bluetooth subsystem version 2.22 0.352343
> > = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> > = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> > = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> > @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> > @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> > @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> > @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> > Address type: 0x06
> > LE Public
> > LE Random
> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> > Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> >> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> > Type: Active (0x01)
> > Interval: 11.250 msec (0x0012)
> > Window: 11.250 msec (0x0012)
> > Own address type: Random (0x01)
> > Filter policy: Accept all advertisement (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> > Scanning: Enabled (0x01)
> > Filter duplicates: Enabled (0x01)
> >> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > Status: Success (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > Status: Success (0x00)
> > @ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
> > Start Discovery (0x0023) plen 1
> > Status: Success (0x00)
> > Address type: 0x06
> > LE Public
> > LE Random
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> >
> > Signed-off-by: João Paulo Rechi Vita <[email protected]>
> > ---
> > net/bluetooth/hci_event.c | 13 +++++++++++++
> > 1 file changed, 13 insertions(+)
> >
> > diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> > index 609fd6871c5a..b349fc2b4123 100644
> > --- a/net/bluetooth/hci_event.c
> > +++ b/net/bluetooth/hci_event.c
> > @@ -3071,6 +3071,19 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> > *opcode = __le16_to_cpu(ev->opcode);
> > *status = skb->data[sizeof(*ev)];
> >
> > + if (*opcode != HCI_OP_RESET && !hci_sent_cmd_data(hdev, *opcode)) {
> > + /* Some buggy controllers generate an extra command complete
> > + * event for the previous command after a new commend was
> > + * already sent, so if the opcode does not match the last sent
> > + * command we should ignore this event.
> > + *
> > + * HCI_OP_RESET is a special case handled in
> > + * hci_req_cmd_complete.
> > + */
> > + bt_dev_err(hdev, "unexpected CC event opcode 0x%4.4x", *opcode);
> > + return;
> > + }
> > +
>
> the return; here is not going to fly. You need to go through the switch statement since it actually does bookkeeping for a lot of features even if the command is not executed by hci_req and instead comes from user space or someone else.
>

Ok, so you want the same approach I had before but not bound to a
quirk. Sorry, when you previously said "ignore this command complete
and not start ahead with the next command" I thought you meant to also
avoid going through that switch statement.

> What is the problem with handling this in hci_req_cmd_complete. We have hci_sent_cmd_data check there already. Lets extend this to ensure that command complete for random commands don’t trigger us to continue with the request.
>

I'll send an updated revision soon.

--
João Paulo Rechi Vita
http://about.me/jprvita

2019-04-25 06:38:34

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

This commit makes the kernel not send the next queued HCI command until
a command complete arrives for the last HCI command sent to the
controller. This change avoids a problem with some buggy controllers
(seen on two SKUs of QCA9377) that send an extra command complete event
for the previous command after the kernel had already sent a new HCI
command to the controller.

The problem was reproduced when starting an active scanning procedure,
where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
command. When this happends the kernel ends up not processing the
command complete for the following commmand, LE_SET_SCAN_PARAM, and
ultimately behaving as if a passive scanning procedure was being
performed, when in fact controller is performing an active scanning
procedure. This makes it impossible to discover BLE devices as no device
found events are sent to userspace.

This problem is reproducible on 100% of the attempts on the affected
controllers. The extra command complete event can be seen at timestamp
27.420131 on the btmon logs bellow.

Bluetooth monitor ver 5.50
= Note: Linux version 5.0.0+ (x86_64) 0.352340
= Note: Bluetooth subsystem version 2.22 0.352343
= New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
= Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
= Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
@ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
@ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
@ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
@ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
Address type: 0x06
LE Public
LE Random
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Random (0x01)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
Start Discovery (0x0023) plen 1
Status: Success (0x00)
Address type: 0x06
LE Public
LE Random
@ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)

Signed-off-by: João Paulo Rechi Vita <[email protected]>
---
include/net/bluetooth/hci_core.h | 1 +
net/bluetooth/hci_core.c | 5 +++++
net/bluetooth/hci_event.c | 3 +++
3 files changed, 9 insertions(+)

diff --git a/include/net/bluetooth/hci_core.h b/include/net/bluetooth/hci_core.h
index 094e61e07030..85bed4e916d3 100644
--- a/include/net/bluetooth/hci_core.h
+++ b/include/net/bluetooth/hci_core.h
@@ -364,6 +364,7 @@ struct hci_dev {
struct sk_buff_head cmd_q;

struct sk_buff *sent_cmd;
+ __u8 sent_cmd_pending_cc;

struct mutex req_lock;
wait_queue_head_t req_wait_q;
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index d6b2540ba7f8..37893b0c6077 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -4380,9 +4380,13 @@ void hci_req_cmd_complete(struct hci_dev *hdev, u16 opcode, u8 status,
if (test_bit(HCI_INIT, &hdev->flags) && opcode == HCI_OP_RESET)
hci_resend_last(hdev);

+ bt_dev_err(hdev,
+ "unexpected CC event for opcode 0x%4.4x", opcode);
return;
}

+ hdev->sent_cmd_pending_cc = 0;
+
/* If the command succeeded and there's still more commands in
* this request the request is not yet complete.
*/
@@ -4493,6 +4497,7 @@ static void hci_cmd_work(struct work_struct *work)

hdev->sent_cmd = skb_clone(skb, GFP_KERNEL);
if (hdev->sent_cmd) {
+ hdev->sent_cmd_pending_cc = 1;
atomic_dec(&hdev->cmd_cnt);
hci_send_frame(hdev, skb);
if (test_bit(HCI_RESET, &hdev->flags))
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 609fd6871c5a..7541a4bc9444 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -3404,6 +3404,9 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
hci_req_cmd_complete(hdev, *opcode, *status, req_complete,
req_complete_skb);

+ if (hdev->sent_cmd_pending_cc)
+ return;
+
if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
queue_work(hdev->workqueue, &hdev->cmd_work);
}
--
2.20.1

2019-04-25 13:32:06

by Marcel Holtmann

[permalink] [raw]

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Hi Joao,

> This commit makes the kernel not send the next queued HCI command until
> a command complete arrives for the last HCI command sent to the
> controller. This change avoids a problem with some buggy controllers
> (seen on two SKUs of QCA9377) that send an extra command complete event
> for the previous command after the kernel had already sent a new HCI
> command to the controller.
>
> The problem was reproduced when starting an active scanning procedure,
> where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
> command. When this happends the kernel ends up not processing the
> command complete for the following commmand, LE_SET_SCAN_PARAM, and
> ultimately behaving as if a passive scanning procedure was being
> performed, when in fact controller is performing an active scanning
> procedure. This makes it impossible to discover BLE devices as no device
> found events are sent to userspace.
>
> This problem is reproducible on 100% of the attempts on the affected
> controllers. The extra command complete event can be seen at timestamp
> 27.420131 on the btmon logs bellow.
>
> Bluetooth monitor ver 5.50
> = Note: Linux version 5.0.0+ (x86_64) 0.352340
> = Note: Bluetooth subsystem version 2.22 0.352343
> = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> Address type: 0x06
> LE Public
> LE Random
> < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> Address: 15:60:F2:91:B2:24 (Non-Resolvable)
>> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> Type: Active (0x01)
> Interval: 11.250 msec (0x0012)
> Window: 11.250 msec (0x0012)
> Own address type: Random (0x01)
> Filter policy: Accept all advertisement (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> LE Set Random Address (0x08|0x0005) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> @ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
> Start Discovery (0x0023) plen 1
> Status: Success (0x00)
> Address type: 0x06
> LE Public
> LE Random
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
> @ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
> Address type: 0x06
> LE Public
> LE Random
> Discovery: Enabled (0x01)
>
> Signed-off-by: João Paulo Rechi Vita <[email protected]>
> ---
> include/net/bluetooth/hci_core.h | 1 +
> net/bluetooth/hci_core.c | 5 +++++
> net/bluetooth/hci_event.c | 3 +++
> 3 files changed, 9 insertions(+)
>
> diff --git a/include/net/bluetooth/hci_core.h b/include/net/bluetooth/hci_core.h
> index 094e61e07030..85bed4e916d3 100644
> --- a/include/net/bluetooth/hci_core.h
> +++ b/include/net/bluetooth/hci_core.h
> @@ -364,6 +364,7 @@ struct hci_dev {
> struct sk_buff_head cmd_q;
>
> struct sk_buff *sent_cmd;
> + __u8 sent_cmd_pending_cc;

is there anything wrong with a bool type? And frankly using a flag seems more safe than just a boolean.

>
> struct mutex req_lock;
> wait_queue_head_t req_wait_q;
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index d6b2540ba7f8..37893b0c6077 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -4380,9 +4380,13 @@ void hci_req_cmd_complete(struct hci_dev *hdev, u16 opcode, u8 status,
> if (test_bit(HCI_INIT, &hdev->flags) && opcode == HCI_OP_RESET)
> hci_resend_last(hdev);
>
> + bt_dev_err(hdev,
> + "unexpected CC event for opcode 0x%4.4x", opcode);

Have you tested this? This will cause many error from tools like hciconfig or hcitool.

> return;
> }
>
> + hdev->sent_cmd_pending_cc = 0;
> +
> /* If the command succeeded and there's still more commands in
> * this request the request is not yet complete.
> */
> @@ -4493,6 +4497,7 @@ static void hci_cmd_work(struct work_struct *work)
>
> hdev->sent_cmd = skb_clone(skb, GFP_KERNEL);
> if (hdev->sent_cmd) {
> + hdev->sent_cmd_pending_cc = 1;
> atomic_dec(&hdev->cmd_cnt);
> hci_send_frame(hdev, skb);
> if (test_bit(HCI_RESET, &hdev->flags))

Fun part is actually that even commands injected via hcitool etc. will be added to the sent_cmd queue unless they are vendor specific commands. However some manufactures choose to use command complete for their vendor commands as well (others don’t).

> diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> index 609fd6871c5a..7541a4bc9444 100644
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -3404,6 +3404,9 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> hci_req_cmd_complete(hdev, *opcode, *status, req_complete,
> req_complete_skb);
>
> + if (hdev->sent_cmd_pending_cc)
> + return;
> +
> if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
> queue_work(hdev->workqueue, &hdev->cmd_work);

I rather see this done super cleanly. We have a pending cmd request from the kernel, make sure it gets answered with the corresponding command complete or command status and not just some other event. If there is a command complete or command status for a command that we don’t have pending, then ignore.

Frankly, you are just hacking around here.

Regards

Marcel

2019-04-26 08:56:27

by João Paulo Rechi Vita

[permalink] [raw]

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

On Thu, Apr 25, 2019 at 7:08 PM Marcel Holtmann <[email protected]> wrote:
>
> Hi Joao,
>
> > This commit makes the kernel not send the next queued HCI command until
> > a command complete arrives for the last HCI command sent to the
> > controller. This change avoids a problem with some buggy controllers
> > (seen on two SKUs of QCA9377) that send an extra command complete event
> > for the previous command after the kernel had already sent a new HCI
> > command to the controller.
> >
> > The problem was reproduced when starting an active scanning procedure,
> > where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
> > command. When this happends the kernel ends up not processing the
> > command complete for the following commmand, LE_SET_SCAN_PARAM, and
> > ultimately behaving as if a passive scanning procedure was being
> > performed, when in fact controller is performing an active scanning
> > procedure. This makes it impossible to discover BLE devices as no device
> > found events are sent to userspace.
> >
> > This problem is reproducible on 100% of the attempts on the affected
> > controllers. The extra command complete event can be seen at timestamp
> > 27.420131 on the btmon logs bellow.
> >
> > Bluetooth monitor ver 5.50
> > = Note: Linux version 5.0.0+ (x86_64) 0.352340
> > = Note: Bluetooth subsystem version 2.22 0.352343
> > = New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
> > = Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
> > = Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
> > @ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
> > @ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
> > @ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
> > @ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
> > Address type: 0x06
> > LE Public
> > LE Random
> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
> > Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> >> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
> > Type: Active (0x01)
> > Interval: 11.250 msec (0x0012)
> > Window: 11.250 msec (0x0012)
> > Own address type: Random (0x01)
> > Filter policy: Accept all advertisement (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
> > Scanning: Enabled (0x01)
> > Filter duplicates: Enabled (0x01)
> >> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > Status: Success (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > Status: Success (0x00)
> > @ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
> > Start Discovery (0x0023) plen 1
> > Status: Success (0x00)
> > Address type: 0x06
> > LE Public
> > LE Random
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> > @ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
> > Address type: 0x06
> > LE Public
> > LE Random
> > Discovery: Enabled (0x01)
> >
> > Signed-off-by: João Paulo Rechi Vita <[email protected]>
> > ---
> > include/net/bluetooth/hci_core.h | 1 +
> > net/bluetooth/hci_core.c | 5 +++++
> > net/bluetooth/hci_event.c | 3 +++
> > 3 files changed, 9 insertions(+)
> >
> > diff --git a/include/net/bluetooth/hci_core.h b/include/net/bluetooth/hci_core.h
> > index 094e61e07030..85bed4e916d3 100644
> > --- a/include/net/bluetooth/hci_core.h
> > +++ b/include/net/bluetooth/hci_core.h
> > @@ -364,6 +364,7 @@ struct hci_dev {
> > struct sk_buff_head cmd_q;
> >
> > struct sk_buff *sent_cmd;
> > + __u8 sent_cmd_pending_cc;
>
> is there anything wrong with a bool type? And frankly using a flag seems more safe than just a boolean.
>

Ok, I'll change it into a flag.

> >
> > struct mutex req_lock;
> > wait_queue_head_t req_wait_q;
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index d6b2540ba7f8..37893b0c6077 100644
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -4380,9 +4380,13 @@ void hci_req_cmd_complete(struct hci_dev *hdev, u16 opcode, u8 status,
> > if (test_bit(HCI_INIT, &hdev->flags) && opcode == HCI_OP_RESET)
> > hci_resend_last(hdev);
> >
> > + bt_dev_err(hdev,
> > + "unexpected CC event for opcode 0x%4.4x", opcode);
>
> Have you tested this? This will cause many error from tools like hciconfig or hcitool.
>

I have tested this, but not with hciconfig or hcitool custom commands.
Do you have an example that I could use to verify this?

> > return;
> > }
> >
> > + hdev->sent_cmd_pending_cc = 0;
> > +
> > /* If the command succeeded and there's still more commands in
> > * this request the request is not yet complete.
> > */
> > @@ -4493,6 +4497,7 @@ static void hci_cmd_work(struct work_struct *work)
> >
> > hdev->sent_cmd = skb_clone(skb, GFP_KERNEL);
> > if (hdev->sent_cmd) {
> > + hdev->sent_cmd_pending_cc = 1;
> > atomic_dec(&hdev->cmd_cnt);
> > hci_send_frame(hdev, skb);
> > if (test_bit(HCI_RESET, &hdev->flags))
>
> Fun part is actually that even commands injected via hcitool etc. will be added to the sent_cmd queue unless they are vendor specific commands. However some manufactures choose to use command complete for their vendor commands as well (others don’t).
>

So injected commands and vendor-specific commands are not part of an
hci_request, but end up in this same hdev->cmd_q somehow. Is that
correct?

> > diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> > index 609fd6871c5a..7541a4bc9444 100644
> > --- a/net/bluetooth/hci_event.c
> > +++ b/net/bluetooth/hci_event.c
> > @@ -3404,6 +3404,9 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
> > hci_req_cmd_complete(hdev, *opcode, *status, req_complete,
> > req_complete_skb);
> >
> > + if (hdev->sent_cmd_pending_cc)
> > + return;
> > +
> > if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
> > queue_work(hdev->workqueue, &hdev->cmd_work);
>
> I rather see this done super cleanly. We have a pending cmd request from the kernel, make sure it gets answered with the corresponding command complete or command status and not just some other event. If there is a command complete or command status for a command that we don’t have pending, then ignore.
>

So, just to make this clear: are you saying we should only try to
match commands with events if the command is part of a hci_request?
IIUC the way to verify if a command is part of a request is to check
if hdev->req_status == HCI_REQ_PEND.

> Frankly, you are just hacking around here.
>

Well, I tried to make this point on my first submission -- I am not
familiar with the HCI layer, but having identified the bug and have
the affected hardware at hand, I thought I might as well try to fix it
so users with this controller can use BLE devices. I am happy to keep
working on it some guidance, but I would not mind testing patches
either if you think that would be easier.

> Regards
>
> Marcel
>

Thanks for the reviews so far. I'm sending a new revision
incorporating my understanding of the feedback above,

Best regards,

--
João Paulo Rechi Vita
http://about.me/jprvita

2019-04-26 08:59:27

by João Paulo Rechi Vita

[permalink] [raw]

Subject: [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command

This commit makes the kernel not send the next queued HCI command until
a command complete arrives for the last HCI command sent to the
controller. This change avoids a problem with some buggy controllers
(seen on two SKUs of QCA9377) that send an extra command complete event
for the previous command after the kernel had already sent a new HCI
command to the controller.

The problem was reproduced when starting an active scanning procedure,
where an extra command complete event arrives for the LE_SET_RANDOM_ADDR
command. When this happends the kernel ends up not processing the
command complete for the following commmand, LE_SET_SCAN_PARAM, and
ultimately behaving as if a passive scanning procedure was being
performed, when in fact controller is performing an active scanning
procedure. This makes it impossible to discover BLE devices as no device
found events are sent to userspace.

This problem is reproducible on 100% of the attempts on the affected
controllers. The extra command complete event can be seen at timestamp
27.420131 on the btmon logs bellow.

Bluetooth monitor ver 5.50
= Note: Linux version 5.0.0+ (x86_64) 0.352340
= Note: Bluetooth subsystem version 2.22 0.352343
= New Index: 80:C5:F2:8F:87:84 (Primary,USB,hci0) [hci0] 0.352344
= Open Index: 80:C5:F2:8F:87:84 [hci0] 0.352345
= Index Info: 80:C5:F2:8F:87:84 (Qualcomm) [hci0] 0.352346
@ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.352347
@ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.352366
@ MGMT Open: btmgmt (privileged) version 1.14 {0x0003} 27.302164
@ MGMT Command: Start Discovery (0x0023) plen 1 {0x0003} [hci0] 27.302310
Address type: 0x06
LE Public
LE Random
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #1 [hci0] 27.302496
Address: 15:60:F2:91:B2:24 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 27.419117
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #3 [hci0] 27.419244
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Random (0x01)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 27.420131
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #5 [hci0] 27.420259
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 27.420969
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 27.421983
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 {0x0003} [hci0] 27.422059
Start Discovery (0x0023) plen 1
Status: Success (0x00)
Address type: 0x06
LE Public
LE Random
@ MGMT Event: Discovering (0x0013) plen 2 {0x0003} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 27.422067
Address type: 0x06
LE Public
LE Random
Discovery: Enabled (0x01)

Signed-off-by: João Paulo Rechi Vita <[email protected]>
---
include/net/bluetooth/hci.h | 2 ++
net/bluetooth/hci_core.c | 5 +++++
net/bluetooth/hci_event.c | 12 ++++++++++++
net/bluetooth/hci_request.c | 4 ----
net/bluetooth/hci_request.h | 4 ++++
5 files changed, 23 insertions(+), 4 deletions(-)

diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
index fbba43e9bef5..883a8c25ccfb 100644
--- a/include/net/bluetooth/hci.h
+++ b/include/net/bluetooth/hci.h
@@ -221,6 +221,8 @@ enum {
HCI_RAW,

HCI_RESET,
+
+ HCI_CMD_PENDING,
};

/* HCI socket flags */
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index d6b2540ba7f8..4b7f20286e1a 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -4383,6 +4383,9 @@ void hci_req_cmd_complete(struct hci_dev *hdev, u16 opcode, u8 status,
return;
}

+ /* If we reach this point this event matches the last command sent */
+ clear_bit(HCI_CMD_PENDING, &hdev->flags);
+
/* If the command succeeded and there's still more commands in
* this request the request is not yet complete.
*/
@@ -4493,6 +4496,8 @@ static void hci_cmd_work(struct work_struct *work)

hdev->sent_cmd = skb_clone(skb, GFP_KERNEL);
if (hdev->sent_cmd) {
+ if (hdev->req_status == HCI_REQ_PEND)
+ set_bit(HCI_CMD_PENDING, &hdev->flags);
atomic_dec(&hdev->cmd_cnt);
hci_send_frame(hdev, skb);
if (test_bit(HCI_RESET, &hdev->flags))
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 609fd6871c5a..cac13f674474 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -3404,6 +3404,12 @@ static void hci_cmd_complete_evt(struct hci_dev *hdev, struct sk_buff *skb,
hci_req_cmd_complete(hdev, *opcode, *status, req_complete,
req_complete_skb);

+ if (test_bit(HCI_CMD_PENDING, &hdev->flags)) {
+ bt_dev_err(hdev,
+ "unexpected event for opcode 0x%4.4x", *opcode);
+ return;
+ }
+
if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
queue_work(hdev->workqueue, &hdev->cmd_work);
}
@@ -3511,6 +3517,12 @@ static void hci_cmd_status_evt(struct hci_dev *hdev, struct sk_buff *skb,
hci_req_cmd_complete(hdev, *opcode, ev->status, req_complete,
req_complete_skb);

+ if (test_bit(HCI_CMD_PENDING, &hdev->flags)) {
+ bt_dev_err(hdev,
+ "unexpected event for opcode 0x%4.4x", *opcode);
+ return;
+ }
+
if (atomic_read(&hdev->cmd_cnt) && !skb_queue_empty(&hdev->cmd_q))
queue_work(hdev->workqueue, &hdev->cmd_work);
}
diff --git a/net/bluetooth/hci_request.c b/net/bluetooth/hci_request.c
index ca73d36cc149..5b3838a3bdc1 100644
--- a/net/bluetooth/hci_request.c
+++ b/net/bluetooth/hci_request.c
@@ -30,10 +30,6 @@
#include "smp.h"
#include "hci_request.h"

-#define HCI_REQ_DONE 0
-#define HCI_REQ_PEND 1
-#define HCI_REQ_CANCELED 2
-
void hci_req_init(struct hci_request *req, struct hci_dev *hdev)
{
skb_queue_head_init(&req->cmd_q);
diff --git a/net/bluetooth/hci_request.h b/net/bluetooth/hci_request.h
index 692cc8b13368..d0cea517d66e 100644
--- a/net/bluetooth/hci_request.h
+++ b/net/bluetooth/hci_request.h
@@ -22,6 +22,10 @@

#include <asm/unaligned.h>

+#define HCI_REQ_DONE 0
+#define HCI_REQ_PEND 1
+#define HCI_REQ_CANCELED 2
+
#define hci_req_sync_lock(hdev) mutex_lock(&hdev->req_lock)
#define hci_req_sync_unlock(hdev) mutex_unlock(&hdev->req_lock)

--
2.20.1

2019-04-26 17:02:13

by Marcel Holtmann

[permalink] [raw]

Subject: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

Subject: [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC

Subject: [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377

Subject: Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

Subject: Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command

Subject: [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command

Subject: Re: [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command