search

jheling / freeathome

Free@Home component for Home Assistant
114 stars 41 forks source link

Home Assistant starts, not everything will be available until it's done. #61

Closed Cavekeeper closed 4 years ago

Cavekeeper commented 4 years ago

Raspberry PI 3 is not booting with activated component freeathome. Message while booting: Home Assistant starts, not everything will be available until it's done. This message will not disappear.

Log: 2020-06-27 12:02:48 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=217 from 2020-06-27 09:54:41.129232) 2020-06-27 12:02:58 WARNING (MainThread) [slixmpp.stringprep] Using slower stringprep, consider compiling the faster cython/libidn one. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.setup] Setup of freeathome is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.weather] Setup of weather platform met is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform darksky is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform openweathermap is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform command_line is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform dwd_weather_warnings is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform mobile_app is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform mobile_app is taking over 10 seconds. 2020-06-27 12:03:17 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform mobile_app is taking over 10 seconds. 2020-06-27 12:03:17 ERROR (MainThread) [metno] https://aa015h6buqvih86i1.api.met.no/weatherapi/locationforecast/1.9/ returned 2020-06-27 12:03:17 ERROR (MainThread) [homeassistant.components.met.weather] Retrying in 18 minutes 2020-06-27 12:03:17 ERROR (MainThread) [homeassistant.components.sensor] Error while setting up coronavirus platform for sensor Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 186, in _async_setup_platform await asyncio.gather(*pending) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 292, in async_add_entities await asyncio.gather(*tasks) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 443, in _async_add_entity entity.async_write_ha_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 297, in async_write_ha_state self._async_write_ha_state() # type: ignore File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 320, in _async_write_ha_state state = self.state File "/usr/src/homeassistant/homeassistant/components/coronavirus/sensor.py", line 55, in state getattr(case, self.info_type) for case in self.coordinator.data.values() TypeError: unsupported operand type(s) for +: 'int' and 'NoneType'

I case the component freeathome is deactivated the RPI will boot without any problems. RPI System:

The next check was to transfer the identical configuration to another system: Synology virtual machine:

The problem does not occur on this machine.

It looks like the problem is related to HA version 0.111.4 and the RPI.3 as well as freeathome.

jheling commented 4 years ago

Hello, if you turn the logging to INFO, do you see any logging of the FAH component? I have just upgraded my test environment to this version (it is running on a pi 2).

Cavekeeper commented 4 years ago

Hello, I have checked the logs. No, everything seems to be ok. No errors especially to FAH. A few days earlier I added another device to freeathome. There are now about 60 devices registered. I am not sure if the problem has occurred since then. The rpi ran trouble-free until the end and was rarely rebooted. Now I have already installed the rpi again. The boot problem continues to occur. In rare cases, however, it also runs up smoothly. The next time you restart, the problems will arise again. Oddly enough, the same constellation runs absolutely smoothly on the Synology Virtual System.

jheling commented 4 years ago

What is the last freeathome entry in the log? Mine is : 2020-06-29 08:19:10 INFO (MainThread) [custom_components.freeathome.light] FreeAtHome setup light. After that I see logging with freeathome status updates.

Cavekeeper commented 4 years ago

I have found these logs: 2020-06-29 13:27:12 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for freeathome which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant. 2020-06-29 13:27:34 WARNING (MainThread) [homeassistant.setup] Setup of freeathome is taking over 10 seconds. In the meantime I had put on a new SD card with HA and played back the backup. Then there were several error messages regarding the HA database. I tried the following solution from this page and simply deleted the DB and restarted HA. Then the rpi ran up smoothly. At the moment I do not know whether it was possibly due to the database. I will watch this and boot the rpi sporadically.

Cavekeeper commented 4 years ago

Unfortunately, the problem still occurs. For a while I can reboot the rpi without problems. Then at some point it stops working and the following error message appears: "Home Assistant starts, not everything will be available until it's done." If I exclude the component freeathome, the rpi boots without problems. During the last attempt it helped to delete the file "home-assistant_v2.db". This is no longer possible. What can I do here for further troubleshooting? FYI, the using free@home version is V2.5.1. Is it possible not to load scenes from freeathome into HA? Maybe to exclude them?

jheling commented 4 years ago

