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

[Valentin Kindschi <valentin.kindschi@fiveco.ch>]

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