mKeRix / room-assistant

Presence tracking and more for automation on the room-level
https://www.room-assistant.io
MIT License
1.28k stars 122 forks source link

Problems running room-assistant on Raspberry Pi Zero #351

Closed swissmaster1 closed 3 years ago

swissmaster1 commented 3 years ago

Describe the bug I run room-assistant on two Raspberry Pi Zero. After every reboot everything is running like a charm. But after some random time room-assistant doesn't report as normaly. When I check the status of the service it tells me on both devices that room-assistant is still running. In the logs I can't see nothing special. When I then reboot both devices everthing is working again for some time. I tried everthing on a 3rd Raspberry Pi Zero with a complete new installation and room-assistant with same result. Yesterday things stopped working on 22:10 in the evening. When I check the status of room-assistant it says me that room-assistant is still running but after that time there is no output when I do this command 'journalctl -u room-assistant.service'

Whats wrong? Is it only a problem of me or is it a bug? What means this error - ClusterService: getaddrinfo -3008 and what can I do against that? Once I got the error: BluetoothClassicService: Failed to retrive RSSI for xyz Trying to lock adapter 0 even though it is already locked. Could this have something to do with that?

When I check home assistant entities I can see the entity of my iphone which I configured in room assistant. It has normaly the state of the room I am. But anyway room-assistant log tells me that: HomeAssistantService: Device tracker requires manual setup in Home Assistant with topic: room-assistant/device_tracker/bluetooth-classic-c0-9a-d0-f1-8e-c1-tracker/state Do I really have to configure something else? If yes what do I have to setup in home assistant?

My DNS server is configured to use *.local domain.

Relevant logs This is what the log says.

