* [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices @ 2019-04-23 7:22 João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC João Paulo Rechi Vita ` (2 more replies) 0 siblings, 3 replies; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-23 7:22 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC 2019-04-23 7:22 [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices João Paulo Rechi Vita @ 2019-04-23 7:22 ` João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377 João Paulo Rechi Vita 2019-04-23 16:17 ` [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices Marcel Holtmann 2 siblings, 0 replies; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-23 7:22 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377 2019-04-23 7:22 [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC João Paulo Rechi Vita @ 2019-04-23 7:22 ` João Paulo Rechi Vita 2019-04-23 16:17 ` [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices Marcel Holtmann 2 siblings, 0 replies; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-23 7:22 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices 2019-04-23 7:22 [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377 João Paulo Rechi Vita @ 2019-04-23 16:17 ` Marcel Holtmann 2019-04-24 5:42 ` João Paulo Rechi Vita 2 siblings, 1 reply; 19+ messages in thread From: Marcel Holtmann @ 2019-04-23 16:17 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, open list:BLUETOOTH DRIVERS, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices 2019-04-23 16:17 ` [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices Marcel Holtmann @ 2019-04-24 5:42 ` João Paulo Rechi Vita 2019-04-24 5:43 ` [PATCH] Bluetooth: Ignore CC events not matching the last HCI command João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-24 5:42 UTC (permalink / raw) To: Marcel Holtmann Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, open list:BLUETOOTH DRIVERS, Network Development, LKML, Linux Upstreaming Team, João Paulo Rechi Vita Hello Marcel, thanks for the quick response. On Wed, Apr 24, 2019 at 12:17 AM Marcel Holtmann <marcel@holtmann.org> 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-24 5:42 ` João Paulo Rechi Vita @ 2019-04-24 5:43 ` João Paulo Rechi Vita 2019-04-24 6:07 ` João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-24 5:43 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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..13fb124d04a4 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; + } + skb_pull(skb, sizeof(*ev)); switch (*opcode) { -- 2.20.1 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-24 5:43 ` [PATCH] Bluetooth: Ignore CC events not matching the last HCI command João Paulo Rechi Vita @ 2019-04-24 6:07 ` João Paulo Rechi Vita 2019-04-24 6:45 ` Marcel Holtmann 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-24 6:07 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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; + } + skb_pull(skb, sizeof(*ev)); switch (*opcode) { -- 2.20.1 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-24 6:07 ` João Paulo Rechi Vita @ 2019-04-24 6:45 ` Marcel Holtmann 2019-04-25 6:37 ` João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: Marcel Holtmann @ 2019-04-24 6:45 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, bgodavar, ytkim, David S. Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> > --- > 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-24 6:45 ` Marcel Holtmann @ 2019-04-25 6:37 ` João Paulo Rechi Vita 2019-04-25 6:38 ` João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-25 6:37 UTC (permalink / raw) To: Marcel Holtmann Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, linux-bluetooth, Network Development, LKML, Linux Upstreaming Team, João Paulo Rechi Vita On Wed, Apr 24, 2019 at 2:45 PM Marcel Holtmann <marcel@holtmann.org> 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 <jprvita@endlessm.com> > > --- > > 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-25 6:37 ` João Paulo Rechi Vita @ 2019-04-25 6:38 ` João Paulo Rechi Vita 2019-04-25 11:07 ` Marcel Holtmann 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-25 6:38 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-25 6:38 ` João Paulo Rechi Vita @ 2019-04-25 11:07 ` Marcel Holtmann 2019-04-26 8:55 ` João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: Marcel Holtmann @ 2019-04-25 11:07 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, bgodavar, ytkim, David S. Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> > --- > 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: [PATCH] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-25 11:07 ` Marcel Holtmann @ 2019-04-26 8:55 ` João Paulo Rechi Vita 2019-04-26 8:56 ` [PATCH v3] " João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-26 8:55 UTC (permalink / raw) To: Marcel Holtmann Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, linux-bluetooth, Network Development, LKML, Linux Upstreaming Team, João Paulo Rechi Vita On Thu, Apr 25, 2019 at 7:08 PM Marcel Holtmann <marcel@holtmann.org> 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 <jprvita@endlessm.com> > > --- > > 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 ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-26 8:55 ` João Paulo Rechi Vita @ 2019-04-26 8:56 ` João Paulo Rechi Vita 2019-04-26 17:01 ` Marcel Holtmann 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-26 8:56 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- 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 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-26 8:56 ` [PATCH v3] " João Paulo Rechi Vita @ 2019-04-26 17:01 ` Marcel Holtmann 2019-04-29 3:30 ` João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: Marcel Holtmann @ 2019-04-26 17:01 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, bgodavar, ytkim, David S. Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> > --- > 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, > }; no new flags here please. This is userspace visible use the hdev->dev_flags. Regards Marcel ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: [PATCH v3] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-26 17:01 ` Marcel Holtmann @ 2019-04-29 3:30 ` João Paulo Rechi Vita 2019-04-29 3:31 ` [PATCH v4] " João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-29 3:30 UTC (permalink / raw) To: Marcel Holtmann Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, linux-bluetooth, Network Development, LKML, Linux Upstreaming Team, João Paulo Rechi Vita On Sat, Apr 27, 2019 at 1:01 AM Marcel Holtmann <marcel@holtmann.org> 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 <jprvita@endlessm.com> > > --- > > 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, > > }; > > no new flags here please. This is userspace visible use the hdev->dev_flags. > Ok, moved to hdev->dev_flags. Sending new revision now. -- João Paulo Rechi Vita http://about.me/jprvita ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH v4] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-29 3:30 ` João Paulo Rechi Vita @ 2019-04-29 3:31 ` João Paulo Rechi Vita 2019-04-29 11:10 ` Marcel Holtmann 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-04-29 3:31 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- include/net/bluetooth/hci.h | 1 + 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, 22 insertions(+), 4 deletions(-) diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h index fbba43e9bef5..9a5330eed794 100644 --- a/include/net/bluetooth/hci.h +++ b/include/net/bluetooth/hci.h @@ -282,6 +282,7 @@ enum { HCI_FORCE_BREDR_SMP, HCI_FORCE_STATIC_ADDR, HCI_LL_RPA_RESOLUTION, + HCI_CMD_PENDING, __HCI_NUM_FLAGS, }; diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c index d6b2540ba7f8..d654476c8d62 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 */ + hci_dev_clear_flag(hdev, HCI_CMD_PENDING); + /* 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) + hci_dev_set_flag(hdev, HCI_CMD_PENDING); 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..8b893baf9bbe 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 (hci_dev_test_flag(hdev, HCI_CMD_PENDING)) { + 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 (hci_dev_test_flag(hdev, HCI_CMD_PENDING)) { + 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 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH v4] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-29 3:31 ` [PATCH v4] " João Paulo Rechi Vita @ 2019-04-29 11:10 ` Marcel Holtmann 2019-05-02 2:01 ` [PATCH v5] " João Paulo Rechi Vita 0 siblings, 1 reply; 19+ messages in thread From: Marcel Holtmann @ 2019-04-29 11:10 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, Balakrishna Godavarthi, ytkim, David S. Miller, linux-bluetooth, Networking, open list, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> > --- > include/net/bluetooth/hci.h | 1 + > 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, 22 insertions(+), 4 deletions(-) > > diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h > index fbba43e9bef5..9a5330eed794 100644 > --- a/include/net/bluetooth/hci.h > +++ b/include/net/bluetooth/hci.h > @@ -282,6 +282,7 @@ enum { > HCI_FORCE_BREDR_SMP, > HCI_FORCE_STATIC_ADDR, > HCI_LL_RPA_RESOLUTION, > + HCI_CMD_PENDING, > > __HCI_NUM_FLAGS, > }; > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c > index d6b2540ba7f8..d654476c8d62 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 */ > + hci_dev_clear_flag(hdev, HCI_CMD_PENDING); > + > /* 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) > + hci_dev_set_flag(hdev, HCI_CMD_PENDING); I think it is better to replace this with hci_req_status_pend(hdev) instead of trying to export HCI_REQ_* constants. Regards Marcel ^ permalink raw reply [flat|nested] 19+ messages in thread
* [PATCH v5] Bluetooth: Ignore CC events not matching the last HCI command 2019-04-29 11:10 ` Marcel Holtmann @ 2019-05-02 2:01 ` João Paulo Rechi Vita 2019-05-05 17:33 ` Marcel Holtmann 0 siblings, 1 reply; 19+ messages in thread From: João Paulo Rechi Vita @ 2019-05-02 2:01 UTC (permalink / raw) To: Marcel Holtmann, Johan Hedberg Cc: bgodavar, ytkim, David S . Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> --- include/net/bluetooth/hci.h | 1 + net/bluetooth/hci_core.c | 5 +++++ net/bluetooth/hci_event.c | 12 ++++++++++++ net/bluetooth/hci_request.c | 5 +++++ net/bluetooth/hci_request.h | 1 + 5 files changed, 24 insertions(+) diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h index fbba43e9bef5..9a5330eed794 100644 --- a/include/net/bluetooth/hci.h +++ b/include/net/bluetooth/hci.h @@ -282,6 +282,7 @@ enum { HCI_FORCE_BREDR_SMP, HCI_FORCE_STATIC_ADDR, HCI_LL_RPA_RESOLUTION, + HCI_CMD_PENDING, __HCI_NUM_FLAGS, }; diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c index d6b2540ba7f8..f275c9905650 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 */ + hci_dev_clear_flag(hdev, HCI_CMD_PENDING); + /* 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 (hci_req_status_pend(hdev)) + hci_dev_set_flag(hdev, HCI_CMD_PENDING); 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..8b893baf9bbe 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 (hci_dev_test_flag(hdev, HCI_CMD_PENDING)) { + 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 (hci_dev_test_flag(hdev, HCI_CMD_PENDING)) { + 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..e9a95ed65491 100644 --- a/net/bluetooth/hci_request.c +++ b/net/bluetooth/hci_request.c @@ -46,6 +46,11 @@ void hci_req_purge(struct hci_request *req) skb_queue_purge(&req->cmd_q); } +bool hci_req_status_pend(struct hci_dev *hdev) +{ + return hdev->req_status == HCI_REQ_PEND; +} + static int req_run(struct hci_request *req, hci_req_complete_t complete, hci_req_complete_skb_t complete_skb) { diff --git a/net/bluetooth/hci_request.h b/net/bluetooth/hci_request.h index 692cc8b13368..55b2050cc9ff 100644 --- a/net/bluetooth/hci_request.h +++ b/net/bluetooth/hci_request.h @@ -37,6 +37,7 @@ struct hci_request { void hci_req_init(struct hci_request *req, struct hci_dev *hdev); void hci_req_purge(struct hci_request *req); +bool hci_req_status_pend(struct hci_dev *hdev); int hci_req_run(struct hci_request *req, hci_req_complete_t complete); int hci_req_run_skb(struct hci_request *req, hci_req_complete_skb_t complete); void hci_req_add(struct hci_request *req, u16 opcode, u32 plen, -- 2.20.1 ^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: [PATCH v5] Bluetooth: Ignore CC events not matching the last HCI command 2019-05-02 2:01 ` [PATCH v5] " João Paulo Rechi Vita @ 2019-05-05 17:33 ` Marcel Holtmann 0 siblings, 0 replies; 19+ messages in thread From: Marcel Holtmann @ 2019-05-05 17:33 UTC (permalink / raw) To: João Paulo Rechi Vita Cc: Johan Hedberg, bgodavar, ytkim, David S. Miller, linux-bluetooth, netdev, linux-kernel, linux, João Paulo Rechi Vita 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 <jprvita@endlessm.com> > --- > include/net/bluetooth/hci.h | 1 + > net/bluetooth/hci_core.c | 5 +++++ > net/bluetooth/hci_event.c | 12 ++++++++++++ > net/bluetooth/hci_request.c | 5 +++++ > net/bluetooth/hci_request.h | 1 + > 5 files changed, 24 insertions(+) patch has been applied to bluetooth-next tree. Regards Marcel ^ permalink raw reply [flat|nested] 19+ messages in thread
end of thread, other threads:[~2019-05-05 17:33 UTC | newest] Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2019-04-23 7:22 [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 1/2] Bluetooth: Create new HCI_QUIRK_WAIT_FOR_MATCHING_CC João Paulo Rechi Vita 2019-04-23 7:22 ` [PATCH 2/2] Bluetooth: Set HCI_QUIRK_WAIT_FOR_MATCHING_CC for QCA9377 João Paulo Rechi Vita 2019-04-23 16:17 ` [PATCH 0/2] Quirk to enable QCA9377 to discover BLE devices Marcel Holtmann 2019-04-24 5:42 ` João Paulo Rechi Vita 2019-04-24 5:43 ` [PATCH] Bluetooth: Ignore CC events not matching the last HCI command João Paulo Rechi Vita 2019-04-24 6:07 ` João Paulo Rechi Vita 2019-04-24 6:45 ` Marcel Holtmann 2019-04-25 6:37 ` João Paulo Rechi Vita 2019-04-25 6:38 ` João Paulo Rechi Vita 2019-04-25 11:07 ` Marcel Holtmann 2019-04-26 8:55 ` João Paulo Rechi Vita 2019-04-26 8:56 ` [PATCH v3] " João Paulo Rechi Vita 2019-04-26 17:01 ` Marcel Holtmann 2019-04-29 3:30 ` João Paulo Rechi Vita 2019-04-29 3:31 ` [PATCH v4] " João Paulo Rechi Vita 2019-04-29 11:10 ` Marcel Holtmann 2019-05-02 2:01 ` [PATCH v5] " João Paulo Rechi Vita 2019-05-05 17:33 ` Marcel Holtmann
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).