Re: [PATCH v2] Bluetooth: Always call advertising disable before setting params

From: Daniel Winkler
Date: Thu Mar 25 2021 - 13:28:28 EST


Hi all,

It looks like my change breaks the expectations of one mgmt-tester
test, which uses an Adv Enable (True) as a test condition. It is
surprised to first see an Adv Enable (False) in the HCI traffic, and
fails. I think my suggested approach here is the simplest and most
robust to solve this race condition, so if the maintainers are happy
with it, I can look into changing the test expectations to suit the
new scenario. Please advise.

Thanks in advance,
Daniel

On Wed, Mar 24, 2021 at 11:47 AM Daniel Winkler
<danielwinkler@xxxxxxxxxx> wrote:
>
> In __hci_req_enable_advertising, the HCI_LE_ADV hdev flag is temporarily
> cleared to allow the random address to be set, which exposes a race
> condition when an advertisement is configured immediately (<10ms) after
> software rotation starts to refresh an advertisement.
>
> In normal operation, the HCI_LE_ADV flag is updated as follows:
>
> 1. adv_timeout_expire is called, HCI_LE_ADV gets cleared in
> __hci_req_enable_advertising, but hci_req configures an enable
> request
> 2. hci_req is run, enable callback re-sets HCI_LE_ADV flag
>
> However, in this race condition, the following occurs:
>
> 1. adv_timeout_expire is called, HCI_LE_ADV gets cleared in
> __hci_req_enable_advertising, but hci_req configures an enable
> request
> 2. add_advertising is called, which also calls
> __hci_req_enable_advertising. Because HCI_LE_ADV was cleared in Step
> 1, no "disable" command is queued.
> 3. hci_req for adv_timeout_expire is run, which enables advertising and
> re-sets HCI_LE_ADV
> 4. hci_req for add_advertising is run, but because no "disable" command
> was queued, we try to set advertising parameters while advertising is
> active, causing a Command Disallowed error, failing the registration.
>
> To resolve the issue, this patch removes the check for the HCI_LE_ADV
> flag, and always queues the "disable" request, since HCI_LE_ADV could be
> very temporarily out-of-sync. According to the spec, there is no harm in
> calling "disable" when advertising is not active.
>
> An example trace showing the HCI error in setting advertising parameters
> is included below, with some notes annotating the states I mentioned
> above:
>
> @ MGMT Command: Add Ext Adv.. (0x0055) plen 35 {0x0001} [hci0]04:05.884
> Instance: 3
> Advertising data length: 24
> 16-bit Service UUIDs (complete): 2 entries
> Location and Navigation (0x1819)
> Phone Alert Status Service (0x180e)
> Company: not assigned (65283)
> Data: 3a3b3c3d3e
> Service Data (UUID 0x9993): 3132333435
> Scan response length: 0
> @ MGMT Event: Advertising Ad.. (0x0023) plen 1 {0x0005} [hci0]04:05.885
> Instance: 3
>
> === adv_timeout_expire request starts running. This request was created
> before our add advertising request
> > HCI Event: Command Complete (0x0e) plen 4 #220 [hci0]04:05.993
> LE Set Advertising Data (0x08|0x0008) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan.. (0x08|0x0009) plen 32 #221 [hci0]04:05.993
> Length: 24
> Service Data (UUID 0xabcd): 161718191a1b1c1d1e1f2021222324252627
> > HCI Event: Command Complete (0x0e) plen 4 #222 [hci0]04:05.995
> LE Set Scan Response Data (0x08|0x0009) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Adver.. (0x08|0x000a) plen 1 #223 [hci0]04:05.995
> Advertising: Disabled (0x00)
> > HCI Event: Command Complete (0x0e) plen 4 #224 [hci0]04:05.997
> LE Set Advertise Enable (0x08|0x000a) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Adve.. (0x08|0x0006) plen 15 #225 [hci0]04:05.997
> Min advertising interval: 200.000 msec (0x0140)
> Max advertising interval: 200.000 msec (0x0140)
> Type: Connectable undirected - ADV_IND (0x00)
> Own address type: Public (0x00)
> Direct address type: Public (0x00)
> Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
> Channel map: 37, 38, 39 (0x07)
> Filter policy: Allow Scan Request, Connect from Any (0x00)
> > HCI Event: Command Complete (0x0e) plen 4 #226 [hci0]04:05.998
> LE Set Advertising Parameters (0x08|0x0006) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Adver.. (0x08|0x000a) plen 1 #227 [hci0]04:05.999
> Advertising: Enabled (0x01)
> > HCI Event: Command Complete (0x0e) plen 4 #228 [hci0]04:06.000
> LE Set Advertise Enable (0x08|0x000a) ncmd 1
> Status: Success (0x00)
>
> === Our new add_advertising request starts running
> < HCI Command: Read Local N.. (0x03|0x0014) plen 0 #229 [hci0]04:06.001
> > HCI Event: Command Complete (0x0e) plen 252 #230 [hci0]04:06.005
> Read Local Name (0x03|0x0014) ncmd 1
> Status: Success (0x00)
> Name: Chromebook_FB3D
>
> === Although the controller is advertising, no disable command is sent
> < HCI Command: LE Set Adve.. (0x08|0x0006) plen 15 #231 [hci0]04:06.005
> Min advertising interval: 200.000 msec (0x0140)
> Max advertising interval: 200.000 msec (0x0140)
> Type: Connectable undirected - ADV_IND (0x00)
> Own address type: Public (0x00)
> Direct address type: Public (0x00)
> Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
> Channel map: 37, 38, 39 (0x07)
> Filter policy: Allow Scan Request, Connect from Any (0x00)
> > HCI Event: Command Complete (0x0e) plen 4 #232 [hci0]04:06.005
> LE Set Advertising Parameters (0x08|0x0006) ncmd 1
> Status: Command Disallowed (0x0c)
>
> Reviewed-by: Miao-chen Chou <mcchou@xxxxxxxxxxxx>
> Signed-off-by: Daniel Winkler <danielwinkler@xxxxxxxxxx>
> ---
>
> Changes in v2:
> - Added btmon snippet showing HCI command failure
>
> net/bluetooth/hci_request.c | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/net/bluetooth/hci_request.c b/net/bluetooth/hci_request.c
> index 8ace5d34b01efe..2b4b99f4cedf21 100644
> --- a/net/bluetooth/hci_request.c
> +++ b/net/bluetooth/hci_request.c
> @@ -1547,8 +1547,10 @@ void __hci_req_enable_advertising(struct hci_request *req)
> if (!is_advertising_allowed(hdev, connectable))
> return;
>
> - if (hci_dev_test_flag(hdev, HCI_LE_ADV))
> - __hci_req_disable_advertising(req);
> + /* Request that the controller stop advertising. This can be called
> + * whether or not there is an active advertisement.
> + */
> + __hci_req_disable_advertising(req);
>
> /* Clear the HCI_LE_ADV bit temporarily so that the
> * hci_update_random_address knows that it's safe to go ahead
> --
> 2.31.0.291.g576ba9dcdaf-goog
>