Nov 17 10:29:29 keller systemd[1]: Started room-assistant service.
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Nov 17 10:29:52 keller node[250]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 17 10:29:52 keller room-assistant[250]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 17 10:29:52 keller node[250]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 17 10:29:52 keller node[250]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 17 10:29:52 keller node[250]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Nov 17 10:29:52 keller node[250]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 17 10:29:52 keller node[250]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 17 10:29:57 keller room-assistant[250]: 11/17/2020, 10:29:57 AM - info - IntegrationsModule: Loading integrations: home-assistant, bluetooth-classic
Nov 17 10:30:19 keller room-assistant[250]: 11/17/2020, 10:30:19 AM - info - NestFactory: Starting Nest application...
Nov 17 10:30:20 keller room-assistant[250]: 11/17/2020, 10:30:20 AM - info - InstanceLoader: AppModule dependencies initialized
Nov 17 10:30:20 keller room-assistant[250]: 11/17/2020, 10:30:20 AM - info - InstanceLoader: ConfigModule dependencies initialized
Nov 17 10:30:20 keller room-assistant[250]: 11/17/2020, 10:30:20 AM - info - InstanceLoader: NestEmitterModule dependencies initialized
Nov 17 10:30:20 keller room-assistant[250]: 11/17/2020, 10:30:20 AM - info - InstanceLoader: IntegrationsModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: HttpModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: DiscoveryModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: ClusterModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: TerminusModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: BluetoothModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: ScheduleModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: EntitiesModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: HomeAssistantModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: BluetoothClassicModule dependencies initialized
Nov 17 10:30:21 keller room-assistant[250]: 11/17/2020, 10:30:21 AM - info - InstanceLoader: StatusModule dependencies initialized
Nov 17 10:30:24 keller room-assistant[250]: 11/17/2020, 10:30:24 AM - info - RoutesResolver: EntitiesController {/entities}:
Nov 17 10:30:24 keller room-assistant[250]: 11/17/2020, 10:30:24 AM - info - RouterExplorer: Mapped {/entities, GET} route
Nov 17 10:30:24 keller room-assistant[250]: 11/17/2020, 10:30:24 AM - info - RoutesResolver: StatusController {/status}:
Nov 17 10:30:24 keller room-assistant[250]: 11/17/2020, 10:30:24 AM - info - RouterExplorer: Mapped {/status, GET} route
Nov 17 10:30:26 keller room-assistant[250]: 11/17/2020, 10:30:26 AM - info - HomeAssistantService: Successfully connected to MQTT broker at mqtt://192.168.1.30:1883
Nov 17 10:30:26 keller room-assistant[250]: 11/17/2020, 10:30:26 AM - info - ConfigService: Loading configuration from /opt/nodejs/lib/node_modules/room-assistant/dist/config/definitions/default.js, config/local.yml
Nov 17 10:30:27 keller room-assistant[250]: 11/17/2020, 10:30:27 AM - info - ClusterService: Starting mDNS advertisements and discovery
Nov 17 10:30:27 keller room-assistant[250]: 11/17/2020, 10:30:27 AM - info - NestApplication: Nest application successfully started
Nov 17 10:30:27 keller room-assistant[250]: 11/17/2020, 10:30:27 AM - info - HomeAssistantService: Device tracker requires manual setup in Home Assistant with topic: room-assistant/device_tracker/bluetooth-classic-c0-9a-d0-f1-8e-c1-tracker/state
Nov 17 10:30:27 keller room-assistant[250]: 11/17/2020, 10:30:27 AM - error - ClusterService: getaddrinfo -3008
Nov 17 10:30:27 keller room-assistant[250]: 11/17/2020, 10:30:27 AM - error - ClusterService: getaddrinfo -3008
Nov 17 12:08:44 keller room-assistant[250]: 11/17/2020, 12:08:44 PM - error - ClusterService: getaddrinfo -3008
Nov 17 12:08:55 keller room-assistant[250]: 11/17/2020, 12:08:55 PM - error - ClusterService: getaddrinfo -3008
Nov 17 14:22:37 keller room-assistant[250]: 11/17/2020, 2:22:37 PM - error - ClusterService: getaddrinfo -3008
Nov 17 17:08:29 keller room-assistant[250]: 11/17/2020, 5:08:29 PM - info - ClusterService: Removed 192.168.1.60:6425 from the cluster with id schlafzimmer
Nov 17 17:08:29 keller room-assistant[250]: 11/17/2020, 5:08:29 PM - info - ClusterService: keller has been elected as leader
Nov 17 17:08:29 keller room-assistant[250]: 11/17/2020, 5:08:29 PM - info - EntitiesService: Refreshing entity states
Nov 17 17:12:29 keller room-assistant[250]: 11/17/2020, 5:12:29 PM - info - ClusterService: schlafzimmer has been elected as leader
Nov 17 17:12:29 keller room-assistant[250]: 11/17/2020, 5:12:29 PM - info - ClusterService: schlafzimmer has been elected as leader
Nov 17 17:12:29 keller room-assistant[250]: 11/17/2020, 5:12:29 PM - info - ClusterService: schlafzimmer has been elected as leader
Nov 18 02:42:33 keller room-assistant[250]: 11/18/2020, 2:42:33 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:42:33 keller room-assistant[250]: 11/18/2020, 2:42:33 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:42:43 keller room-assistant[250]: 11/18/2020, 2:42:43 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:42:43 keller room-assistant[250]: 11/18/2020, 2:42:43 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:58:35 keller room-assistant[250]: 11/18/2020, 2:58:35 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:58:35 keller room-assistant[250]: 11/18/2020, 2:58:35 AM - error - ClusterService: getaddrinfo -3008
Nov 18 02:58:35 keller room-assistant[250]: 11/18/2020, 2:58:35 AM - error - ClusterService: getaddrinfo -3008
Nov 18 04:23:39 keller room-assistant[250]: 11/18/2020, 4:23:39 AM - error - ClusterService: getaddrinfo -3008
Nov 18 04:23:50 keller room-assistant[250]: 11/18/2020, 4:23:50 AM - error - ClusterService: getaddrinfo -3008
Nov 18 04:24:03 keller room-assistant[250]: 11/18/2020, 4:24:03 AM - info - HomeAssistantService: Re-connected to broker
Nov 18 04:24:03 keller room-assistant[250]: 11/18/2020, 4:24:03 AM - info - EntitiesService: Refreshing entity states
Nov 18 04:34:40 keller room-assistant[250]: 11/18/2020, 4:34:40 AM - error - ClusterService: getaddrinfo -3008
Nov 18 04:34:52 keller room-assistant[250]: 11/18/2020, 4:34:52 AM - error - ClusterService: getaddrinfo -3008
Nov 18 04:37:40 keller room-assistant[250]: 11/18/2020, 4:37:40 AM - error - ClusterService: getaddrinfo -3008
Nov 18 10:59:29 keller room-assistant[250]: 11/18/2020, 10:59:29 AM - info - ClusterService: Removed 192.168.1.60:6425 from the cluster with id schlafzimmer
Nov 18 10:59:29 keller room-assistant[250]: 11/18/2020, 10:59:29 AM - info - ClusterService: keller has been elected as leader
Nov 18 10:59:29 keller room-assistant[250]: 11/18/2020, 10:59:29 AM - info - EntitiesService: Refreshing entity states
Nov 18 11:03:12 keller room-assistant[250]: 11/18/2020, 11:03:12 AM - info - ClusterService: schlafzimmer has been elected as leader
Nov 18 17:02:35 keller room-assistant[250]: 11/18/2020, 5:02:35 PM - info - ClusterService: Removed 192.168.1.60:6425 from the cluster with id schlafzimmer
Nov 18 17:02:36 keller room-assistant[250]: 11/18/2020, 5:02:35 PM - info - ClusterService: keller has been elected as leader
Nov 18 17:02:36 keller room-assistant[250]: 11/18/2020, 5:02:35 PM - info - EntitiesService: Refreshing entity states
Nov 18 17:06:28 keller room-assistant[250]: 11/18/2020, 5:06:28 PM - info - ClusterService: Added 192.168.1.60:6425 to the cluster with id schlafzimmer
Nov 18 17:06:28 keller room-assistant[250]: 11/18/2020, 5:06:28 PM - info - ClusterService: schlafzimmer has been elected as leader

