IssueTracker

Intro

This is a follow-up to BLE 'direct' connect doesn't time out, AOSP 235446122, which was reported for the Android 13 beta program and has been closed for further comments - though the issue still persists in the public release of Android 13 :(

Recap of the issue:

'Direct' BLE connection attempts made via BluetoothGatt#connectGatt(.., false, ..) are expected to time out after 30 sec on Pixel phones. However, for Android 13 the 'direct' BLE connection attempts only time out correctly when the BLE device is NOT bonded. In cases where the BLE device is bonded, the connection attempt only times out at the lower layers, e.g. it can be seen in the HCI log that the connection is cancelled, but this never propagates up to the Java layer and the app requesting the connection attempt is not informed about the connection being cancelled.

Current situation

Our apps connect to multiple bonded BLE devices at the same time and we have run into more reconnection problems related to the missing callback for when a 'direct' BLE connection attempt times out.
Below I have listed some of the scenarios we have encountered.
Scenario 4 is probably the most interesting scenario, as it contains all the issue combined in one. I have provide an Android bugreport for scenario 4.

Let me know if you need additional info or bugreports.

Test setup

Phones:
Pixel 4 (TP1A.220624.014)
Pixel 6 (TP1A.220624.021)
Both phones behave in the same way as described below.

Scenarios

Scenario 1: Unbonded, single BLE device

Steps to reproduce:

1. Start BLE advertising on the BLE device
2. Scan for the BLE device using e.g. Nordic nRF Mobile Connect
3. When the BLE device is discovered, connect to it
4. Take the BLE device out of range or power it off, so the connection times out
5. Create a 'direct' BLE connection attempt to the disconnected BLE device

Expected outcome:

The connection attempt should time out after 30 sec and the BluetoothGattCallback#onConnectionStateChanged() method is called with status=133 (0x85) - just as for Android 12 and older.

Actual outcome:

The connection attempt times out after 30 sec and the BluetoothGattCallback#onConnectionStateChanged() method is called with status=133 (0x85) - just as for Android 12 and older.

Scenario 2: Bonded, single BLE device

Steps to reproduce:

1. Start BLE advertising on the BLE device
2. Scan for the BLE device using e.g. Nordic nRF Mobile Connect
3. When the BLE device is discovered, connect to it
4. Pair the BLE device from the phone
5. Take the BLE device out of range or power it off, so the connection times out
6. Create a 'direct' BLE connection attempt to the disconnected BLE device

Expected outcome:

The connection attempt should time out after 30 sec and the BluetoothGattCallback#onConnectionStateChanged() method is called with status=133 (0x85) - just as for Android 12 and older.

Actual outcome:

The connection attempt only times out at the lower layers. In the HCI log it can be seen that the host sends a "LE Create Connection Cancel" message to the controller and the controller acknowledges it. HOWEVER, this doesn't trickle up to the Java layer. The BluetoothGattCallback#onConnectionStateChanged() method is NOT called, and thus the app is not informed about the connection attempt being cancelled.

Scenario 3: Bonded, two BLE devices; one device disconnects

Steps to reproduce:

1. Start BLE advertising on both BLE device A and BLE device B
2. Scan for the BLE devices using e.g. Nordic nRF Mobile Connect
3. When the BLE devices are discovered, connect to them one by one
4. Pair both BLE devices from the phone
5. Take one of the BLE device out of range or power it off, so the connection times out
6. Create a 'direct' BLE connection attempt to the disconnected BLE device

Expected outcome:

The connection attempt should time out after 30 sec and the BluetoothGattCallback#onConnectionStateChanged() method is called with status=133 (0x85) - just as for Android 12 and older.

Actual outcome:

The connection attempt only times out at the lower layers. In the HCI log it can be seen that the host sends a "LE Create Connection Cancel" message to the controller and the controller acknowledges it. HOWEVER, this doesn't trickle up to the Java layer. The BluetoothGattCallback#onConnectionStateChanged() method is NOT called, and thus the app is not informed about the connection attempt being cancelled.

Scenario 4: Bonded, two BLE devices; both devices disconnect, 'direct' connection attempts are made within 30 sec of eachother.

Bug report file:

Scenario 4, bugreport-oriole-TP1A.220624.021-2022-08-16-15-10-21.zip

Reproducibility:

10/10

Devices:

