Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failed to detect iOS companion app ID #738

Closed
sharpopotamus opened this issue May 28, 2021 · 8 comments
Closed

Failed to detect iOS companion app ID #738

sharpopotamus opened this issue May 28, 2021 · 8 comments
Labels

Comments

@sharpopotamus
Copy link

Describe the bug
I have several pi zeros running RA installed/managed via Ansible. Ever since 2.16.0, I've had stability issues tracking iOS devices with the companion app. It'll work for a day or so after restarting the RA service, but after that it stops tracking the companion app. The RA instance continues to be accessible via the API and the companion app browser. And it still tracks other BLE devices.

At around same time this error started occurring, I think RA itself started broadcasting BLE from the raspberry pis? I've started getting notifications on my iOS devices to connect to the various raspberry pi hostnames via bluetooth. I've been declining the connection requests, not sure if that's relevant though.

To reproduce
Install RA on an RPI0 via Ansible and let it run for a while.

Relevant logs

May 28 10:58:56 bedroom-pi room-assistant[323]: 28/05/2021, 10:58:56 - info - BluetoothLowEnergyService: Discovered new BLE peripheral e5a392d853514fb48bde277773263
May 28 10:58:57 bedroom-pi room-assistant[323]: 28/05/2021, 10:58:57 - info - BluetoothLowEnergyService: Attempting app discovery for tag 58fe181ee054
May 28 10:59:07 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:07 - error - BluetoothService: Failed to connect to 58:fe:18:1e:e0:54: timed out
May 28 10:59:07 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:07 - warn - BluetoothLowEnergyService: Failed to discover companion app ID due to error: timed out
May 28 10:59:35 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:35 - info - BluetoothService: Detected unusually long lock on Bluetooth adapter 0, force unlocking
May 28 10:59:37 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:37 - info - BluetoothLowEnergyService: Discovered new BLE peripheral 51fbf8e22652 with ID 51fbf8e2
May 28 10:59:41 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:41 - info - BluetoothLowEnergyService: Attempting app discovery for tag 58fe181ee054
May 28 10:59:51 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:51 - error - BluetoothService: Failed to connect to 58:fe:18:1e:e0:54: timed out
May 28 10:59:51 bedroom-pi room-assistant[323]: 28/05/2021, 10:59:51 - warn - BluetoothLowEnergyService: Failed to discover companion app ID due to error: timed out

Relevant configuration

all:
  hosts:
    'bedroom-pi.local':
      ansible_user: *****
      ansible_password: *****
      room_assistant_config:
        cluster:
          quorum: 5
          weight: 50
          peerAddresses:
            - '*****:6425'
     [5 other hosts with similar configs]
  vars:
    room_assistant_version: 2.18.1
    room_assistant_global_config:
      global:
        integrations:
          - homeAssistant
          - bluetoothLowEnergy      
      bluetoothLowEnergy:
        timeout: 60
        whitelist:
          - [ios companion app IDs]

Expected behavior
Continued tracking of iOS devices.

Environment

  • room-assistant version: 2.18.1
  • installation type: NOdeJS via Ansible
  • hardware: Raspberry Pi Zero, integrated bluetooth with a usb ethernet adapter
  • OS: Raspberry Pi OS Lite

Additional context
Add any other context about the problem here.

@sharpopotamus
Copy link
Author

sharpopotamus commented May 28, 2021

Looking at #704, my issue looks pretty similar, although I haven't noticed that the behavior is specifically related to moving the iOS device in or out of range.

@mKeRix
Copy link
Owner

mKeRix commented May 30, 2021

Hm, connection requests shouldn't be shown on your iOS device, at least the room-assistant code never requests a pairing. The characteristic that is read from the devices is accessible without authentication/pairing to make the process more seamless.

Since you've mentioned the beacon broadcasting: Are you using the auto-toggle visibility setting in the app? And if not, could you try simply disabling the broadcasted beacon using instanceBeaconEnabled to see if that makes it any better? It is only used for that one feature in the app, so if you don't use that you shouldn't notice any impact.

@sharpopotamus
Copy link
Author