Relevant configuration My configuration

global:
  integrations:
    - homeAssistant
    - bluetoothClassic
homeAssistant:
  mqttUrl: 'mqtt://192.168.1.30:1883'
  mqttOptions:
    username:
    password:
bluetoothClassic:
  addresses:
    - 'xyz'

Environment

Additional context Add any other context about the problem here.

oz-glenn commented 3 years ago

I installed Room Assistant today on my Raspberry Pi Zero W. I'm having the same experience - it worked for an hour or two, then stopped reporting. Everything looked normal, and only a restart fixed it.

swissmaster1 commented 3 years ago

Do you have an idea why this happened? Did you see something in the log?

oz-glenn commented 3 years ago

My config:

global:
  integrations:
    - homeAssistant
    - bluetoothClassic
homeAssistant:
  mqttUrl: 'mqtt://192.168.30.21:1883'
  mqttOptions:
    username: user
    password: password
bluetoothClassic:
  addresses:
    - private
    - private

Logs:

Nov 20 07:40:38 man-cave-rpi systemd[1]: Started room-assistant service.
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 20 07:40:56 man-cave-rpi room-assistant[281]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** Please fix your application to use the native API of Avahi!
Nov 20 07:40:56 man-cave-rpi node[281]: *** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
Nov 20 07:41:01 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:01 AM - info - IntegrationsModule: Loading integrations: home-assistant, bluetooth-classic
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - NestFactory: Starting Nest application...
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: AppModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: ConfigModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: NestEmitterModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: IntegrationsModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: HttpModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: DiscoveryModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: ClusterModule dependencies initialized
Nov 20 07:41:07 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:07 AM - info - InstanceLoader: TerminusModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: BluetoothModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: ScheduleModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: EntitiesModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: HomeAssistantModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: BluetoothClassicModule dependencies initialized
Nov 20 07:41:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:08 AM - info - InstanceLoader: StatusModule dependencies initialized
Nov 20 07:41:29 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:29 AM - info - RoutesResolver: EntitiesController {/entities}:
Nov 20 07:41:29 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:29 AM - info - RouterExplorer: Mapped {/entities, GET} route
Nov 20 07:41:29 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:29 AM - info - RoutesResolver: StatusController {/status}:
Nov 20 07:41:29 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:29 AM - info - RouterExplorer: Mapped {/status, GET} route
Nov 20 07:41:33 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:33 AM - info - HomeAssistantService: Successfully connected to MQTT broker at mqtt://192.168.30.21:1883
Nov 20 07:41:33 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:33 AM - info - ConfigService: Loading configuration from /opt/nodejs/lib/node_modules/room-assistant/dist/config/definitions/default.js, config/local.yml
Nov 20 07:41:34 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:34 AM - info - ClusterService: Starting mDNS advertisements and discovery
Nov 20 07:41:34 man-cave-rpi room-assistant[281]: 11/20/2020, 7:41:34 AM - info - NestApplication: Nest application successfully started
Nov 20 07:44:26 man-cave-rpi room-assistant[281]: 11/20/2020, 7:44:26 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:47:33 man-cave-rpi room-assistant[281]: 11/20/2020, 7:47:33 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:48:16 man-cave-rpi room-assistant[281]: 11/20/2020, 7:48:16 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:48:56 man-cave-rpi room-assistant[281]: 11/20/2020, 7:48:56 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:50:08 man-cave-rpi room-assistant[281]: 11/20/2020, 7:50:08 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:50:35 man-cave-rpi room-assistant[281]: 11/20/2020, 7:50:35 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:52:51 man-cave-rpi room-assistant[281]: 11/20/2020, 7:52:51 AM - error - ClusterService: getaddrinfo -3008
Nov 20 07:53:00 man-cave-rpi room-assistant[281]: 11/20/2020, 7:53:00 AM - error - ClusterService: getaddrinfo -3008

