Before diving into the issue, I'd like to thank you for updating the Velbus integration! A faster startup thanks to the caching of the modules will be a nice QoL improvement :-)
However, there seems to be an issue for the moment, which causes all kind of issues (state in HA not properly synced with state of Velbus switches for example):
2021-10-08 11:34:59 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: sensor.velbus, climate.velbus, binary_sensor.velbus, switch.velbus, cover.velbus, light.velbus
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.sensor] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.climate] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.binary_sensor] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.switch] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.cover] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:35:02 ERROR (MainThread) [homeassistant.components.light] Setup of platform velbus is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2021-10-08 11:39:05 WARNING (MainThread) [homeassistant.bootstrap] Setup timed out for bootstrap - moving forward
2021-10-08 11:44:32 ERROR (MainThread) [velbus] Not all modules are loaded within a timeout of 600 seconds, continuing with the loaded modules
I've increased the logging in HA, and have attached the output of the velbus module (
velbus_init.log ). Some other interesting lines from homeassistant.core are:
2021-10-08 13:27:44 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=velbus, service=scan>
2021-10-08 13:27:44 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=velbus, service=sync_clock>
2021-10-08 13:27:44 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=velbus, service=set_memo_text>
2021-10-08 13:27:44 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=velbus>
2021-10-08 13:28:49 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-662' coro=<velbus_connect_task() running at /usr/src/homeassistant/homeassistant/components/velbus/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f3153a514c0>()]> cb=[<TaskWakeupMethWrapper object at 0x7f3159a2d880>(), <4 more>, <TaskWakeupMethWrapper object at 0x7f3159a333a0>()]>
2021-10-08 13:29:49 DEBUG (MainThread) [homeassistant.core] Waited 120 seconds for task: <Task pending name='Task-662' coro=<velbus_connect_task() running at /usr/src/homeassistant/homeassistant/components/velbus/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f3153a514c0>()]> cb=[<TaskWakeupMethWrapper object at 0x7f3159a2d880>(), <4 more>, <TaskWakeupMethWrapper object at 0x7f3159a333a0>()]>
2021-10-08 13:30:49 DEBUG (MainThread) [homeassistant.core] Waited 180 seconds for task: <Task pending name='Task-662' coro=<velbus_connect_task() running at /usr/src/homeassistant/homeassistant/components/velbus/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f3153a514c0>()]> cb=[<TaskWakeupMethWrapper object at 0x7f3159a2d880>(), <4 more>, <TaskWakeupMethWrapper object at 0x7f3159a333a0>()]>
2021-10-08 13:31:49 DEBUG (MainThread) [homeassistant.core] Waited 240 seconds for task: <Task pending name='Task-662' coro=<velbus_connect_task() running at /usr/src/homeassistant/homeassistant/components/velbus/__init__.py:58> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f3153a514c0>()]> cb=[<TaskWakeupMethWrapper object at 0x7f3159a2d880>(), <4 more>, <TaskWakeupMethWrapper object at 0x7f3159a333a0>()]>
I've checked my /config/.storage/.velbuscache folder, and can see some files in there:
_ velbuscache ls -lah
total 80K
drwxr-xr-x 2 root root 4.0K Oct 8 09:02 .
drwxr-xr-x 4 root root 4.0K Oct 8 11:39 ..
-rw-r--r-- 1 root root 5.1K Oct 8 11:34 1.p
-rw-r--r-- 1 root root 4.5K Oct 8 11:34 16.p
-rw-r--r-- 1 root root 4.6K Oct 8 11:34 17.p
-rw-r--r-- 1 root root 4.6K Oct 8 11:34 18.p
-rw-r--r-- 1 root root 5.1K Oct 8 11:34 2.p
-rw-r--r-- 1 root root 5.3K Oct 8 09:45 22.p
-rw-r--r-- 1 root root 5.1K Oct 8 11:34 3.p
-rw-r--r-- 1 root root 5.1K Oct 8 11:34 4.p
-rw-r--r-- 1 root root 6.9K Oct 8 11:34 6.p
However, if one file per module is to be expected, a lot of them are missing for the moment:
Please let me know how I can help you to debug the issue.
Before diving into the issue, I'd like to thank you for updating the Velbus integration! A faster startup thanks to the caching of the modules will be a nice QoL improvement :-)
However, there seems to be an issue for the moment, which causes all kind of issues (state in HA not properly synced with state of Velbus switches for example):
I've increased the logging in HA, and have attached the output of the velbus module ( velbus_init.log ). Some other interesting lines from
homeassistant.coreare:I've checked my
/config/.storage/.velbuscachefolder, and can see some files in there:However, if one file per module is to be expected, a lot of them are missing for the moment:
Please let me know how I can help you to debug the issue.