* Intermittent Not connectable devices reported @ 2023-06-02 9:45 Herman Meerlo 2023-06-07 6:45 ` Herman Meerlo 2023-06-07 19:21 ` Luiz Augusto von Dentz 0 siblings, 2 replies; 7+ messages in thread From: Herman Meerlo @ 2023-06-02 9:45 UTC (permalink / raw) To: linux-bluetooth I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: • Connect to DBus to start the discovery • Devices are found, interfacesAdded callbacks are made, everything looks fine • Stop discovery • Directly some devices are removed by the interfacesRemoved callback • My code does not get the device it searches for -> unhappy user What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: > HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 LE Advertising Report (0x02) Num reports: 1 Event type: Scan response - SCAN_RSP (0x04) Address type: Public (0x00) Address: F4:B8:5E:64:02:55 (Texas Instruments) Data length: 26 Name (complete): BeeWi SmartLite Peripheral Conn. Interval: 0x0028 - 0x0050 TX power: 0 dBm RSSI: -42 dBm (0xd6) @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 LE Address: F4:B8:5E:64:02:55 (Texas Instruments) RSSI: -42 dBm (0xd6) Flags: 0x00000004 Not Connectable Data length: 26 Name (complete): BeeWi SmartLite Peripheral Conn. Interval: 0x0028 - 0x0050 TX power: 0 dBm But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: > HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 LE Advertising Report (0x02) Num reports: 1 Event type: Connectable undirected - ADV_IND (0x00) Address type: Public (0x00) Address: F4:B8:5E:64:02:55 (Texas Instruments) Data length: 15 Flags: 0x06 LE General Discoverable Mode BR/EDR Not Supported Company: Texas Instruments Inc. (13) Data: 06030108b0e408f7 RSSI: -43 dBm (0xd5) @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 LE Address: 44:6E:FF:00:0D:65 (Resolvable) RSSI: -74 dBm (0xb6) Flags: 0x00000000 Data length: 17 Flags: 0x1a LE General Discoverable Mode Simultaneous LE and BR/EDR (Controller) Simultaneous LE and BR/EDR (Host) TX power: 9 dBm Company: Apple, Inc. (76) Type: Unknown (16) Data: 01188898dc > HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 LE Advertising Report (0x02) Num reports: 1 Event type: Connectable undirected - ADV_IND (0x00) Address type: Random (0x01) Address: FA:BD:8D:12:26:BF (Static) Data length: 29 Name (short): P mesh Flags: 0x04 BR/EDR Not Supported 128-bit Service UUIDs (partial): 1 entry Vendor specific RSSI: -47 dBm (0xd1) @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 LE Address: F4:B8:5E:64:02:55 (Texas Instruments) RSSI: -43 dBm (0xd5) Flags: 0x00000000 Data length: 15 Flags: 0x06 LE General Discoverable Mode BR/EDR Not Supported Company: Texas Instruments Inc. (13) Data: 06030108b0e408f7 So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-02 9:45 Intermittent Not connectable devices reported Herman Meerlo @ 2023-06-07 6:45 ` Herman Meerlo 2023-06-07 19:21 ` Luiz Augusto von Dentz 1 sibling, 0 replies; 7+ messages in thread From: Herman Meerlo @ 2023-06-07 6:45 UTC (permalink / raw) To: linux-bluetooth > On 2 Jun 2023, at 11:45, Herman Meerlo <herman.meerlo@athom.nl> wrote: > > I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: > > • Connect to DBus to start the discovery > • Devices are found, interfacesAdded callbacks are made, everything looks fine > • Stop discovery > • Directly some devices are removed by the interfacesRemoved callback > • My code does not get the device it searches for -> unhappy user > > What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. > So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: > >> HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Scan response - SCAN_RSP (0x04) > Address type: Public (0x00) > Address: F4:B8:5E:64:02:55 (Texas Instruments) > Data length: 26 > Name (complete): BeeWi SmartLite > Peripheral Conn. Interval: 0x0028 - 0x0050 > TX power: 0 dBm > RSSI: -42 dBm (0xd6) > @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > RSSI: -42 dBm (0xd6) > Flags: 0x00000004 > Not Connectable > Data length: 26 > Name (complete): BeeWi SmartLite > Peripheral Conn. Interval: 0x0028 - 0x0050 > TX power: 0 dBm > > But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: > >> HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Connectable undirected - ADV_IND (0x00) > Address type: Public (0x00) > Address: F4:B8:5E:64:02:55 (Texas Instruments) > Data length: 15 > Flags: 0x06 > LE General Discoverable Mode > BR/EDR Not Supported > Company: Texas Instruments Inc. (13) > Data: 06030108b0e408f7 > RSSI: -43 dBm (0xd5) > @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 > LE Address: 44:6E:FF:00:0D:65 (Resolvable) > RSSI: -74 dBm (0xb6) > Flags: 0x00000000 > Data length: 17 > Flags: 0x1a > LE General Discoverable Mode > Simultaneous LE and BR/EDR (Controller) > Simultaneous LE and BR/EDR (Host) > TX power: 9 dBm > Company: Apple, Inc. (76) > Type: Unknown (16) > Data: 01188898dc >> HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Connectable undirected - ADV_IND (0x00) > Address type: Random (0x01) > Address: FA:BD:8D:12:26:BF (Static) > Data length: 29 > Name (short): P mesh > Flags: 0x04 > BR/EDR Not Supported > 128-bit Service UUIDs (partial): 1 entry > Vendor specific > RSSI: -47 dBm (0xd1) > @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > RSSI: -43 dBm (0xd5) > Flags: 0x00000000 > Data length: 15 > Flags: 0x06 > LE General Discoverable Mode > BR/EDR Not Supported > Company: Texas Instruments Inc. (13) > Data: 06030108b0e408f7 > > So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: > > https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 > > It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? Can someone take a look at this? It is happening quite often and I can not imagine that I’m the only one with this issue. ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-02 9:45 Intermittent Not connectable devices reported Herman Meerlo 2023-06-07 6:45 ` Herman Meerlo @ 2023-06-07 19:21 ` Luiz Augusto von Dentz 2023-06-08 16:32 ` Luiz Augusto von Dentz 1 sibling, 1 reply; 7+ messages in thread From: Luiz Augusto von Dentz @ 2023-06-07 19:21 UTC (permalink / raw) To: Herman Meerlo; +Cc: linux-bluetooth Hi Herman, On Fri, Jun 2, 2023 at 2:51 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: > > I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: > > • Connect to DBus to start the discovery > • Devices are found, interfacesAdded callbacks are made, everything looks fine > • Stop discovery > • Directly some devices are removed by the interfacesRemoved callback > • My code does not get the device it searches for -> unhappy user > > What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. > So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: > > > HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Scan response - SCAN_RSP (0x04) > Address type: Public (0x00) > Address: F4:B8:5E:64:02:55 (Texas Instruments) > Data length: 26 > Name (complete): BeeWi SmartLite > Peripheral Conn. Interval: 0x0028 - 0x0050 > TX power: 0 dBm > RSSI: -42 dBm (0xd6) > @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > RSSI: -42 dBm (0xd6) > Flags: 0x00000004 > Not Connectable > Data length: 26 > Name (complete): BeeWi SmartLite > Peripheral Conn. Interval: 0x0028 - 0x0050 > TX power: 0 dBm > > But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: > > > HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Connectable undirected - ADV_IND (0x00) > Address type: Public (0x00) > Address: F4:B8:5E:64:02:55 (Texas Instruments) > Data length: 15 > Flags: 0x06 > LE General Discoverable Mode > BR/EDR Not Supported > Company: Texas Instruments Inc. (13) > Data: 06030108b0e408f7 > RSSI: -43 dBm (0xd5) > @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 > LE Address: 44:6E:FF:00:0D:65 (Resolvable) > RSSI: -74 dBm (0xb6) > Flags: 0x00000000 > Data length: 17 > Flags: 0x1a > LE General Discoverable Mode > Simultaneous LE and BR/EDR (Controller) > Simultaneous LE and BR/EDR (Host) > TX power: 9 dBm > Company: Apple, Inc. (76) > Type: Unknown (16) > Data: 01188898dc > > HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 > LE Advertising Report (0x02) > Num reports: 1 > Event type: Connectable undirected - ADV_IND (0x00) > Address type: Random (0x01) > Address: FA:BD:8D:12:26:BF (Static) > Data length: 29 > Name (short): P mesh > Flags: 0x04 > BR/EDR Not Supported > 128-bit Service UUIDs (partial): 1 entry > Vendor specific > RSSI: -47 dBm (0xd1) > @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > RSSI: -43 dBm (0xd5) > Flags: 0x00000000 > Data length: 15 > Flags: 0x06 > LE General Discoverable Mode > BR/EDR Not Supported > Company: Texas Instruments Inc. (13) > Data: 06030108b0e408f7 > > So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: > > https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 > > It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? You are saying that the controller would interleave ADV_IND of different peers before SCAN_RSP, in that case yes that would be possible that the device would be marked as NOT_CONNECTABLE, usually that is not really the case which is why we end up adding the code above: * In the really unlikely case that a controller get confused * and just sends a scan response event, then it is marked as * not connectable as well. I guess it is not really unlikely after all, so perhaps we need a flag indicating this is a standalone SCAN_RSP e.g. MGMT_DEV_FOUND_SCAN_RSP, then we can treat it accordingly in userspace. -- Luiz Augusto von Dentz ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-07 19:21 ` Luiz Augusto von Dentz @ 2023-06-08 16:32 ` Luiz Augusto von Dentz 2023-06-09 11:11 ` Herman Meerlo 2023-06-14 8:29 ` Herman Meerlo 0 siblings, 2 replies; 7+ messages in thread From: Luiz Augusto von Dentz @ 2023-06-08 16:32 UTC (permalink / raw) To: Herman Meerlo; +Cc: linux-bluetooth Hi Herman, On Wed, Jun 7, 2023 at 12:21 PM Luiz Augusto von Dentz <luiz.dentz@gmail.com> wrote: > > Hi Herman, > > On Fri, Jun 2, 2023 at 2:51 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: > > > > I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: > > > > • Connect to DBus to start the discovery > > • Devices are found, interfacesAdded callbacks are made, everything looks fine > > • Stop discovery > > • Directly some devices are removed by the interfacesRemoved callback > > • My code does not get the device it searches for -> unhappy user > > > > What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. > > So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: > > > > > HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 > > LE Advertising Report (0x02) > > Num reports: 1 > > Event type: Scan response - SCAN_RSP (0x04) > > Address type: Public (0x00) > > Address: F4:B8:5E:64:02:55 (Texas Instruments) > > Data length: 26 > > Name (complete): BeeWi SmartLite > > Peripheral Conn. Interval: 0x0028 - 0x0050 > > TX power: 0 dBm > > RSSI: -42 dBm (0xd6) > > @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 > > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > > RSSI: -42 dBm (0xd6) > > Flags: 0x00000004 > > Not Connectable > > Data length: 26 > > Name (complete): BeeWi SmartLite > > Peripheral Conn. Interval: 0x0028 - 0x0050 > > TX power: 0 dBm > > > > But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: > > > > > HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 > > LE Advertising Report (0x02) > > Num reports: 1 > > Event type: Connectable undirected - ADV_IND (0x00) > > Address type: Public (0x00) > > Address: F4:B8:5E:64:02:55 (Texas Instruments) > > Data length: 15 > > Flags: 0x06 > > LE General Discoverable Mode > > BR/EDR Not Supported > > Company: Texas Instruments Inc. (13) > > Data: 06030108b0e408f7 > > RSSI: -43 dBm (0xd5) > > @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 > > LE Address: 44:6E:FF:00:0D:65 (Resolvable) > > RSSI: -74 dBm (0xb6) > > Flags: 0x00000000 > > Data length: 17 > > Flags: 0x1a > > LE General Discoverable Mode > > Simultaneous LE and BR/EDR (Controller) > > Simultaneous LE and BR/EDR (Host) > > TX power: 9 dBm > > Company: Apple, Inc. (76) > > Type: Unknown (16) > > Data: 01188898dc > > > HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 > > LE Advertising Report (0x02) > > Num reports: 1 > > Event type: Connectable undirected - ADV_IND (0x00) > > Address type: Random (0x01) > > Address: FA:BD:8D:12:26:BF (Static) > > Data length: 29 > > Name (short): P mesh > > Flags: 0x04 > > BR/EDR Not Supported > > 128-bit Service UUIDs (partial): 1 entry > > Vendor specific > > RSSI: -47 dBm (0xd1) > > @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 > > LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > > RSSI: -43 dBm (0xd5) > > Flags: 0x00000000 > > Data length: 15 > > Flags: 0x06 > > LE General Discoverable Mode > > BR/EDR Not Supported > > Company: Texas Instruments Inc. (13) > > Data: 06030108b0e408f7 > > > > So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: > > > > https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 > > > > It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? > > You are saying that the controller would interleave ADV_IND of > different peers before SCAN_RSP, in that case yes that would be > possible that the device would be marked as NOT_CONNECTABLE, usually > that is not really the case which is why we end up adding the code > above: > > * In the really unlikely case that a controller get confused > * and just sends a scan response event, then it is marked as > * not connectable as well. > > I guess it is not really unlikely after all, so perhaps we need a flag > indicating this is a standalone SCAN_RSP e.g. MGMT_DEV_FOUND_SCAN_RSP, > then we can treat it accordingly in userspace. Can you try with the following change: https://patchwork.kernel.org/project/bluetooth/patch/20230607194518.2901376-1-luiz.dentz@gmail.com/ -- Luiz Augusto von Dentz ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-08 16:32 ` Luiz Augusto von Dentz @ 2023-06-09 11:11 ` Herman Meerlo 2023-06-14 8:29 ` Herman Meerlo 1 sibling, 0 replies; 7+ messages in thread From: Herman Meerlo @ 2023-06-09 11:11 UTC (permalink / raw) To: Luiz Augusto von Dentz; +Cc: linux-bluetooth > On 8 Jun 2023, at 18:32, Luiz Augusto von Dentz <luiz.dentz@gmail.com> wrote: > > Hi Herman, > > On Wed, Jun 7, 2023 at 12:21 PM Luiz Augusto von Dentz > <luiz.dentz@gmail.com> wrote: >> >> Hi Herman, >> >> On Fri, Jun 2, 2023 at 2:51 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: >>> >>> I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: >>> >>> • Connect to DBus to start the discovery >>> • Devices are found, interfacesAdded callbacks are made, everything looks fine >>> • Stop discovery >>> • Directly some devices are removed by the interfacesRemoved callback >>> • My code does not get the device it searches for -> unhappy user >>> >>> What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. >>> So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: >>> >>>> HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Scan response - SCAN_RSP (0x04) >>> Address type: Public (0x00) >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> Data length: 26 >>> Name (complete): BeeWi SmartLite >>> Peripheral Conn. Interval: 0x0028 - 0x0050 >>> TX power: 0 dBm >>> RSSI: -42 dBm (0xd6) >>> @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> RSSI: -42 dBm (0xd6) >>> Flags: 0x00000004 >>> Not Connectable >>> Data length: 26 >>> Name (complete): BeeWi SmartLite >>> Peripheral Conn. Interval: 0x0028 - 0x0050 >>> TX power: 0 dBm >>> >>> But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: >>> >>>> HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Connectable undirected - ADV_IND (0x00) >>> Address type: Public (0x00) >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> Data length: 15 >>> Flags: 0x06 >>> LE General Discoverable Mode >>> BR/EDR Not Supported >>> Company: Texas Instruments Inc. (13) >>> Data: 06030108b0e408f7 >>> RSSI: -43 dBm (0xd5) >>> @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 >>> LE Address: 44:6E:FF:00:0D:65 (Resolvable) >>> RSSI: -74 dBm (0xb6) >>> Flags: 0x00000000 >>> Data length: 17 >>> Flags: 0x1a >>> LE General Discoverable Mode >>> Simultaneous LE and BR/EDR (Controller) >>> Simultaneous LE and BR/EDR (Host) >>> TX power: 9 dBm >>> Company: Apple, Inc. (76) >>> Type: Unknown (16) >>> Data: 01188898dc >>>> HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Connectable undirected - ADV_IND (0x00) >>> Address type: Random (0x01) >>> Address: FA:BD:8D:12:26:BF (Static) >>> Data length: 29 >>> Name (short): P mesh >>> Flags: 0x04 >>> BR/EDR Not Supported >>> 128-bit Service UUIDs (partial): 1 entry >>> Vendor specific >>> RSSI: -47 dBm (0xd1) >>> @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> RSSI: -43 dBm (0xd5) >>> Flags: 0x00000000 >>> Data length: 15 >>> Flags: 0x06 >>> LE General Discoverable Mode >>> BR/EDR Not Supported >>> Company: Texas Instruments Inc. (13) >>> Data: 06030108b0e408f7 >>> >>> So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: >>> >>> https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 >>> >>> It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? >> >> You are saying that the controller would interleave ADV_IND of >> different peers before SCAN_RSP, in that case yes that would be >> possible that the device would be marked as NOT_CONNECTABLE, usually >> that is not really the case which is why we end up adding the code >> above: >> >> * In the really unlikely case that a controller get confused >> * and just sends a scan response event, then it is marked as >> * not connectable as well. >> >> I guess it is not really unlikely after all, so perhaps we need a flag >> indicating this is a standalone SCAN_RSP e.g. MGMT_DEV_FOUND_SCAN_RSP, >> then we can treat it accordingly in userspace. > > Can you try with the following change: > > https://patchwork.kernel.org/project/bluetooth/patch/20230607194518.2901376-1-luiz.dentz@gmail.com/ > > -- > Luiz Augusto von Dentz Yes of course, I am going to give it a try. It will require a complete new build setup so it will probably take a while. But really thankful that you made a potential fix for this problem. I’ll keep you posted. ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-08 16:32 ` Luiz Augusto von Dentz 2023-06-09 11:11 ` Herman Meerlo @ 2023-06-14 8:29 ` Herman Meerlo 2023-06-14 16:56 ` Luiz Augusto von Dentz 1 sibling, 1 reply; 7+ messages in thread From: Herman Meerlo @ 2023-06-14 8:29 UTC (permalink / raw) To: Luiz Augusto von Dentz; +Cc: linux-bluetooth > On 8 Jun 2023, at 18:32, Luiz Augusto von Dentz <luiz.dentz@gmail.com> wrote: > > Hi Herman, > > On Wed, Jun 7, 2023 at 12:21 PM Luiz Augusto von Dentz > <luiz.dentz@gmail.com> wrote: >> >> Hi Herman, >> >> On Fri, Jun 2, 2023 at 2:51 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: >>> >>> I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: >>> >>> • Connect to DBus to start the discovery >>> • Devices are found, interfacesAdded callbacks are made, everything looks fine >>> • Stop discovery >>> • Directly some devices are removed by the interfacesRemoved callback >>> • My code does not get the device it searches for -> unhappy user >>> >>> What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. >>> So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: >>> >>>> HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Scan response - SCAN_RSP (0x04) >>> Address type: Public (0x00) >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> Data length: 26 >>> Name (complete): BeeWi SmartLite >>> Peripheral Conn. Interval: 0x0028 - 0x0050 >>> TX power: 0 dBm >>> RSSI: -42 dBm (0xd6) >>> @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> RSSI: -42 dBm (0xd6) >>> Flags: 0x00000004 >>> Not Connectable >>> Data length: 26 >>> Name (complete): BeeWi SmartLite >>> Peripheral Conn. Interval: 0x0028 - 0x0050 >>> TX power: 0 dBm >>> >>> But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: >>> >>>> HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Connectable undirected - ADV_IND (0x00) >>> Address type: Public (0x00) >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> Data length: 15 >>> Flags: 0x06 >>> LE General Discoverable Mode >>> BR/EDR Not Supported >>> Company: Texas Instruments Inc. (13) >>> Data: 06030108b0e408f7 >>> RSSI: -43 dBm (0xd5) >>> @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 >>> LE Address: 44:6E:FF:00:0D:65 (Resolvable) >>> RSSI: -74 dBm (0xb6) >>> Flags: 0x00000000 >>> Data length: 17 >>> Flags: 0x1a >>> LE General Discoverable Mode >>> Simultaneous LE and BR/EDR (Controller) >>> Simultaneous LE and BR/EDR (Host) >>> TX power: 9 dBm >>> Company: Apple, Inc. (76) >>> Type: Unknown (16) >>> Data: 01188898dc >>>> HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 >>> LE Advertising Report (0x02) >>> Num reports: 1 >>> Event type: Connectable undirected - ADV_IND (0x00) >>> Address type: Random (0x01) >>> Address: FA:BD:8D:12:26:BF (Static) >>> Data length: 29 >>> Name (short): P mesh >>> Flags: 0x04 >>> BR/EDR Not Supported >>> 128-bit Service UUIDs (partial): 1 entry >>> Vendor specific >>> RSSI: -47 dBm (0xd1) >>> @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) >>> RSSI: -43 dBm (0xd5) >>> Flags: 0x00000000 >>> Data length: 15 >>> Flags: 0x06 >>> LE General Discoverable Mode >>> BR/EDR Not Supported >>> Company: Texas Instruments Inc. (13) >>> Data: 06030108b0e408f7 >>> >>> So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: >>> >>> https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 >>> >>> It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? >> >> You are saying that the controller would interleave ADV_IND of >> different peers before SCAN_RSP, in that case yes that would be >> possible that the device would be marked as NOT_CONNECTABLE, usually >> that is not really the case which is why we end up adding the code >> above: >> >> * In the really unlikely case that a controller get confused >> * and just sends a scan response event, then it is marked as >> * not connectable as well. >> >> I guess it is not really unlikely after all, so perhaps we need a flag >> indicating this is a standalone SCAN_RSP e.g. MGMT_DEV_FOUND_SCAN_RSP, >> then we can treat it accordingly in userspace. > > Can you try with the following change: > > https://patchwork.kernel.org/project/bluetooth/patch/20230607194518.2901376-1-luiz.dentz@gmail.com/ > > -- > Luiz Augusto von Dentz I can confirm this change works. I see this now in the batman logs instead of the “Not Connectable”: @ MGMT Event: Device Found (0x0012) plen 34 {0x0001} [hci0] 37.727785 LE Address: E1:A1:94:4C:15:D8 (Static) RSSI: -80 dBm (0xb0) Flags: 0x00000020. <————— the new flag! Unknown device flag (0x00000020) Data length: 20 Name (complete): F48F92CBE54430A8EA ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intermittent Not connectable devices reported 2023-06-14 8:29 ` Herman Meerlo @ 2023-06-14 16:56 ` Luiz Augusto von Dentz 0 siblings, 0 replies; 7+ messages in thread From: Luiz Augusto von Dentz @ 2023-06-14 16:56 UTC (permalink / raw) To: Herman Meerlo; +Cc: linux-bluetooth Hi Herman, On Wed, Jun 14, 2023 at 1:29 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: > > > > > On 8 Jun 2023, at 18:32, Luiz Augusto von Dentz <luiz.dentz@gmail.com> wrote: > > > > Hi Herman, > > > > On Wed, Jun 7, 2023 at 12:21 PM Luiz Augusto von Dentz > > <luiz.dentz@gmail.com> wrote: > >> > >> Hi Herman, > >> > >> On Fri, Jun 2, 2023 at 2:51 AM Herman Meerlo <herman.meerlo@athom.nl> wrote: > >>> > >>> I'm working on a Raspberry Pi device that performs periodic BLE discovery and tries to connect to multiple devices. Most of the times this goes fine but especially in BLE heavy environments every now and then it fails because it says that the device is not found. I have been debugging this issue for a few weeks now and it comes down to this: > >>> > >>> • Connect to DBus to start the discovery > >>> • Devices are found, interfacesAdded callbacks are made, everything looks fine > >>> • Stop discovery > >>> • Directly some devices are removed by the interfacesRemoved callback > >>> • My code does not get the device it searches for -> unhappy user > >>> > >>> What happens under the hood is that DBus removes all devices from it's cache that have been indicated by Bluez as being Not connectable. I.e. there is no use in keeping them around, you can't connect to them anyway. But... this is not true for the device I'm looking for. It is marked as Not connectable incorrectly. > >>> So to chase down the problem I create a btmon dump which shows indeed that the device is reported to be Not connectable after having received a SCAN_RSP: > >>> > >>>> HCI Event: LE Meta Event (0x3e) plen 38 #73 [hci0] 34.359921 > >>> LE Advertising Report (0x02) > >>> Num reports: 1 > >>> Event type: Scan response - SCAN_RSP (0x04) > >>> Address type: Public (0x00) > >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) > >>> Data length: 26 > >>> Name (complete): BeeWi SmartLite > >>> Peripheral Conn. Interval: 0x0028 - 0x0050 > >>> TX power: 0 dBm > >>> RSSI: -42 dBm (0xd6) > >>> @ MGMT Event: Device Found (0x0012) plen 40 {0x0001} [hci0] 34.360057 > >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > >>> RSSI: -42 dBm (0xd6) > >>> Flags: 0x00000004 > >>> Not Connectable > >>> Data length: 26 > >>> Name (complete): BeeWi SmartLite > >>> Peripheral Conn. Interval: 0x0028 - 0x0050 > >>> TX power: 0 dBm > >>> > >>> But all ADV_IND PDU's before that clearly indicate that the device is connectable, it is only after this SCAN_RSP that it is reported as Not connectable: > >>> > >>>> HCI Event: LE Meta Event (0x3e) plen 27 #46 [hci0] 34.152817 > >>> LE Advertising Report (0x02) > >>> Num reports: 1 > >>> Event type: Connectable undirected - ADV_IND (0x00) > >>> Address type: Public (0x00) > >>> Address: F4:B8:5E:64:02:55 (Texas Instruments) > >>> Data length: 15 > >>> Flags: 0x06 > >>> LE General Discoverable Mode > >>> BR/EDR Not Supported > >>> Company: Texas Instruments Inc. (13) > >>> Data: 06030108b0e408f7 > >>> RSSI: -43 dBm (0xd5) > >>> @ MGMT Event: Device Found (0x0012) plen 31 {0x0001} [hci0] 34.152905 > >>> LE Address: 44:6E:FF:00:0D:65 (Resolvable) > >>> RSSI: -74 dBm (0xb6) > >>> Flags: 0x00000000 > >>> Data length: 17 > >>> Flags: 0x1a > >>> LE General Discoverable Mode > >>> Simultaneous LE and BR/EDR (Controller) > >>> Simultaneous LE and BR/EDR (Host) > >>> TX power: 9 dBm > >>> Company: Apple, Inc. (76) > >>> Type: Unknown (16) > >>> Data: 01188898dc > >>>> HCI Event: LE Meta Event (0x3e) plen 41 #47 [hci0] 34.156958 > >>> LE Advertising Report (0x02) > >>> Num reports: 1 > >>> Event type: Connectable undirected - ADV_IND (0x00) > >>> Address type: Random (0x01) > >>> Address: FA:BD:8D:12:26:BF (Static) > >>> Data length: 29 > >>> Name (short): P mesh > >>> Flags: 0x04 > >>> BR/EDR Not Supported > >>> 128-bit Service UUIDs (partial): 1 entry > >>> Vendor specific > >>> RSSI: -47 dBm (0xd1) > >>> @ MGMT Event: Device Found (0x0012) plen 29 {0x0001} [hci0] 34.157030 > >>> LE Address: F4:B8:5E:64:02:55 (Texas Instruments) > >>> RSSI: -43 dBm (0xd5) > >>> Flags: 0x00000000 > >>> Data length: 15 > >>> Flags: 0x06 > >>> LE General Discoverable Mode > >>> BR/EDR Not Supported > >>> Company: Texas Instruments Inc. (13) > >>> Data: 06030108b0e408f7 > >>> > >>> So I am heavily doubting whether the Linux kernel code has a bug in handling the SCAN_RSP. Please look at this part of the kernel: > >>> > >>> https://github.com/torvalds/linux/blob/48b1320a674e1ff5de2fad8606bee38f724594dc/net/bluetooth/hci_event.c#L6326 > >>> > >>> It sets the NOT CONNECTABLE flag by default for a SCAN_RSP and will overwrite it with any flags it has received with a previous ADV_IND. But it does not seem to take into account that in BLE heavy environments the previous ADV_IND might be of a totally different device. So every now and then it will enter the first path where it will just report the device with a NOT_CONNECTABLE flag. Or am I missing something here? > >> > >> You are saying that the controller would interleave ADV_IND of > >> different peers before SCAN_RSP, in that case yes that would be > >> possible that the device would be marked as NOT_CONNECTABLE, usually > >> that is not really the case which is why we end up adding the code > >> above: > >> > >> * In the really unlikely case that a controller get confused > >> * and just sends a scan response event, then it is marked as > >> * not connectable as well. > >> > >> I guess it is not really unlikely after all, so perhaps we need a flag > >> indicating this is a standalone SCAN_RSP e.g. MGMT_DEV_FOUND_SCAN_RSP, > >> then we can treat it accordingly in userspace. > > > > Can you try with the following change: > > > > https://patchwork.kernel.org/project/bluetooth/patch/20230607194518.2901376-1-luiz.dentz@gmail.com/ > > > > -- > > Luiz Augusto von Dentz > > I can confirm this change works. I see this now in the batman logs instead of the “Not Connectable”: > > > @ MGMT Event: Device Found (0x0012) plen 34 {0x0001} [hci0] 37.727785 > LE Address: E1:A1:94:4C:15:D8 (Static) > RSSI: -80 dBm (0xb0) > Flags: 0x00000020. <————— the new flag! > Unknown device flag (0x00000020) > Data length: 20 > Name (complete): F48F92CBE54430A8EA > Yeah, that is to be expected, I will document and add support to btmon to print the flag properly. -- Luiz Augusto von Dentz ^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2023-06-14 16:57 UTC | newest] Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2023-06-02 9:45 Intermittent Not connectable devices reported Herman Meerlo 2023-06-07 6:45 ` Herman Meerlo 2023-06-07 19:21 ` Luiz Augusto von Dentz 2023-06-08 16:32 ` Luiz Augusto von Dentz 2023-06-09 11:11 ` Herman Meerlo 2023-06-14 8:29 ` Herman Meerlo 2023-06-14 16:56 ` Luiz Augusto von Dentz
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.