There's also repeated errors in the syslog:

Nov 20 07:59:36 man-cave-rpi kernel: [ 1148.979913] debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Nov 20 07:59:42 man-cave-rpi kernel: [ 1154.982730] debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Nov 20 07:59:42 man-cave-rpi kernel: [ 1154.982760] debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Nov 20 07:59:48 man-cave-rpi kernel: [ 1160.981742] debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Nov 20 07:59:48 man-cave-rpi kernel: [ 1160.981766] debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Nov 20 07:59:54 man-cave-rpi kernel: [ 1166.979426] debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Nov 20 07:59:54 man-cave-rpi kernel: [ 1166.979455] debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Nov 20 08:00:00 man-cave-rpi kernel: [ 1172.982103] debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Nov 20 08:00:00 man-cave-rpi kernel: [ 1172.982134] debugfs: File 'le_max_key_size' in directory 'hci0' already present!

The problem is that these errors are present when it's working and nothing seems to change when it stops working.

mKeRix commented 3 years ago

Both of your logs seem completely fine to me at first glance to be honest, so I'm sorry to hear that it stops working. I have two ideas for further actions:

v2.11.0 was the version that changed quite a few things around how Bluetooth is handled in room-assistant to accommodate running BLE and BT Classic on the same adapter. Since both of you don't require this feature at the moment I wonder if the old version may have been more stable in that regard.

swissmaster1 commented 3 years ago

Today after room-assistant stopped working and didnt recognize my mobile phone anymore I tried something else. I stopped the room-assistant service with sudo systemctl stop room-assistant. After that I started it with room-assistant -v. It started without an error but didnt recognize something (my mobile phone). After I rebooted the raspberry it immediately worked again. Very strange.

swissmaster1 commented 3 years ago

Tried that: downgrade room-assistant to 2.10.1 I did a completly new install (incl. raspbian) with v.2.10.1 and it is not working on both raspberry pi. I got no devices reported with that version to my home assistant instance. And it gave me this error: HomeAssistantService: Cannot add property hash, object is not extensible. I switched now back to v 2.12.0 and it is running now again. But I still have the problem that it stops working after a random time.

swissmaster1 commented 3 years ago

I let room-assistant run now sometime with "room-assistant -v" to get more information. This morning it stoped working again and I saw alway this output, again and again: 11/22/2020, 7:31:37 AM - debug - BluetoothService: Querying for RSSI of C0:xy:xy:xy:xy:xy using hcitool 11/22/2020, 7:31:40 AM - debug - BluetoothService: Query of C0:xy:xy:xy:xy:xy reached scan time limit, resetting hci0 I then hit Ctrl+C to stop room-assistant. The started it again with room-assistant -v. Everything loaded correctly, no errors reported and also connected to mqtt. But bluetoothservice gave the same outputs as before and didn't recognize my device: 11/22/2020, 7:40:37 AM - debug - BluetoothService: Querying for RSSI of C0:xy:xy:xy:xy:xy using hcitool 11/22/2020, 7:40:40 AM - debug - BluetoothService: Query of C0:xy:xy:xy:xy:xy reached scan time limit, resetting hci0 Then I did a reboot and from this point it looks like it didn't scan for any bluetooth devices (no debug outputs of bluetoothservice). I don't know what is going on. I run nothing else on the pi zero and using a standard configuration.

