search

bropat / ioBroker.eusec

This ioBroker adapter allows to control Eufy security devices by connecting to the Eufy cloud servers.
MIT License
137 stars 17 forks source link

Endless loop: lan_ip_address changed, consumes 100% CPU #74

Closed greuff closed 3 years ago

greuff commented 3 years ago

It's the first time that I'm trying out this adapter (and also my first time with iobroker). I have 3 EufyCam 2C Pros and I was able to add them to iobroker (latest stable from today) without a problem. After a few hours, the adapter "went crazy" and flipped the lan_ip_address in an endless loop, consuming 100% CPU:

2021-02-06 20:44:57.687  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.688  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.691  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.691  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.694  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.694  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.698  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.698  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.701  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.701  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.705  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.708  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.708  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.709  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.712  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.712  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.715  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.716  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.719  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.719  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.722  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.723  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.726  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.726  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.729  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.729  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.733  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.733  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.736  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.736  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.740  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.740  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.743  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.743  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.747  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.747  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.750  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.750  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.753  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.754  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.757  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.758  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.761  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.761  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.764  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.764  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.768  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.768  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.771  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.771  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.775  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.775  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.778  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.778  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.782  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.782  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.785  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.785  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.788  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.789  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-06 20:44:57.792  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.792  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-06 20:44:57.795  - info: mqtt.0 (21783) send2Server eufy-security.0.T8010N2320435969.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320435969/station/lan_ip_address]
2021-02-06 20:44:57.796  - info: eufy-security.0 (23758) state eufy-security.0.T8010N2320435969.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)

And so on. Only a complete restart of iobroker ended this, after that things were back to normal. It flips between the internal and external IP address of the base. Any idea what may have caused this?

Platform: linux os: linux Architecture: arm CPUs: 4 Speed: 1500 MHz Model: ARMv7 Processor rev 3 (v7l) RAM: 3.7 GB System uptime: 5 T. 00:35:40 Node.js: v12.20.1 NPM: 6.14.10 Disk size: 29.0 GiB Disk free: 25.1 GiB adapters count: 326 Uptime: 00:06:45 Active instances: 5

greuff commented 3 years ago

It happened again over night, right after these events:

2021-02-07 00:02:55.011  - debug: eufy-security.0 (24435) PushClient.buildHeartbeatPingRequest(): heartbeatPingRequest: {"last_stream_id_received":40}
2021-02-07 00:02:55.046  - debug: eufy-security.0 (24435) PushClient.handleHeartbeatAck(): message: {"tag":1,"object":{"lastStreamIdReceived":40}}
2021-02-07 00:07:55.012  - debug: eufy-security.0 (24435) PushClient.sendHeartbeat(): streamId: 41
2021-02-07 00:07:55.013  - debug: eufy-security.0 (24435) PushClient.buildHeartbeatPingRequest(): heartbeatPingRequest: {"last_stream_id_received":41}
2021-02-07 00:07:55.048  - debug: eufy-security.0 (24435) PushClient.handleHeartbeatAck(): message: {"tag":1,"object":{"lastStreamIdReceived":41}}
2021-02-07 00:07:59.844  - info: eufy-security.0 (24435) Refresh data from cloud and schedule next refresh.

I've redacted sensitive information from the following lines:

2021-02-07 00:07:59.845  - ^[[34mdebug^[[39m: eufy-security.0 (24435) API.request(): method: post endpoint: app/get_hub_list baseUrl: https://security-app-eu.eufylife.com/v1 token: 93743a17523ecdc8d37653170b6f9a1d32a8df58f13cee98 data: undefined headers: {"app_version":"v2.3.0_792","os_type":"android","os_version":"29","phone_model":"ONEPLUS A3003","country":"DE","language":"de","openudid":"a9e56d3c91514f77","uid":"","net_type":"wifi","mnc":"02","mcc":"262","sn":"120f11f108e6","Model_type":"PHONE","timezone":"GMT+01:00"}
2021-02-07 00:07:59.941  - ^[[34mdebug^[[39m: eufy-security.0 (24435) API.updateDeviceInfo(): stations - Response: {...}
2021-02-07 00:07:59.943  - ^[[34mdebug^[[39m: eufy-security.0 (24435) API.updateDeviceInfo(): stations - element: {...}
2021-02-07 00:07:59.944  - ^[[34mdebug^[[39m: eufy-security.0 (24435) API.updateDeviceInfo(): stations - device_type: 0
2021-02-07 00:07:59.944  - ^[[34mdebug^[[39m: eufy-security.0 (24435) EufySecurity.handleHubs(): hubs: 1
2021-02-07 00:07:59.945  - ^[[34mdebug^[[39m: eufy-security.0 (24435) EufySecurity.handleHubs(): stations: 1
2021-02-07 00:07:59.946  - ^[[34mdebug^[[39m: eufy-security.0 (24435) handleStations(): count: 1
2021-02-07 00:07:59.947  - ^[[34mdebug^[[39m: eufy-security.0 (24435) API.request(): method: post endpoint: app/get_devs_list baseUrl: https://security-app-eu.eufylife.com/v1 token: 93743a17523ecdc8d37653170b6f9a1d32a8df58f13cee98 data: undefined headers: {"app_version":"v2.3.0_792","os_type":"android","os_version":"29","phone_model":"ONEPLUS A3003","country":"DE","language":"de","openudid":"a9e56d3c91514f77","uid":"","net_type":"wifi","mnc":"02","mcc":"262","sn":"120f11f108e6","Model_type":"PHONE","timezone":"GMT+01:00"}
2021-02-07 00:07:59.978  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 00:07:59.990  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 00:07:59.976  - ^[[32minfo^[[39m: mqtt.0 (24028) send2Server eufy-security.0.T8010N2320491172.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320491172/station/lan_ip_address]
2021-02-07 00:07:59.996  - ^[[32minfo^[[39m: mqtt.0 (24028) send2Server eufy-security.0.T8010N2320491172.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320491172/station/lan_ip_address]
2021-02-07 00:07:59.998  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 00:08:00.001  - ^[[32minfo^[[39m: mqtt.0 (24028) send2Server eufy-security.0.T8010N2320491172.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320491172/station/lan_ip_address]
2021-02-07 00:08:00.004  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 00:08:00.007  - ^[[32minfo^[[39m: mqtt.0 (24028) send2Server eufy-security.0.T8010N2320491172.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320491172/station/lan_ip_address]
2021-02-07 00:08:00.009  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 00:08:00.012  - ^[[32minfo^[[39m: mqtt.0 (24028) send2Server eufy-security.0.T8010N2320491172.station.lan_ip_address[iobroker/eufy-security/0/T8010N2320491172/station/lan_ip_address]
...
bropat commented 3 years ago

Hi @greuff ,

I think the problem could be with the configuration of the ioBroker MQTT adapter. How did you configure it?

Did you enable the following option in the MQTT Adapter?

Publish only on change

It almost looks like the MQTT adapter tries to "change" the state in the Eufy-Security Adapter again and again. The following log entry does not mean that the state of the Eufy-Security Adapter is constantly changed, because the adapter ignores a state that is already acknowledged (this additional log entry is actually unnecessary and will not be output in the next version).

2021-02-07 00:08:00.009  - ^[[32minfo^[[39m: eufy-security.0 (24435) state eufy-security.0.T8010N2320491172.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
greuff commented 3 years ago

Hi @bropat , thank you very much for looking into this. This is my MQTT configuration:

image

Yes, the option "publish only on change" is on!

bropat commented 3 years ago

Can you try to put the MQTT adapter in debug mode so that if the problem occurs again we can see what it does?

greuff commented 3 years ago

Ok, did it, this happens every 10 minutes (and doesn't go into the endless loop):

2021-02-07 13:01:43.337  - ^[[34mdebug^[[39m: eufy-security.0 (7108) API.request(): method: post endpoint: app/get_devs_list baseUrl: https://security-app-eu.eufylife.com/v1 token: xxx data: undefined headers: {"app_version":"v2.3.0_792","os_type":"android","os_version":"29","phone_model":"ONEPLUS A3003","country":"DE","language":"de","openudid":"xxx","uid":"","net_type":"wifi","mnc":"02","mcc":"262","sn":"xxx","Model_type":"PHONE","timezone":"GMT+01:00"}
2021-02-07 13:01:43.365  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:01:43.365  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699303362,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699303362}
2021-02-07 13:01:43.367  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:01:43.367  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:01:43.375  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699303372,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699303362}
2021-02-07 13:01:43.374  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:01:43.390  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699303387,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699303387}
2021-02-07 13:01:43.391  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:01:43.392  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:01:43.400  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699303397,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699303387}
2021-02-07 13:01:43.392  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:01:43.401  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)

And this is the start of things going crazy (after about 3 hours):

2021-02-07 13:11:43.610  - ^[[34mdebug^[[39m: eufy-security.0 (7108) API.updateDeviceInfo(): stations - device_type: 0
2021-02-07 13:11:43.610  - ^[[34mdebug^[[39m: eufy-security.0 (7108) EufySecurity.handleHubs(): hubs: 1
2021-02-07 13:11:43.610  - ^[[34mdebug^[[39m: eufy-security.0 (7108) EufySecurity.handleHubs(): stations: 1
2021-02-07 13:11:43.611  - ^[[34mdebug^[[39m: eufy-security.0 (7108) handleStations(): count: 1
2021-02-07 13:11:43.611  - ^[[34mdebug^[[39m: eufy-security.0 (7108) API.request(): method: post endpoint: app/get_devs_list baseUrl: https://security-app-eu.eufylife.com/v1 token: xxx data: undefined headers: {"app_version":"v2.3.0_792","os_type":"android","os_version":"29","phone_model":"ONEPLUS A3003","country":"DE","language":"de","openudid":"xxx","uid":"","net_type":"wifi","mnc":"02","mcc":"262","sn":"120f11f108e6","Model_type":"PHONE","timezone":"GMT+01:00"}
2021-02-07 13:11:43.626  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.627  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903624,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699903624}
2021-02-07 13:11:43.627  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.628  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.632  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903630,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699903630}
2021-02-07 13:11:43.632  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.634  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.633  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.633  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.637  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903630,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903624}
2021-02-07 13:11:43.638  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.638  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.638  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.641  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903636,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903636}
2021-02-07 13:11:43.642  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.642  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.645  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.645  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903643,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903643}
2021-02-07 13:11:43.647  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.646  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.646  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.649  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903645,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903645}
2021-02-07 13:11:43.650  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.650  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.653  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.654  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903651,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903651}
2021-02-07 13:11:43.654  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.654  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.657  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.658  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903655,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903655}
2021-02-07 13:11:43.658  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.659  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.667  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.668  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903666,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903666}
2021-02-07 13:11:43.669  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.669  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.672  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.672  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903670,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903670}
2021-02-07 13:11:43.673  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.673  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.676  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
2021-02-07 13:11:43.677  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903675,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903675}
2021-02-07 13:11:43.678  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.678  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.681  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 192.168.178.45 (ack = true)
2021-02-07 13:11:43.682  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903680,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903680}
2021-02-07 13:11:43.682  - ^[[32minfo^[[39m: mqtt.0 (10775) send2Server eufy-security.0.T8010Nxxx.station.lan_ip_address[iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address]
2021-02-07 13:11:43.683  - ^[[34mdebug^[[39m: mqtt.0 (10775) Send to server "iobroker/iobroker/eufy-security/0/T8010Nxxx/station/lan_ip_address": [object Object]
2021-02-07 13:11:43.686  - ^[[32minfo^[[39m: eufy-security.0 (7108) state eufy-security.0.T8010Nxxx.station.lan_ip_address changed: 78.xxx.xxx.xxx (ack = true)
...
bropat commented 3 years ago

As you can see from the logs, the problem is with the MQTT adapter.

My adapter has changed the same state 2 times (although this is not correct and has already been fixed in the development branch):

"from": "system.adapter.eufy-security.0"

2021-02-07 13:11:43.627  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903624,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699903624}

2021-02-07 13:11:43.632  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903630,"q":0,"from":"system.adapter.eufy-security.0","lc":1612699903630}

On the other hand, with the MQTT adapter you can see that it constantly changes the same state again and again and gets into a loop:

"from": "system.adapter.mqtt.0"

2021-02-07 13:11:43.637  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903630,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903624}

2021-02-07 13:11:43.641  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903636,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903636}

2021-02-07 13:11:43.645  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"78.xxx.xxx.xxx","ack":true,"ts":1612699903643,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903643}

2021-02-07 13:11:43.649  - ^[[34mdebug^[[39m: mqtt.0 (10775) stateChange eufy-security.0.T8010Nxxx.station.lan_ip_address: {"val":"192.168.178.45","ack":true,"ts":1612699903645,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1612699903645}
...

It seems to me a BUG.

I have now written to the developer of the MQTT adapter to understand what the problem is.

greuff commented 3 years ago

Thank you! If there is anything that I can do to help, please let me know.

bropat commented 3 years ago

@greuff They told me to open an issue, so you better open an issue here and refer to this issue there. They will surely ask you more detailed info/tests.

I will leave this issue open until further notice.

bropat commented 3 years ago

@greuff From the other issue I read the problem was fixed by changing a configuration parameter. Could you post the solution here for completeness?

Thanks! :)

greuff commented 3 years ago

Yes, the problem was indeed the (default) configuration of the MQTT adapter. By default it subscribes to every topic on the broker. If you set the "subscribe pattern" to some non-existing topic, the problem disappears. Thanks for your support!