BLE device A: 70:B8:2F:FD:0F:4E (xx:xx:xx:xx:39:2c), clientIf=6
BLE device B: 53:19:DB:60:BD:3E (xx:xx:xx:xx:38:22), clientIf=7
Both BLE devices use BLE privacy.

Steps to reproduce: (timestamps are from the log)

1. Start BLE advertising on both BLE device A and BLE device B
2. Scan for the BLE devices using e.g. Nordic nRF Mobile Connect
3. When the BLE devices are discovered, connect to them one by one (15:07:23.076 and 15:07:30.441)
4. Pair both BLE devices from the phone (15:07:38.440 and 15:07:48.435)
5. Take both BLE devices out of range or power them off, so the connections time out (15:08:22.690)
6. Create a 'direct' BLE connection attempt to the disconnected BLE device A (15:08:43.957)
7. Within 30 sec create a 'direct' BLE connection attempt to the disconnected BLE device B (15:08:47.180)

Expected outcome:

Both connection attempts should time out after 30 sec and the BluetoothGattCallback#onConnectionStateChanged() method is called with status=133 (0x85) for each BLE device - just as for Android 12 and older.

Actual outcome:

From the HCI log (notice time stamps in the HCI log are in UTC, whereas in the system log file, they are in UTC+2), it can be seen that the connection attempt for BLE device A is sent from the host to the controller at:
11246 0.000225 13:08:43.983904 host controller HCI_CMD 62 Sent LE Extended Create Connection

But it is cancelled again, just before the connection attempt to BLE device B:
11250 0.000498 13:08:47.199894 host controller HCI_CMD 4 Sent LE Create Connection Cancel

This information is not propagated back up to app, so the app believes the connection attempt is still running.
11257 0.000251 13:08:47.204344 host controller HCI_CMD 62 Sent LE Extended Create Connection

Then 30 sec after the connection attempt to BLE device A is requested, it times out:
11261 0.000987 13:09:13.983077 host controller HCI_CMD 4 Sent LE Create Connection Cancel shim::legacy::btm 2022-08-16 15:09:13.967 ACL Connection failed : xx:xx:xx:xx:39:2c[public] le reason:CONNECTION_ACCEPT_TIMEOUT

This information is not propagated back up to app, so the app believes the connection attempt is still running.

Just after the connection times out, a new connection attempt is made, but this one does not come from the app, and there are no traces of it in the system log:
11268 0.001247 13:09:13.998712 host controller HCI_CMD 62 Sent LE Extended Create Connection

The 'direct' connection attempt to BLE device B never times out, and thus keeps running (forever)...

Then nothing more happens until later, when both BLE devices are brought back into range, and according to the HCI log the BLE device B reconnects, as the connection attempt for it was never cancelled...
11270 40.732216 13:09:54.733883 controller host HCI_EVT 34 Rcvd LE Meta (LE Enhanced Connection Complete) shim::legacy::btm 2022-08-16 15:09:54.735 ACL Connection successful : xx:xx:xx:xx:38:22[public] Le

But the system log reports two connections are established:

• One for the random advertisement address: 53:19:db:60:bd:3e

08-16 15:09:54.735 1002 2228 2997 I bluetooth: packages/modules/Bluetooth/system/stack/gatt/connection_manager.cc:215 on_connection_complete: Le connection completed to device:53:19:db:60:bd:3e

• But also one for the public address: xx:xx:xx:xx:38:22 (!)

08-16 15:09:54.735 1002 2228 2997 I bluetooth: packages/modules/Bluetooth/system/stack/gatt/connection_manager.cc:215 on_connection_complete: Le connection completed to device:xx:xx:xx:xx:38:22

Something is clearly wrong here and makes our app very hard to use for many users, as one or both of their BLE devices will no longer reconnect until they close our app or toggle Bluetooth off/on.

Shortly after, more weird things happen, but I cannot rule out that it is caused by nRF, so I will not go into more details about it here, but feel free to a take a look at it from 15:09:54.940, where a second connection to BLE device B is suddenly is created, so both clientIf=7 and clientIf=8 refers to BLE device B.

Scenario 5: Bonded, two BLE devices; one device disconnects, second device disconnects after more than 30 sec

Same as scenario 2 for both devices: the BluetoothGattCallback#onConnectionStateChanged() method is not called for any of the BLE devices.