mKeRix commented 3 years ago

Hm, these messages are not worrisome in itself, as they always happen when the device isn't in reach of the instance for example. It is possible that the adapter hung up on itself. One quickfix workaround might be to increase interval to 10 and scanTimeLimit to 6, as that will be much less aggressive on the adapter and might prevent it from crashing.

If you happen to see this again, could you also try if running hciconfig hci0 down && hciconfig hci0 up works to fix the issue? You can do it without turning room-assistant off and then just observe.

swissmaster1 commented 3 years ago

I installed room-assistant the same way on a raspberry pi 3. Its now working since more than a day without problems. I'll try it further but for now it looks like raspberry pi zero isn't a good way to run room-assistant.

swissmaster1 commented 3 years ago

hciconfig hci0 down && hciconfig hci0 up didn't change anything on my pi zero's. I dont see a way to get them constantly runnig without crash. The logs dont give me information to solve the problem. I cant find the reason. I only know that a raspberry pi 3 works with exactly the same setup/configuration. Maybe there are some hardware limitations or so on pi zero?

oz-glenn commented 3 years ago

I've been waiting until now for it to happen again. I did have the rpi lock up 2 days ago but I'm not sure that was caused by room assistant. Tonight, I went out there and it didn't detect me, but the rpi hadn't locked up. I tried hciconfig hci0 down && hciconfig hci0 up, but that didn't work. I restarted the service. Didn't work. The logs looked normal with no errors and continuing activity. HTOP showed normal CPU/Memory usage.

I restarted and it started working.

mKeRix commented 3 years ago

I have been running room-assistant on 5 Pi Zero Ws successfully for quite a while now, so I don't think it is a specific hardware problem that affects all. Unfortunately this also makes this really hard to debug and understand. :(

One thing that has helped people in the past is to make sure all the system software and the firmware is up-to-date. You can do that with sudo apt-get update && sudo apt-get upgrade and sudo rpi-update respectively. Is that something you could try?

swissmaster1 commented 3 years ago

Hi Heiko Thank you for your support. I tried everything. Installed Raspian Buster on 2 Zero's. Upgraded both. Installed room-assistant again as provided on your page. But still not working. But room-assistant on my Pi 3 is still working since a few days.

oz-glenn commented 3 years ago

As an update, it was working until it locked up again this morning. It took 2 restarts to get it to work again. I've ordered another Pi Zero W, hoping I can narrow down if it's this particular board or not. Now I think of it, I had troubles with it locking up when I tried to run PiHole on it, too. I'll update with results once that arrives in a week or so.

swissmaster1 commented 3 years ago

Room-Assistant still running on Pi 3 since 1 week without problems. Never had to reboot.

Can you maybe make an ISO of your microSD and share that? So we can try if this would work on our Pi Zeros by only change the config file.

balonchiks commented 3 years ago

i've experienced exactly the same today on a pi zero w, with everything installed from scrath about 2 month ago.

did a sudo apt-get update && sudo apt-get upgradeand sudo rpi-update and restarted - will keep an eye on it's behaviour

room-assistant is the latest version as per npm

mKeRix commented 3 years ago

Hm, pulling an ISO from one of my running Pis might be a bit tricky since I would have to figure out a way to wipe any personal settings (WiFi passwords etc) from it completely. I've been thinking about this for a little while and have come to the conclusion that I would like to give buildroot a try to generate a custom Linux image with everything pre-configured and pre-installed. Atm I would like to get the current beta (especially the iPhone stuff) to a stable point first, but after that I could imagine tackling this. Maybe something for the Christmas holidays.

oz-glenn commented 3 years ago

I received my second RPi Zero W yesterday. It lasted a few hours and then stopped detecting. As before the logs give no hints, and restarting the service has no effect. I solved the problem with a sledgehammer on the first RPi Zero W with a cron job to restart every hour, I'm about to do the same with the second one.

mKeRix commented 3 years ago

As a side note, I added some more timeouts in the last beta version (v2.13.0-beta.3) that could possibly also help with this issue. Since just restarting room-assistant works for you something it may just be that something gets stuck while performing the inquiries and room-assistant does not handle that properly.

vivobg commented 3 years ago

I am having the same issue with 2 Zero Ws, running on 2.12.0, fresh install of everything, as of 2 days ago. I see the following in the logs 12/12/2020, 8:43:31 PM - debug - BluetoothService: Query of xx:xx:xx:xx:xx:xx reached scan time limit, resetting hci0

Also, when I run hcitool -i hci0 cc "xx:xx:xx:xx:xx:xx" I get "Can't create connection: Input/output error", when the mobile phone is a meter away in direct line of sight.

I rebooted one of the Zeros, and it started working again, but I am keeping the other one on, to try and debug the issue.

Restarting the room-assistant service did not help. I tried updating to 2.13.0-beta.3, but the non-restarted Zero is still not working.

balonchiks commented 3 years ago

my 2 cents:

i've reinstalled room-assistant on a fresh rpi zero w via docket this time and in couple of days i got the issue again. pi is not detecting any of the devices, the logs are empty. restarting room-assistant container didn't help so i had to do a rpi full restart to bet it back working.

on that day, the only things that were in the log are:

12/16/2020, 10:00:30 AM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.
12/16/2020, 10:06:47 AM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.
12/16/2020, 10:51:55 AM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.
12/16/2020, 2:58:34 PM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.
12/16/2020, 3:34:49 PM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.
12/16/2020, 6:20:31 PM - error - ClusterService: Command failed: dig +short @224.0.0.251 -p 5353 -4 rpi-office.local.

what is interesting is that rpi-office is that particular rpi. is it trying to speak to itself? is that normal?

just in case here's cluster part of my config on this rpi:

  cluster:
    autoDiscovery: false
    port: 6425
    peerAddresses:
      - 10.x.x.31:6425
      - 10.x.x.115:6425
      - 10.x.x.45:6425
      - 10.x.x.30:6425
  instanceName: office
balonchiks commented 3 years ago

yet another update - tried the latest beta v2.13.0-beta.4 - the result is still the same. rpi stopped reporting in 2 hours with absolutely clear logs.

patdemko commented 3 years ago

I just started using room assistant about a week ago or so ago and I'm noticing the same pi zero issues. I'm having no problems with it running on two Pi3's and a Pi4, but both of the Pi zeros I've tried eventually lock up after a while like is mentioned. One thing I have noticed through the logs is the just prior to getting into the hung state the wifi interface drops and quickly reconnects. When it reconnects it shows a valid IP is received via dhcp. However, the device is no longer responding to pings or sending packets at this time. I have found that if I catch it early enough and disconnect it manually from my Wifi AP it will reconnect and start passing data again. If it sits too long in that hung state the AP reconnect command won't work and I then need to restart the Pi zero to get it back.

mKeRix commented 3 years ago

While testing stuff for #309 I have also started noticing these issues now - the adapter becomes unstable or gets stuck, which then leads to nothing working correctly anymore. I am testing out a bunch of different things to stabilize this and recover from such failure states better, however only with medium amounts of success so far. Before bringing the companion app feature to stable I definitely want this issue to be solved.

swissmaster1 commented 3 years ago

Are there any news on this issue?

mKeRix commented 3 years ago

My local test installation seems to be able to recover from this, although I am testing it with other stuff enabled. I'm not 100% happy with my test results, but I think for this specific issue it might be valuable to at least get another beta release out. I'll try to facilitate that tomorrow.

mKeRix commented 3 years ago

I just published 2.13.0-beta.5, which includes the stability improvements that I mentioned. Note that for regular BLE tracking the performance will be slightly degraded in the beta, as the companion app discovery process cannot be disabled yet (an option I want to add before making this an actual release). You can easily counteract that by raising the timeout setting though. Could you check if this resolves any of your issues?

mKeRix commented 3 years ago

I just realized that I forgot to mention something regarding the beta.5 - for it to function fully while running as a non-root user you need to grant an additional permission that would otherwise only be needed for BT Classic:

sudo setcap cap_net_admin+eip $(eval readlink -f `which hciconfig`)
balonchiks commented 3 years ago

thanks, but that doesn't needed for the docker image, correct?

mKeRix commented 3 years ago

Exactly, that is only required for direct NodeJS installations, not on Docker or the Home Assistant add-on.

balonchiks commented 3 years ago