As I said, turning the logging level to INFO wil show more information about the startup of homeassistant. You will also get more information of the Free@home component.

Cavekeeper commented 4 years ago

Yes, off course. Please refer to the log below. I don´t understand the connection issue. This is only a small selection of the entries. There are many more of them. Could it be an IPV6 problem?

2020-07-06 11:47:44 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for freeathome which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant. 2020-07-06 11:48:01 INFO (MainThread) [custom_components.freeathome.pfreeathome] Connect Free@Home 101acfcc-b83a-477c-994b-ad92b1710f1f@busch-jaeger.de 2020-07-06 11:48:01 INFO (MainThread) [custom_components.freeathome.pfreeathome] version: 2.5.1 2020-07-06 11:48:01 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 11:48:14 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 11:48:17 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection

RPI and SysAP have a fixed IP address. Next I changed the IP address to SysAP.local in configuration.yaml. Unfortunately the same result: no connection. Within my network, the SysAP can be reached as normal. The ping command is always positive.

This entry in the log is infinite. 2020-07-06 12:04:42 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection

jheling commented 4 years ago

My version of the firmware is 2.4 , but that should not be a problem. Later in the logging you should see something like below appearing:

2020-06-29 08:19:06 INFO (MainThread) [slixmpp.features.feature_bind.bind] JID set to: b6f51e17-b6b4-4c61-951b-8209e0be7e48@busch-jaeger.de/e22d027d 2020-06-29 08:19:07 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Received new session result

One of the last loggings should be: 2020-06-29 08:19:08 INFO (MainThread) [custom_components.freeathome.pfreeathome] Roster callback

after that all the devices of your system should be logged.

have you tried a reset of the sysap? Sometimes i had to do this to get the whole thing working again.

Cavekeeper commented 4 years ago

No, this entry "2020-06-29 08:19:08 INFO (MainThread) [custom_components.freeathome.pfreeathome] Roster callback" does not appear. The last entries are all the connection problems. There is nothing more. I have taken SysAP off the network several times and restarted. It doesn´t be helpful.

My next trail, now I have started the HA again with the same configuration in the Virtual Manager of my Synology. This seems to have connected. However, only after the 3rd attempt.

2020-07-06 13:29:37 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for freeathome which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant. 2020-07-06 13:29:44 INFO (MainThread) [custom_components.freeathome.pfreeathome] Connect Free @ Home 101acfcc-b83a-477c-994b-ad92b1710f1f@busch-jaeger.de 2020-07-06 13:29:44 INFO (MainThread) [custom_components.freeathome.pfreeathome] version: 2.5.1 2020-07-06 13:29:44 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 13:29:47 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 13:29:51 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 13:29:52 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 13:29:54 INFO (MainThread) [custom_components.freeathome.pfreeathome] waiting for connection 2020-07-06 13:29:54 INFO (MainThread) [custom_components.freeathome.fah.crypto] 2 2020-07-06 13:29:54 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Received new session result 2020-07-06 13:29:54 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] 1 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Received response login sasl 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Received response challenge 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Received SASL Login Confirmation 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.fah.saslhandler] Successfully Authenticated 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.pfreeathome] send presence 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.pfreeathome] get roster 2020-07-06 13:29:55 INFO (MainThread) [custom_components.freeathome.pfreeathome] Roster callback

The connection doesn't always work either. It is a coincidence when HA in the VM connects to SysAP. However, this works better than with rpi. With the rpi I can no longer connect.

Cavekeeper commented 4 years ago

My next test looks a little better. I installed a new HA instance on the rpi and was able to connect to FAH the first time. I will now try to rebuild everything with this new HA instance without playing back a backup. However, my HA installation is very extensive. Maybe I can do it. That is my only hope now.

jheling commented 4 years ago

I have just accepted a pull request for code that reconnects after the connection is lost. Maybe this will help too.

Cavekeeper commented 4 years ago

I think I've solved the problem. During the step-by-step reinstallation of the RPI, I noticed that the problem occurred after installing the sensor.yaml backup. So I looked for the problem within this file. After I cleaned this up, the RPI started up without any problems. It is only puzzling what this has to do with FAH. But now the RPI has been running smoothly for several days. Several restarts also worked perfectly.