Yep I noticed instanceBeaconEnabled after posting and disabled it, so I haven't been seeing any more pairing requests.
Unfortunately I am still getting the same errors as before.

While digging through the RA logs, I did find some additional wild looking errors on one of the pi zeros with the issue. Not sure if they're relevant though, as I've only seen these errors on one of the devices so far:

May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Error: Adapter is already resetting
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothService.resetHciDevice (/opt/nodejs/lib/node_modules/room-assistant/dist/integration-support/bluetooth/bluetooth.service.js:184:19)
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothLowEnergyService.discoverCompanionAppId (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:123:39)
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.applyCompanionAppOverride (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:283
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.handleDiscovery (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:86:15)
May 30 16:58:07 patiopi room-assistant[289]: (Use `node --trace-warnings ...` to show where the warning was created)
May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a
May 30 16:58:07 patiopi room-assistant[289]: (node:289) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a n
May 30 16:57:52 patiopi room-assistant[289]: 30/05/2021, 16:57:52 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:01 patiopi room-assistant[289]: 30/05/2021, 16:58:01 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:04 patiopi room-assistant[289]: 30/05/2021, 16:58:04 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:07 patiopi room-assistant[289]: 30/05/2021, 16:58:07 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:07 patiopi room-assistant[289]: 30/05/2021, 16:58:07 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Error: Adapter is already resetting
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothService.resetHciDevice (/opt/nodejs/lib/node_modules/room-assistant/dist/integration-support/bluetooth/bluetooth.service.js:184:19)
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothLowEnergyService.discoverCompanionAppId (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:123:39)
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.applyCompanionAppOverride (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:283
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.handleDiscovery (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:86:15)
May 30 16:58:07 patiopi room-assistant[289]: (Use `node --trace-warnings ...` to show where the warning was created)
May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a
May 30 16:58:07 patiopi room-assistant[289]: (node:289) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a n
May 30 16:58:16 patiopi room-assistant[289]: 30/05/2021, 16:58:16 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:19 patiopi room-assistant[289]: 30/05/2021, 16:58:19 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:19 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Error: Adapter is already resetting
May 30 16:58:19 patiopi room-assistant[289]:     at BluetoothService.resetHciDevice (/opt/nodejs/lib/node_modules/room-assistant/dist/integration-support/bluetooth/bluetooth.service.js:184:19)
May 30 16:58:19 patiopi room-assistant[289]:     at BluetoothLowEnergyService.discoverCompanionAppId (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:123:39)
May 30 16:58:19 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.applyCompanionAppOverride (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:283
May 30 16:58:19 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.handleDiscovery (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:86:15)
May 30 16:58:19 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a
May 30 16:58:25 patiopi room-assistant[289]: 30/05/2021, 16:58:25 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:41 patiopi room-assistant[289]: 30/05/2021, 16:58:41 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
lines 509-531
May 30 16:57:52 patiopi room-assistant[289]: 30/05/2021, 16:57:52 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:01 patiopi room-assistant[289]: 30/05/2021, 16:58:01 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:04 patiopi room-assistant[289]: 30/05/2021, 16:58:04 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:07 patiopi room-assistant[289]: 30/05/2021, 16:58:07 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:07 patiopi room-assistant[289]: 30/05/2021, 16:58:07 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Error: Adapter is already resetting
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothService.resetHciDevice (/opt/nodejs/lib/node_modules/room-assistant/dist/integration-support/bluetooth/bluetooth.service.js:184:19)
May 30 16:58:07 patiopi room-assistant[289]:     at BluetoothLowEnergyService.discoverCompanionAppId (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:123:39)
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.applyCompanionAppOverride (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:283
May 30 16:58:07 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.handleDiscovery (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:86:15)
May 30 16:58:07 patiopi room-assistant[289]: (Use `node --trace-warnings ...` to show where the warning was created)
May 30 16:58:07 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a
May 30 16:58:07 patiopi room-assistant[289]: (node:289) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a n
May 30 16:58:16 patiopi room-assistant[289]: 30/05/2021, 16:58:16 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:19 patiopi room-assistant[289]: 30/05/2021, 16:58:19 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 16:58:19 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Error: Adapter is already resetting
May 30 16:58:19 patiopi room-assistant[289]:     at BluetoothService.resetHciDevice (/opt/nodejs/lib/node_modules/room-assistant/dist/integration-support/bluetooth/bluetooth.service.js:184:19)
May 30 16:58:19 patiopi room-assistant[289]:     at BluetoothLowEnergyService.discoverCompanionAppId (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:123:39)
May 30 16:58:19 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.applyCompanionAppOverride (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:283
May 30 16:58:19 patiopi room-assistant[289]:     at async BluetoothLowEnergyService.handleDiscovery (/opt/nodejs/lib/node_modules/room-assistant/dist/integrations/bluetooth-low-energy/bluetooth-low-energy.service.js:86:15)
May 30 16:58:19 patiopi room-assistant[289]: (node:289) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a
May 30 16:58:25 patiopi room-assistant[289]: 30/05/2021, 16:58:25 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 16:58:41 patiopi room-assistant[289]: 30/05/2021, 16:58:41 - error - BluetoothLowEnergyService: Failed to search for companion app at tag 7c508c5941a5: timed out
May 30 17:00:00 patiopi room-assistant[289]: 30/05/2021, 17:00:00 - info - BluetoothLowEnergyService: Discovered new BLE peripheral e696f26f138d with ID e696f26f138d and RSSI -68
May 30 17:00:00 patiopi room-assistant[289]: 30/05/2021, 17:00:00 - info - BluetoothLowEnergyService: Discovered new BLE peripheral ca78ee90c3bc with ID ca78ee90c3bc and RSSI -69
May 30 17:00:01 patiopi room-assistant[289]: 30/05/2021, 17:00:01 - info - BluetoothLowEnergyService: Discovered new BLE peripheral 7e16895d6e83 with ID 7e16895d6e83 and RSSI -97
May 30 17:00:29 patiopi room-assistant[289]: 30/05/2021, 17:00:29 - info - BluetoothLowEnergyService: Attempting app discovery for tag 7c508c5941a5
May 30 17:00:30 patiopi room-assistant[289]: (node:289) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 disconnect listeners added to [Peripheral]. Use emitter.setMaxListeners() to increase limit

@BelgarionNL
Copy link

BelgarionNL commented Jun 30, 2021

did you have any more issues?

I am also seeing the same error: warn - BluetoothLowEnergyService: Failed to discover companion app ID due to error:

weird thing they are now all in the proper cluster. and the quorum seems to be working great.
its just that sometimes 1 rpi0 for some reason refuses to track the iphones while other pi's work fine.

restart seems to work. I would have preferred the RPI to restart itself if it cant connect to the companion app since its kinda critical :)

@sharpopotamus
Copy link
Author

Yeah I'm still having the same issues. I put a bandaid on it by either rebooting the pi or restarting the RA process whenever those errors start popping up. It ends up rebooting every couple hours though, so not the best solution.

@CobraDunn
Copy link

@BelgarionNL
@sharpopotamus

I hope I don't get my fingers smacked for sharing, but you should read through #763. No promises, but I was experiencing all types of what I thought was unrelated unusual behavior prior. The test version resolved all my issues.

@BelgarionNL
Copy link

@CobraDunn I read through all that but since I am running a docker solution (which I find to be the superior way, ow the irony) I cant use that test version yet.

rpi0w with Dietpi auto installing all necessary settings including docker etc.
and then portainer launching the stacks with room-assistant + telegraf as dockers for also monitoring the pi's is so fast and simple.

I only have to use winscp to drop the local.yml file and the telegraf.conf in their respective dockers and poof it works :)

@sharpopotamus
Copy link
Author

Well, at the end of the day, none of my attempts at updating or changing the RA installation on the Pis helped. But then I migrated the RA companion app from test flight to the 1.0 version on the app store and boom, no problems at all. No freaking clue why that did it, but I won't look that gift horse in the mouth.
Thanks everyone for the help!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants