RE: Bluetooth: fix endless adv params retry after a cancelled connection

RE: Bluetooth: fix endless adv params retry after a cancelled connection

[bluez.test.bot]

[-- Attachment #1: Type: text/plain, Size: 2389 bytes --]

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=1147269

---Test result---

Test Summary:
CheckPatch                    PASS      1.65 seconds
VerifyFixes                   PASS      0.13 seconds
VerifySignedoff               PASS      0.14 seconds
GitLint                       PASS      0.65 seconds
SubjectPrefix                 PASS      0.25 seconds
BuildKernel                   PASS      27.32 seconds
CheckAllWarning               PASS      29.88 seconds
CheckSparse                   PASS      28.87 seconds
BuildKernel32                 PASS      30.57 seconds
CheckKernelLLVM               SKIP      0.00 seconds
TestRunnerSetup               PASS      499.72 seconds
TestRunner_l2cap-tester       PASS      66.25 seconds
TestRunner_iso-tester         PASS      80.03 seconds
TestRunner_bnep-tester        PASS      19.40 seconds
TestRunner_mgmt-tester        FAIL      222.42 seconds
TestRunner_rfcomm-tester      PASS      25.40 seconds
TestRunner_sco-tester         PASS      31.73 seconds
TestRunner_ioctl-tester       PASS      26.30 seconds
TestRunner_mesh-tester        FAIL      25.99 seconds
TestRunner_smp-tester         PASS      23.88 seconds
TestRunner_userchan-tester    PASS      20.74 seconds
TestRunner_6lowpan-tester     PASS      23.54 seconds
IncrementalBuild              PASS      34.39 seconds

Details
##############################
Test: CheckKernelLLVM - SKIP
Desc: Build kernel with LLVM + context analysis
Output:
Clang not found
##############################
Test: TestRunner_mgmt-tester - FAIL
Desc: Run mgmt-tester with test-runner
Output:
Total: 501, Passed: 496 (99.0%), Failed: 1, Not Run: 4

Failed Test Cases
Read Exp Feature - Success                           Failed       0.248 seconds
##############################
Test: TestRunner_mesh-tester - FAIL
Desc: Run mesh-tester with test-runner
Output:
Total: 10, Passed: 8 (80.0%), Failed: 2, Not Run: 0

Failed Test Cases
Mesh - Send cancel - 1                               Timed out    2.347 seconds
Mesh - Send cancel - 2                               Timed out    1.986 seconds


https://github.com/bluez/bluetooth-next/pull/600

---
Regards,
Linux Bluetooth

[PATCH v4 0/2] Bluetooth: fix endless adv params retry after a cancelled connection

[Valentin Kindschi]

A gateway device that advertises as a peripheral while also making
outgoing central connections gets stuck logging

  Bluetooth: hci0: Opcode 0x2006 failed: -16

every 2 s indefinitely, starting seconds after an outgoing connection
attempt times out and is cancelled. Measured on one unit: 5326
occurrences over 3 hours, ending only when bluetoothd was restarted,
which resets the controller.

The controller is behaving per specification: LE Set Advertising
Parameters is Command Disallowed while advertising is enabled. The host
issues it anyway, and then cannot recover.

Sequence, from btmon (BCM43455, no LE Extended Advertising, so legacy
advertising and the software rotation loop are in use):

  LE Create Connection                     Status Success
  ... 13.8 s, peer does not answer ...
  LE Set Advertising Parameters   0x2006    Success        \ done: resume
  LE Set Advertising Enable       0x200a    Success        / HCI_LE_ADV set
  LE Create Connection Cancel     0x200e    Success
  LE Connection Complete                    Unknown Conn Id
  LE Set Advertising Parameters   0x2006    Command Disallowed   [+63 ms]
  LE Set Advertising Parameters   0x2006    Command Disallowed   [+1.954 s]
  LE Set Advertising Parameters   0x2006    Command Disallowed   [+2.016 s]
  ... every ~2.016 s, for hours, and no 0x200a is ever sent again

Three connection attempts earlier in the same capture that *succeeded*
show the same 0x2006 + 0x200a pair and do not trigger this. Only an
attempt that times out and is cancelled does.

Why it never recovers: hci_enable_advertising_sync() returns as soon as
LE Set Advertising Parameters fails, before the LE Set Advertising Enable
that would set HCI_LE_ADV. hci_schedule_adv_instance_sync() re-arms
adv_instance_expire every HCI_DEFAULT_ADV_DURATION (2 s) and its
"already advertising" shortcut tests HCI_LE_ADV, which can no longer
become true. hci_disable_advertising_sync() cannot break the tie either -
it returns without sending anything while HCI_LE_ADV is clear, which is
exactly when the flag is wrong.

Patch 1 removes the redundant advertising enable that creates the
mismatch. Patch 2 stops HCI_LE_ADV being cleared for a connection
complete that reports no connection.

Patch 1 has been verified on the affected device. btmon counts:

  before, 2.6 min capture: 78 LE Set Advertising Parameters sent,
                           78 Command Disallowed, 0 LE Set Advertising
                           Enable sent
  after,  2.0 min capture:  3 LE Set Advertising Parameters sent,
                            0 Command Disallowed, 5 LE Set Advertising
                            Enable sent, all successful

The enable being sent and accepted again is the point: HCI_LE_ADV gets
set, so the rotation loop's shortcut works and nothing accumulates.

Patch 2, in its v4 !status form, has since been tested on the same
device with both patches applied. A 221 s capture contains two outgoing
connection attempts to an out-of-range peer that the host cancelled:

  LE Set Advertising Parameters   0x2006    Success
  LE Set Advertising Enable       0x200a    Success
  LE Create Connection Cancel     0x200e    Success
  LE Connection Complete                    Unknown Conn Id   [central]

Nothing follows either event; the next command is an unrelated scan
restart 70 ms later, where before the fixes a Command Disallowed appeared
at +63 ms and then every ~2 s. Over the capture: 7 LE Set Advertising
Parameters and 10 LE Set Advertising Enable, all Success, no Command
Disallowed of any opcode. Two central connections to other peers
completed normally afterwards, so advertising survived the cancelled
attempts. Patch 2's effect is still not separately attributable from
patch 1's, as both were applied.

Both apply to bluetooth-next. A 6.12.y backport needs a small context
adjustment in patch 2 (mainline has hci_store_wake_reason() in
le_conn_complete_evt()); I can send it if wanted.

A third, unrelated Command Disallowed on the same device - LE Set Random
Address refused on every active scan restart because advertising is only
paused for the address update when LL privacy is in use - is sent
separately, as it has a different cause and touches hci_sync.c only.

Tooling disclosure (Documentation/process/generated-content.rst):
the bug was found and the patches drafted with the help of an AI coding
assistant, over a debugging session on the affected hardware. The inputs
were btmon captures and kernel logs from the device; the assistant was
asked to identify what re-issues LE Set Advertising Parameters every 2 s
and to propose a fix. Its first two proposed mechanisms were wrong and
were discarded after being checked against the captures; a third proposed
change (making hci_disable_advertising_sync() always emit the disable)
was built and tested on the device, broke advertising registration
outright, and was dropped. The two patches here are what survived. All
code and reasoning were reviewed by the submitter, and the verification
numbers above were measured on hardware.

Changes in v4:
- Patch 2 now tests !status rather than excluding only
  HCI_ERROR_UNKNOWN_CONN_ID, per review, and its changelog covers the
  extended advertising point raised there. Built and tested on the device
  in that form; the capture above is from this version.
- Patch 1 is unchanged.

Changes in v3:
- Shortened both subject lines to fit the 80-character limit and removed
  hard tabs from the changelog bodies (GitLint). No functional change.
- On the CI failures reported for v2, which I believe are unrelated:

  The two mesh-tester "Send cancel" timeouts reproduce on an unpatched
  kernel. Running bluez master's mesh-tester against stock 6.8.0 gives
  Total: 10, Passed: 8, Failed: 2 with the same two cases failing - the
  same result CI reports here, on a kernel that never carried these
  patches.

  mgmt-tester "Read Exp Feature - Success" also fails on that unpatched
  kernel, though my local mgmt run is not a clean baseline (424/501 there
  versus 496/501 on CI, which looks like tester/kernel version skew in my
  environment). Independently, that test exercises the experimental
  features read on index 0xffff with no controller involved, which none of
  these patches touch.

  Of the last 25 pull requests on bluez/bluetooth-next, these two suites
  ran on 10 and failed on all 10, including changes that cannot plausibly
  affect them (btintel version parsing, eir OOB read, devcoredump
  teardown); the other 15 are driver-only series where they are skipped.

  Happy to be told otherwise if these are in fact expected to pass.

Changes in v2:
- Rebased onto bluetooth-next. v1 was generated against 6.12.y and the
  hci_event.c hunk did not apply to HEAD, because mainline calls
  hci_store_wake_reason() in le_conn_complete_evt() and v1's context did
  not include it. No functional change; the fix is identical.

Valentin Kindschi (2):
  Bluetooth: hci_conn: re-enable advertising only for peripheral role
  Bluetooth: hci_event: keep HCI_LE_ADV set if the host cancelled

 net/bluetooth/hci_conn.c  |  3 ++-
 net/bluetooth/hci_event.c |  8 +++++---
 2 files changed, 7 insertions(+), 4 deletions(-)

--
2.34.1

[PATCH v4 1/2] Bluetooth: hci_conn: re-enable advertising only for peripheral role

[Valentin Kindschi]

hci_le_conn_failed() unconditionally calls hci_enable_advertising(),
although its own comment states advertising should be re-enabled only
when the failed attempt was made as a peripheral.

hci_le_conn_failed() is reached from hci_conn_failed() for every failed
LE connection, including outgoing central connections. For a central
attempt this enable is redundant: hci_le_create_conn_sync() already
restores advertising via hci_resume_advertising_sync() in its done:
block. Because hci_enable_advertising() only queues the work on
cmd_sync_work, it runs *after* that resume has already succeeded and
set HCI_LE_ADV.

The resulting HCI sequence, captured on a BCM43455 (no LE Extended
Advertising, so legacy advertising is used):

  LE Create Connection                     Status Success
  ... 13.8 s, peer never answers ...
  LE Set Advertising Parameters (0x2006)   Success   <- done: resume,
  LE Set Advertising Enable     (0x200a)   Success      HCI_LE_ADV set
  LE Create Connection Cancel   (0x200e)   Success
  LE Connection Complete                   Unknown Conn Id
  LE Set Advertising Parameters (0x2006)   Command Disallowed (0x0c)

The last command is the queued enable from hci_le_conn_failed() running
as a second hci_enable_advertising_sync() pass. It clears HCI_LE_ADV
(hci_sync.c, "Clear the HCI_LE_ADV bit temporarily"), then sends
LE Set Advertising Parameters while the controller is still advertising,
which the controller correctly rejects with Command Disallowed.

The disable-first call at the top of hci_enable_advertising_sync()
cannot prevent this: hci_disable_advertising_sync() returns early
without sending anything when HCI_LE_ADV is clear, so it is a no-op
exactly when the flag is wrong.

hci_enable_advertising_sync() then returns without sending LE Set
Advertising Enable, so HCI_LE_ADV is never set again. The legacy
software rotation loop re-arms hci_schedule_adv_instance_sync() every
HCI_DEFAULT_ADV_DURATION (2 s), and its "already advertising" shortcut
tests HCI_LE_ADV, which can no longer become true. The command is
therefore retried every 2 s indefinitely:

  Bluetooth: hci0: Opcode 0x2006 failed: -16

Observed on a gateway as 5326 occurrences over 3 hours, ending only when
bluetoothd was restarted. Connection attempts that succeed do not call
hci_le_conn_failed() and never trigger this.

Add the role test the comment already describes. Both other
hci_enable_advertising() call sites reached from a failed/closed LE
connection (hci_cs_disconnect() and hci_disconn_complete_evt()) already
guard on conn->role == HCI_ROLE_SLAVE; this one was missed.

Reproducing needs legacy advertising (ext_adv_capable() false, so the
software rotation loop is used), simultaneous peripheral advertising and
outgoing central connects, and a central connect that times out rather
than failing fast.

The Fixes tag points at the commit that introduced the advertising
restart into this path for the directed-advertising (peripheral) case;
the role test that the later commit 0b1db38ca26b ("Bluetooth: Fix check
for direct advertising") added to the sibling paths was never applied
here.

Fixes: 3c857757ef6e ("Bluetooth: Add directed advertising support through connect()")
Cc: stable@vger.kernel.org
Assisted-by: Claude:claude-opus-5 btmon
Signed-off-by: Valentin Kindschi <valentin.kindschi@fiveco.ch>
---
Changes in v2:
- Rebased onto bluetooth-next; no functional change.

 net/bluetooth/hci_conn.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/net/bluetooth/hci_conn.c b/net/bluetooth/hci_conn.c
--- a/net/bluetooth/hci_conn.c
+++ b/net/bluetooth/hci_conn.c
@@ -1262,7 +1262,8 @@ static void hci_le_conn_failed(struct hci_conn *conn, u8 status)
 	/* Enable advertising in case this was a failed connection
 	 * attempt as a peripheral.
 	 */
-	hci_enable_advertising(hdev);
+	if (conn->role == HCI_ROLE_SLAVE)
+		hci_enable_advertising(hdev);
 }

 /* This function requires the caller holds hdev->lock */
--
2.34.1

[PATCH v4 2/2] Bluetooth: hci_event: clear HCI_LE_ADV only on a created connection

[Valentin Kindschi]

le_conn_complete_evt() clears HCI_LE_ADV before looking at the event
status, on the premise stated in its comment that all controllers stop
advertising when a connection is created.

That premise only holds when a connection was actually created. On a
non-zero status none was, and the controller is still advertising: after
the host issues LE Create Connection Cancel the event arrives with
Unknown Connection Identifier (0x02), and a connection timeout behaves
the same way. Clearing the flag there leaves the host believing
advertising is off while the controller has it on.

It is also wrong for extended advertising, where several sets can be
advertising at once. hci_cc_le_set_ext_adv_enable() is careful about
this - on disabling one set it walks hdev->adv_instances and only clears
HCI_LE_ADV once no instance is still enabled. The unconditional clear
here discards that bookkeeping, so one set connecting drops the flag
while the others keep advertising.

The direction of the error matters. A flag left set is self-correcting:
hci_disable_advertising_sync() sends LE Set Advertising Enable(0) and
the command complete puts the state back. A flag left clear is not,
because that same function returns early without sending anything while
the flag is clear:

  - LE Set Advertising Parameters is then sent to a controller that is
    still advertising, and is correctly rejected with Command Disallowed
    (0x0c);
  - hci_enable_advertising_sync() returns at that point, before the
    LE Set Advertising Enable that would set HCI_LE_ADV again.

On a controller without LE Extended Advertising that is reachable from
here: hci_schedule_adv_instance_sync() re-arms adv_instance_expire every
HCI_DEFAULT_ADV_DURATION (2 s) and its "already advertising" shortcut
tests HCI_LE_ADV, which can no longer become true, so the parameter
write is retried for as long as advertising is configured:

  Bluetooth: hci0: Opcode 0x2006 failed: -16

Only clear the flag when a connection was established.

Note this is not on its own sufficient to stop that retry loop - the
redundant enable queued by hci_le_conn_failed() clears HCI_LE_ADV itself
and recreates the same mismatch, which patch 1 addresses. This patch
fixes the event handler reporting a state the controller is not in.

Verified on the affected device (BCM43455, legacy advertising only) with
this patch and patch 1 applied. A 221 s btmon capture with an out-of-range
peer at -90 dBm contains two outgoing connection attempts that the host
cancelled, each producing exactly the event this patch changes:

  < LE Set Advertising Parameters  0x2006   Success
  < LE Set Advertising Enable      0x200a   Success
  < LE Create Connection Cancel    0x200e   Success
  > LE Connection Complete   Unknown Connection Identifier (0x02), central

Nothing follows either one; the next command is an unrelated scan restart
70 ms later. Over the whole capture: 7 LE Set Advertising Parameters sent,
all Success; 10 LE Set Advertising Enable, all Success; no Command
Disallowed of any opcode, and no 2 s cadence anywhere. Two central
connections to other peers completed normally afterwards, with feature
exchange and a connection parameter update, so advertising was still live
across the cancelled attempts.

The extended advertising case above is a code argument, not a measurement:
this controller has no LE Extended Advertising, so that path is not
exercised by the capture.

Fixes: fbd96c151cdc ("Bluetooth: Fix clearing HCI_LE_ADV for LE connections")
Cc: stable@vger.kernel.org
Assisted-by: Claude:claude-opus-5 btmon
Signed-off-by: Valentin Kindschi <valentin.kindschi@fiveco.ch>
---
Changes in v4:
- Test !status instead of status != HCI_ERROR_UNKNOWN_CONN_ID, per review:
  a connection timeout should not clear the flag either. Built and tested
  on the device in that form; the capture quoted above is from this
  version, so the effect is now measured rather than inferred as in v2/v3.
- Note the extended-advertising case raised in review: several sets can be
  advertising at once, and hci_cc_le_set_ext_adv_enable() already tracks
  that per instance, which the unconditional clear here was discarding.
- On Advertising Timeout (0x3c), which v2/v3 used to justify a narrower
  test: a controller can report it, since hci_le_directed_advertising_sync()
  uses high duty cycle directed advertising. Not clearing the flag there is
  harmless because directed advertising is always bracketed by
  hci_pause_advertising_sync() / hci_resume_advertising_sync() in
  hci_le_create_conn_sync(), and the resume re-schedules with force=true,
  which bypasses the HCI_LE_ADV shortcut. le_conn_timeout() also disables
  advertising itself on the peripheral path.
- A stale-set flag is self-correcting (hci_disable_advertising_sync() then
  sends the disable) whereas a stale-clear flag is self-sustaining, which is
  the bug here, so erring towards set is the safer direction.

Changes in v3:
- Shortened the subject and removed hard tabs from the changelog (GitLint).

Changes in v2:
- Rebased onto bluetooth-next; no functional change.
  v1's hci_event.c context lacked the hci_store_wake_reason() call
  present in mainline, so the hunk did not apply.

 net/bluetooth/hci_event.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -5720,10 +5720,11 @@ static void le_conn_complete_evt(struct hci_dev *hdev, u8 status,
 	hci_dev_lock(hdev);
 	hci_store_wake_reason(hdev, bdaddr, bdaddr_type);
 
-	/* All controllers implicitly stop advertising in the event of a
-	 * connection, so ensure that the state bit is cleared.
+	/* Advertising stops when a connection is created. On a failed
+	 * connection it keeps running, so leave the state bit alone.
 	 */
-	hci_dev_clear_flag(hdev, HCI_LE_ADV);
+	if (!status)
+		hci_dev_clear_flag(hdev, HCI_LE_ADV);
 
 	/* Check for existing connection:
 	 *
--
2.34.1

RE: Bluetooth: fix endless adv params retry after a cancelled connection

[bluez.test.bot]

[-- Attachment #1: Type: text/plain, Size: 2396 bytes --]

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=1147864

---Test result---

Test Summary:
CheckPatch                    PASS      129.83 seconds
VerifyFixes                   PASS      31.66 seconds
VerifySignedoff               PASS      29.18 seconds
GitLint                       PASS      54.19 seconds
SubjectPrefix                 PASS      9.42 seconds
BuildKernel                   PASS      27.95 seconds
CheckAllWarning               PASS      32.02 seconds
CheckSparse                   PASS      40.40 seconds
BuildKernel32                 PASS      54.02 seconds
CheckKernelLLVM               SKIP      0.00 seconds
TestRunnerSetup               PASS      523.32 seconds
TestRunner_l2cap-tester       PASS      102.83 seconds
TestRunner_iso-tester         PASS      84.41 seconds
TestRunner_bnep-tester        PASS      22.08 seconds
TestRunner_mgmt-tester        FAIL      243.75 seconds
TestRunner_rfcomm-tester      PASS      41.81 seconds
TestRunner_sco-tester         PASS      40.28 seconds
TestRunner_ioctl-tester       PASS      30.45 seconds
TestRunner_mesh-tester        FAIL      27.35 seconds
TestRunner_smp-tester         PASS      28.03 seconds
TestRunner_userchan-tester    PASS      46.05 seconds
TestRunner_6lowpan-tester     PASS      44.01 seconds
IncrementalBuild              PASS      173.49 seconds

Details
##############################
Test: CheckKernelLLVM - SKIP
Desc: Build kernel with LLVM + context analysis
Output:
Clang not found
##############################
Test: TestRunner_mgmt-tester - FAIL
Desc: Run mgmt-tester with test-runner
Output:
Total: 501, Passed: 496 (99.0%), Failed: 1, Not Run: 4

Failed Test Cases
Read Exp Feature - Success                           Failed       0.257 seconds
##############################
Test: TestRunner_mesh-tester - FAIL
Desc: Run mesh-tester with test-runner
Output:
Total: 10, Passed: 8 (80.0%), Failed: 2, Not Run: 0

Failed Test Cases
Mesh - Send cancel - 1                               Timed out    2.696 seconds
Mesh - Send cancel - 2                               Timed out    1.988 seconds


https://github.com/bluez/bluetooth-next/pull/610

---
Regards,
Linux Bluetooth