apparently it does not fix the issue for me. it has been working fine on a beta for a couple of days, but this morning i find it unresponsive again. also on other pi i've used version 2.10.0 and the behaviour is the same after couple of days - it's not reporting any devices until i reboot it. rpi 3 and rpi 4 still work fine for months now..

oz-glenn commented 3 years ago

I updated to the beta a week ago. It was looking good to start with - it lasted a few days. Since then, it's back to the old behavior, it lasts for random times between 1-9 hours, and only a reboot will fix it.

mKeRix commented 3 years ago

@username-ibis Could you give beta.6 a try as well?

oz-glenn commented 3 years ago

I installed beta.6 this morning. Went to work, by the time I came home, it wasn't detecting me. Nothing in the logs.

billimek commented 3 years ago

I wonder if there is a hardware flaw in the raspberry pi zero's that results in the bluetooth system failing and there isn't a software remedy, other than a reboot or hard power-cycle.

magimat commented 3 years ago

I have the exact same problem running on a pi 3b. Everything is fine for a while (between a few hours to a day or two) and then all of a sudden, it crashes with some hci0 errors in the logs and it only comes back after a reboot.

Really annoying, because when it works it’s really cool, but presence detection needs to be rock solid.

adizukerman commented 3 years ago

I'm having similar issues. I find it it is problem when a raspberry pi zero w gets all failed readings for a certain amount of time (e.g. you are not home or far away from the device for awhile). I wrote a small program in python that in essence keeps running hcitool -i hci0 cc "XX:XX:XX:XX:XX:XX" && hcitool -i hci0 rssi "XX:XX:XX:XX:XX:XX" every 10 seconds and find that I have the same issue. After a number of failures (not sure the limit) it will no longer get rssi readings when the my iPhone or Apple Watch comes back within range. I also tried to replace hictool with something based on https://github.com/ewenchou/bluetooth-proximity/blob/master/bt_proximity/bt_rssi.py and have the same issue. I don't know how to figure out how to "reset" the adapter before it fails.

magimat commented 3 years ago

as a complement, here is what I get in the logs for on my raspberry pi 3b when it's crashed.

First I get a few:

error - BluetoothService: Command failed: hcitool -i hci0 cc "xx:xx:xx:xx:xx:xx" && hcitool -i hci0 rssi "xx:xx:xx:xx:xx:xx"

and then, logs get filled with:

error - BluetoothClassicService: Failed to retrieve RSSI for xx:xx:xx:xx:xx:xx: Trying to lock adapter 0 even though it is already locked

and at this point, I need to reboot it for it to work again.

I'm running it via docker on a raspberry pi 3b.

mKeRix commented 3 years ago

Thanks for your additional remarks and thoughts on this topic, it did give me another idea of what to try. Do you see the same issues when you make room-assistant a bit less aggressive on the adapter? Something like this:

bluetoothClassic:
  scanTimeLimit: 7
  interval: 15

You can also set it to something even higher as a test.

oz-glenn commented 3 years ago

So far so good with the suggested changes. It does seem a little slow to recognise me on entry, but it's been running for a couple of days now without drama. Interestingly it has also started detecting my Apple watch, which after initially setting it up was never detected again until this latest config change.

balonchiks commented 3 years ago

Working good for me too with the changes for the last 3 days!

mKeRix commented 3 years ago

In that case I'll probably raise the defaults to a secure value in the next version. Still allows anyone that wants to push their hardware to tune it back down, but makes the default experience better for new users.

magimat commented 3 years ago

