Bluez5 from master on 27 June 2022
1d6cfb8e625a944010956714c1802bc1e1fc6c4f
monitor: Fix crash when using RTT backend
Kernel:
5.4.199
After turning scan on, after a short time it hangs.? Here are the packets to start discovery:
< HCI Command: LE Set Exte.. (0x08|0x0042) plen 6 ?#1777 [hci0] 11:06:02.731748
? ? ? ? Extended scan: Enabled (0x01)
? ? ? ? Filter duplicates: Enabled (0x01)
? ? ? ? Duration: 0 msec (0x0000)
? ? ? ? Period: 0.00 sec (0x0000)
> HCI Event: Command Complete (0x0e) plen 4 ? ? ? ?#1778 [hci0] 11:06:02.741529
? ? ? LE Set Extended Scan Enable (0x08|0x0042) ncmd 1
? ? ? ? Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 ?{0x0001} [hci0] 11:06:02.741819
? ? ? Start Discovery (0x0023) plen 1
? ? ? ? Status: Success (0x00)
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
@ MGMT Event: Discovering (0x0013) plen 2 ? ? ? {0x0001} [hci0] 11:06:02.741899
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
? ? ? ? Discovery: Enabled (0x01)
After a short time and 1215 devices found (0x0012), no commands may be executed:
bluetooth]# scan off
Failed to stop discovery: org.bluez.Error.InProgress
btmon output looks stuck.? Often the output stops in the middle of an event:
> HCI Event: LE Meta Event (0x3e) plen 41 ? ? ? ? ?#3484 [hci0] 11:06:13.493567
? ? ? LE Extended Advertising Report (0x0d)
? ? ? ? Num reports: 1
? ? ? ? Entry 0
? ? ? ? ? Event type: 0x0010
? ? ? ? ? ? Props: 0x0010
? ? ? ? ? ? ? Use legacy advertising PDUs
? ? ? ? ? ? Data status: ^[[0;32mComplete^[[0m
? ? ? ? ? Legacy PDU Type: ADV_NONCONN_IND (0x0010)
? ? ? ? ? Address type: Random (0x01)
? ? ? ? ? Address: 0C:7D:02:DB:5A:57 (Non-Resolvable)
? ? ? ? ? Prima
Note that "Primary PHY" is incomplete.
The hang during scan happens 100% of the time.
John Klug
I was running btmon through pcat to avoid running out of space on the device.? I think this was causing packets to be cut off midstream at the end.
Here is the btmon output when turning scan off:
? ? ? LE Extended Advertising Report (0x0d)
? ? ? ? Num reports: 1
? ? ? ? Entry 0
? ? ? ? ? Event type: 0x0010
? ? ? ? ? ? Props: 0x0010
? ? ? ? ? ? ? Use legacy advertising PDUs
? ? ? ? ? ? Data status: Complete
? ? ? ? ? Legacy PDU Type: ADV_NONCONN_IND (0x0010)
? ? ? ? ? Address type: Random (0x01)
? ? ? ? ? Address: 06:62:7D:C6:64:48 (Non-Resolvable)
? ? ? ? ? Primary PHY: LE 1M
? ? ? ? ? Secondary PHY: No packets
? ? ? ? ? SID: no ADI field (0xff)
? ? ? ? ? TX power: 127 dBm
? ? ? ? ? RSSI: -68 dBm (0xbc)
? ? ? ? ? Periodic advertising interval: 0.00 msec (0x0000)
? ? ? ? ? Direct address type: Public (0x00)
? ? ? ? ? Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
? ? ? ? ? Data length: 0x1f
? ? ? ? 1e ff 06 00 01 09 20 02 74 f5 eb a3 76 9d e7 b5 ?...... .t...v...
? ? ? ? 11 e6 85 a0 41 ca 09 4d 27 f1 f6 dc a5 5f bc ? ? ....A..M'...._.
? ? ? ? Company: Microsoft (6)
? ? ? ? ? Data: 0109200274f5eba3769de7b511e685a041ca094d27f1f6dca55fbc
@ MGMT Command: Stop Discovery (0x0024) plen 1 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? {0x0001} [hci0] 159.216816
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
@ MGMT Event: Command Complete (0x0001) plen 4 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? {0x0001} [hci0] 159.220056
? ? ? Stop Discovery (0x0024) plen 1
? ? ? ? Status: Rejected (0x0b)
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
John Klug
From: John Klug
Sent: Wednesday, July 6, 2022 5:23 PM
To: Linux-Bluetooth MailingList <[email protected]>
Subject: [BUG] Extended Scan Hangs
?
Bluez5 from master on 27 June 2022
1d6cfb8e625a944010956714c1802bc1e1fc6c4f
monitor: Fix crash when using RTT backend
Kernel:
5.4.199
After turning scan on, after a short time it hangs.? Here are the packets to start discovery:
< HCI Command: LE Set Exte.. (0x08|0x0042) plen 6 ?#1777 [hci0] 11:06:02.731748
? ? ? ? Extended scan: Enabled (0x01)
? ? ? ? Filter duplicates: Enabled (0x01)
? ? ? ? Duration: 0 msec (0x0000)
? ? ? ? Period: 0.00 sec (0x0000)
> HCI Event: Command Complete (0x0e) plen 4 ? ? ? ?#1778 [hci0] 11:06:02.741529
? ? ? LE Set Extended Scan Enable (0x08|0x0042) ncmd 1
? ? ? ? Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4 ?{0x0001} [hci0] 11:06:02.741819
? ? ? Start Discovery (0x0023) plen 1
? ? ? ? Status: Success (0x00)
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
@ MGMT Event: Discovering (0x0013) plen 2 ? ? ? {0x0001} [hci0] 11:06:02.741899
? ? ? ? Address type: 0x06
? ? ? ? ? LE Public
? ? ? ? ? LE Random
? ? ? ? Discovery: Enabled (0x01)
After a short time and 1215 devices found (0x0012), no commands may be executed:
bluetooth]# scan off
Failed to stop discovery: org.bluez.Error.InProgress
btmon output looks stuck.? Often the output stops in the middle of an event:
> HCI Event: LE Meta Event (0x3e) plen 41 ? ? ? ? ?#3484 [hci0] 11:06:13.493567
? ? ? LE Extended Advertising Report (0x0d)
? ? ? ? Num reports: 1
? ? ? ? Entry 0
? ? ? ? ? Event type: 0x0010
? ? ? ? ? ? Props: 0x0010
? ? ? ? ? ? ? Use legacy advertising PDUs
? ? ? ? ? ? Data status: ^[[0;32mComplete^[[0m
? ? ? ? ? Legacy PDU Type: ADV_NONCONN_IND (0x0010)
? ? ? ? ? Address type: Random (0x01)
? ? ? ? ? Address: 0C:7D:02:DB:5A:57 (Non-Resolvable)
? ? ? ? ? Prima
Note that "Primary PHY" is incomplete.
The hang during scan happens 100% of the time.
John Klug
Hi John,
On Wed, Jul 6, 2022 at 3:56 PM John Klug <[email protected]> wrote:
>
> I was running btmon through pcat to avoid running out of space on the device. I think this was causing packets to be cut off midstream at the end.
>
> Here is the btmon output when turning scan off:
>
> LE Extended Advertising Report (0x0d)
> Num reports: 1
> Entry 0
> Event type: 0x0010
> Props: 0x0010
> Use legacy advertising PDUs
> Data status: Complete
> Legacy PDU Type: ADV_NONCONN_IND (0x0010)
> Address type: Random (0x01)
> Address: 06:62:7D:C6:64:48 (Non-Resolvable)
> Primary PHY: LE 1M
> Secondary PHY: No packets
> SID: no ADI field (0xff)
> TX power: 127 dBm
> RSSI: -68 dBm (0xbc)
> Periodic advertising interval: 0.00 msec (0x0000)
> Direct address type: Public (0x00)
> Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
> Data length: 0x1f
> 1e ff 06 00 01 09 20 02 74 f5 eb a3 76 9d e7 b5 ...... .t...v...
> 11 e6 85 a0 41 ca 09 4d 27 f1 f6 dc a5 5f bc ....A..M'...._.
> Company: Microsoft (6)
> Data: 0109200274f5eba3769de7b511e685a041ca094d27f1f6dca55fbc
> @ MGMT Command: Stop Discovery (0x0024) plen 1 {0x0001} [hci0] 159.216816
> Address type: 0x06
> LE Public
> LE Random
> @ MGMT Event: Command Complete (0x0001) plen 4 {0x0001} [hci0] 159.220056
> Stop Discovery (0x0024) plen 1
> Status: Rejected (0x0b)
> Address type: 0x06
> LE Public
> LE Random
Looks like a bug in the kernel since it is rejecting the stop
discovery, have you checked if there are any fixes for it later on?