BLE adapter being reset after each Companion App discovery

[PeteBa]

Describe the bug
Following a fresh install of room-assistant onto a Raspberry Pi Zero W, I am now seeing repeated resets of the ble adapter immediately following Companion App discovery. The service recovers and continues to provide location updates so the impact is minimal but an adapter reset shouldn't be happening.

From the logs, It looks like the Room-Assistant BLE service successfully discovers a Companion App but then fails to restart scanning. This then triggers the watchdog to reset the ble adapter after ~30 seconds and normal operation resumes. Since the iPhone changes MAC address every twenty minutes, the three log lines below are repeated on a regular basis.

08/11/2021, 20:41:40 - info - BluetoothLowEnergyService: Attempting app discovery for tag 405c873e850a
08/11/2021, 20:41:41 - info - BluetoothLowEnergyService: Discovered companion app with ID B123456D-EADB-EEF9-EFCC-2C3D56D1C836 for tag 405c873e850a
08/11/2021, 20:42:14 - warn - BluetoothService: Did not detect any low energy advertisements in a while, resetting

Given that an identical install from September - same pi and same room-assistant 2.19.1 - does not experience this problem, I suspect this is connected with an update a few weeks ago of the bluetooth-hci-socket package that room-assistant relies upon. Reverting to the previous version of the package resolves the issue.

Anyone with a recent install (i.e. room-assistant v2.19.1, bluetooth-hci-socket 0.5.3-8) seeing the same in their logs ?

To reproduce
This looks to occur on any fresh install from the last few weeks that pulls down the 0.5.3-8 version of bluetooth-hci-socket. You can run the following commands to confirm the dependency version:

$ npm list -g --all | grep bluetooth-hci-socket

The adapter resets go away if you force room-assistant to use the previous version of bluetooth-hci-socket:

$ sudo npm install -g --unsafe-perm @abandonware/[email protected]
$ sudo rm -rf /opt/nodejs/lib/node_modules/room-assistant/node_modules/@abandonware/bluetooth-hci-socket

Environment

• room-assistant version: 2.19.1
• installation type: NodeJS
• hardware: Raspberry Pi Zero W

Additional context

@mKeRix , this is identical to the Bleno issue we discussed here. Some thoughts:

• The fact that it has resurfaced suggests an underlying problem that bluetooth-hci-socket exposes but may not necessarily cause. I am happy to explore this. A possibly related problem is being tracked on the bluetooth-hci-socket's repo here.
• An adapter reset every 20 minute shouldnt be a big deal but when an iPhone is on the edge of reception and the companion app query fails then you can get a rapidly repeating cycle as the discovery process retries immediately following the reset.
• Given the above, it might be worth considering an update to the mkerix/noble package that ties bluetooth-hci-socket to the 0.5.3-7 version until there is a proper resolution on this? That would at least avoid new installs facing this issue.

[tunip]

I have this message constantly too on all 5 nodes.

Nov 29 12:16:17 Hobbyraum room-assistant[259]: 29/11/2021, 12:16:17 - info - BluetoothLowEnergyService: Discovered companion app with ID 5C60E279-....... for tag 553f6aa253fa
Nov 29 12:16:47 Hobbyraum room-assistant[259]: 29/11/2021, 12:16:47 - warn - BluetoothService: Did not detect any low energy advertisements in a while, resetting

[PeteBa]

Thanks Tunip for confirming. Can you provide a few extra details on version and operating system ?

You can get the version of OS, node, room-assistant and bluetooth-hci-socket with:

$ cat /etc/os-release
$ node -v
$ room-assistant -h
$ npm list -g --all | grep bluetooth-hci-socket

If you are willing, could you try downgrading the socket package on one of your nodes to see if that rectifies the situation with:

$ sudo npm install -g --unsafe-perm @abandonware/[email protected]
$ sudo rm -rf /opt/nodejs/lib/node_modules/room-assistant/node_modules/@abandonware/bluetooth-hci-socket

@eLVee1991, @JK-443, sorry for pinging you guys but hoping you could confirm the issue in the original post as I know you have recent installs?

[tunip]

Hi PetBa, sorry of the missing details. It was a fresh installation from the last weekend.

Hardare:

Raspberry Pi Zero W

pi@Buro:~ $ cat /etc/os-release

PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)"
NAME="Raspbian GNU/Linux"
VERSION_ID="11"
VERSION="11 (bullseye)"
VERSION_CODENAME=bullseye

pi@Buro:~ $ node -v

v16.13.0

pi@Buro:~ $ room-assistant -h

room-assistant 2.19.1

pi@Buro:~ $ npm list -g --all | grep bluetooth-hci-socket

  │ ├─┬ @abandonware/[email protected]
  │ ├── @abandonware/[email protected] deduped
npm notice 
npm notice New patch version of npm available! 8.1.0 -> 8.1.4
npm notice Changelog: https://github.com/npm/cli/releases/tag/v8.1.4
npm notice Run npm install -g [email protected] to update!
npm notice 

Will test the downgrade of the socket package on all nodes. Let you know the result.

[tunip]

Downgrade of the socket package on all nodes done.
First look into the log was fine. No BluetoothService: Did not detect any low energy advertisements in a while, resetting messages after Discovered companion app

[tunip]

Instead of Did not detect any low energy advertisements in a while, resetting now I have this message before Discovered companion app:

Nov 29 13:40:30 Hobbyraum kernel: Bluetooth: hci0: link tx timeout
Nov 29 13:40:30 Hobbyraum kernel: Bluetooth: hci0: link tx timeout
Nov 29 13:40:37 Hobbyraum room-assistant[273]: 29/11/2021, 13:40:37 - info - BluetoothLowEnergyService: Discovered companion app with ID 5C60E279-....... for tag 7d7d4ae3......

[PeteBa]

Yep, I have been seeing those messages for about 6 months now. I suspect due to a kernel/driver update as there are other reports of this with unrelated applications. I haven't seen any downsides as room-assistant retries failed connections. If you want to "revert the revert" then you can easily go back to the latest bluetooth-hci-socket with (though you will likely continue to see those messages):

$ sudo npm install -g --unsafe-perm @abandonware/bluetooth-hci-socket

[github-actions]

There hasn't been any activity on this issue recently. In an effort to provide a better overview of current issues we automatically clean some of the old ones. Many of them may already be resolved in newer versions of room-assistant.
This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.