I had it going for a few days too with those parameters, but it just crashed again :(

2/3/2021, 12:40:16 AM - error - BluetoothClassicService: Failed to retrieve RSSI for xx:xx:xx:xx:xx:xx:: Command failed: hcitool -i hci0 cmd 0x01 0x0008

I guess at this point I'll just give up on this and get back to gps presence detection, because this is way too glitchy to be useful :(

github-actions[bot] commented 3 years ago

:tada: This issue has been resolved in version 2.13.1 :tada:

The release is available on:

Your semantic-release bot :package::rocket:

neil2802 commented 3 years ago

Hi all. Very new to home assistant and also very inexperienced but am dabbling with room assistant and had the exact same issues on 4 pi zero w's using wifi. I bought some ethernet hats for the zeros, disabled wifi and they are now hard wired via ethernet. Bang! Total reliability. Up and running for over a month now with no issues at all. Understand this may not be practicle for all, but might give an insight into why the pi's are hanging. (wifi issues?) Just need to tweak to get the room presence to update quicker. Always gets it right but can take up to 5 minutes.

patdemko commented 3 years ago

Hi all. Very new to home assistant and also very inexperienced but am dabbling with room assistant and had the exact same issues on 4 pi zero w's using wifi. I bought some ethernet hats for the zeros, disabled wifi and they are now hard wired via ethernet. Bang! Total reliability. Up and running for over a month now with no issues at all. Understand this may not be practicle for all, but might give an insight into why the pi's are hanging. (wifi issues?) Just need to tweak to get the room presence to update quicker. Always gets it right but can take up to 5 minutes.

Thanks for confirming it's related to the pi zero w's wifi connection with your Ethernet test. While it's gotten better since the changes made in response to this issue (my pi zero's are not locking up requiring a hard reboot anymore), they are disconnected way more than they're connected. I still have no issues with the Pi3 or Pi4's using their wifi connection.

image

neil2802 commented 3 years ago

Hi

Thanks for the reply.

Like I said in my post I’m very inexperienced but thought I’d give some feed back from my own experience, as i think your “project” is fantastic.

I had issues with the pi’s even before loading your software. (painfully slow or unresponsive over SSH).

It’s also probably helped as I’ve turned off wifi on the pi’s so the chip can concentrate on the Bluetooth (classic) side.

Anyhow, thanks for a great bit of software

From: patdemko @.*** Sent: 03 May 2021 13:36 To: mKeRix/room-assistant Cc: neil2802; Comment Subject: Re: [mKeRix/room-assistant] Problems running room-assistant on Raspberry Pi Zero (#351)

Hi all. Very new to home assistant and also very inexperienced but am dabbling with room assistant and had the exact same issues on 4 pi zero w's using wifi. I bought some ethernet hats for the zeros, disabled wifi and they are now hard wired via ethernet. Bang! Total reliability. Up and running for over a month now with no issues at all. Understand this may not be practicle for all, but might give an insight into why the pi's are hanging. (wifi issues?) Just need to tweak to get the room presence to update quicker. Always gets it right but can take up to 5 minutes.

Thanks for confirming it's related to the pi zero w's wifi connection with your Ethernet test. While it's gotten better since the changes made in response to this issue (my pi zero's are not locking up requiring a hard reboot anymore), they are disconnected way more than they're connected. I still have no issues with the Pi3 or Pi4's using their wifi connection.

https://user-images.githubusercontent.com/11141892/116876016-cec9e680-abe9-11eb-8f7f-42ea57ce5ee3.png image

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/mKeRix/room-assistant/issues/351#issuecomment-831230726 , or unsubscribe https://github.com/notifications/unsubscribe-auth/AM7CWCOAS5OE5SYRVT5COHTTL2KBTANCNFSM4T3E6LEA . https://github.com/notifications/beacon/AM7CWCISNPYEA3GD7MMACULTL2KBTA5CNFSM4T3E6LEKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOGGFZGBQ.gif

gravyflex commented 3 years ago

Hi all. Very new to home assistant and also very inexperienced but am dabbling with room assistant and had the exact same issues on 4 pi zero w's using wifi. I bought some ethernet hats for the zeros, disabled wifi and they are now hard wired via ethernet. Bang! Total reliability. Up and running for over a month now with no issues at all. Understand this may not be practicle for all, but might give an insight into why the pi's are hanging. (wifi issues?) Just need to tweak to get the room presence to update quicker. Always gets it right but can take up to 5 minutes.

You are on to something... I disabled the onboard Bluetooth on my pizero and added a USB bt dongle. The last few hours look stable. I am going to see how this works out. Thanks for sharing.

swissmaster1 commented 3 years ago

is there any news to this issue? Is room-assistant now working on pi zero???

oz-glenn commented 3 years ago

is there any news to this issue? Is room-assistant now working on pi zero???

Nope. It lasts anywhere between a day or less and 3 or 4, then it doesn’t detect. I’m tired of trying to SSH in, and it’s not where my computer lives, so when it fails I just pull the power and most of the time that fixes it, although sometimes it takes 2 or 3 resets.