[SOLVED]Hass websocket falsely reporting ready on boot??
-
Hi, @toggledbits
I just noticed that following a reboot of my raspberry pi, some of the rules, that I was expecting to recover, are not catching up following a reboot. I have made a simple test rule (rule-m6rz6ol1) with only "after Date/time" as trigger and "turn on a lamp" as a set reaction. All my infrastructure is on the same board so Reactor, Hass, Zwavejs, ... are all rebooting.
Here is the sequence of the test case (All time converted to Zulu to match logs):
- Rule "after Date/Time" set to 14:05:00z
- Shutdown on Raspberry Pi at 14:04:00z
- Power back up at 14:08:00z
- Rule overview shows true as of 14:08:14z waiting for 00:00:00 in GUI
From the log I can see that MSR is picking up the rule and knows that the state of the rule has changed from false to true and tries to send the update to HASS but failed with websocket error.
Here is what I see from the log:
- 14:04:04z shutdown complete
- 14:08:08z Power up
- 14:08:13.111z websocket connection
- 14:08:15:323z Reaction to the light failed, Websocket not opened
- After there is a series of websocket connection attempt until 14:08:51z where it seemed to be really ready.
Back in 2021 we had a discussion (https://smarthome.community/topic/700/solved-start-up?_=1738766986566) and you proposed to add a startup_delay:xxxx and startup_wait:xxxx parameter in the engine section of "reactor.yaml". When I try the startup_delay (this used to be a hard delay), the engine failed to start (I think). I then try the startup_wait:xxxx without any success. Since it wait for the connection status to be up to cancel the delay, it does not do anyting since Hass is reporting the socket up without really being up ( I think...).
Questions:
- Did I figured it all wrong?
- should the startup_delay:xxxxx have worked?
- Any ideas?
Here is the log:
OK now I am stuck. I did add the log but when I submit the editor complained saying that I am limited to 32767 characters. The log from the shutdown to the time the websocket is stable is about 300000 character long. What are my options?
-
Set
wait_all_controllers: true
in yourengine
subsection. The default delay is 60 seconds. If that's not enough, setstartup_wait
(units are milliseconds) to something larger than 60000. -
@toggledbits I have a similar issue but I do not have a wait_all_controllers: true in my engine subsection.
I just add it I suppose ? Thanks
This is what I have under engine.
engine: # enabled - whether or not the rules engine runs. Change only when directed. enabled: true # # startup_wait - Time to wait for all controllers to come ready. Reactor often starts faster # than most hubs, so this pause allows Reactor to wait for a tunable time. The # Engine is not started until all controllers are ready or this timeout # expires. See https://smarthome.community/topic/700/start-up startup_wait: 600000 # milliseconds, default 60000 (one minute) # # allow_shell_action - The "Shell Command" reaction action comes with some security risks, so # by default it is disabled. To enable it, set this value true. # allow_shell_action: true # allow_shell_action_substitution: true # # shell_action_timeout - The "Shell Command" action will allow the running command to run for # up to this many milliseconds before it terminates it (to prevent run- # away processes). The default is 30000 (milliseconds, 30 seconds). #shell_action_timeout: 30000 # # monitored_entities - if you can't figure out what is changing an entity, # (not the data, but the physical device, like a light # that is being turned on or off at an unexpected time), # you can add it to this list and the logs will post # a message whenever an action is performed on the # device (no log level changes are needed, the message # is unconditional). # monitored_entities: # - vera>device_XXX
-
@toggledbits I have a similar issue but I do not have a wait_all_controllers: true in my engine subsection.
I just add it I suppose ? Thanks
This is what I have under engine.
engine: # enabled - whether or not the rules engine runs. Change only when directed. enabled: true # # startup_wait - Time to wait for all controllers to come ready. Reactor often starts faster # than most hubs, so this pause allows Reactor to wait for a tunable time. The # Engine is not started until all controllers are ready or this timeout # expires. See https://smarthome.community/topic/700/start-up startup_wait: 600000 # milliseconds, default 60000 (one minute) # # allow_shell_action - The "Shell Command" reaction action comes with some security risks, so # by default it is disabled. To enable it, set this value true. # allow_shell_action: true # allow_shell_action_substitution: true # # shell_action_timeout - The "Shell Command" action will allow the running command to run for # up to this many milliseconds before it terminates it (to prevent run- # away processes). The default is 30000 (milliseconds, 30 seconds). #shell_action_timeout: 30000 # # monitored_entities - if you can't figure out what is changing an entity, # (not the data, but the physical device, like a light # that is being turned on or off at an unexpected time), # you can add it to this list and the logs will post # a message whenever an action is performed on the # device (no log level changes are needed, the message # is unconditional). # monitored_entities: # - vera>device_XXX
@Snowman said in Hass websocket falsely reporting ready on boot??:
I do not have a
wait_all_controllers: true
in my engine subsection.I just add it I suppose ?
Correct!
-
With startup_wait: 120000 I have the same result as before.
-Rule set to trigger at 00:55z
-Shutdown down completed at 00:54:27z
-First log entry after power up at 00:58:06
-Socket connection with Hass at 00:58:12z[latest-25016]2025-02-06T00:54:27.398Z <Structure:NOTICE> Structure Structure#1 stopped [latest-25016]2025-02-06T00:54:27.398Z <app:NOTICE> Closing APIs... [latest-25016]2025-02-06T00:54:27.398Z <wsapi:NOTICE> wsapi: closing... [latest-25016]2025-02-06T00:54:27.399Z <wsapi:NOTICE> wsapi: disconnecting from "192.168.2.33#1" (1001 service closing) [latest-25016]2025-02-06T00:54:27.401Z <httpapi:NOTICE> HTTP API closing... [latest-25016]2025-02-06T00:54:27.403Z <wsapi:NOTICE> wsapi: server closed [latest-25016]2025-02-06T00:54:27.405Z <wsapi:WARN> client close from unknown connection? "192.168.2.33#1" [latest-25016]2025-02-06T00:58:06.180Z <app:null> Reactor build latest-25016-d47fea38 starting on v20.10.0 /usr/local/bin/node [latest-25016]2025-02-06T00:58:06.198Z <app:null> Process ID 1 user/group 0/0; docker; platform linux/arm64 #1 SMP PREEMPT Debian 1:6.6.74-1+rpt1 (2025-01-27); locale (undefined) [latest-25016]2025-02-06T00:58:06.203Z <app:null> Basedir /opt/reactor; data in /var/reactor/storage [latest-25016]2025-02-06T00:58:06.207Z <app:null> NODE_PATH=/opt/reactor:/opt/reactor/node_modules [latest-25016]2025-02-06T00:58:06.278Z <app:null> Resolved timezone=America/Toronto, environment TZ=America/Toronto; offset minutes from UTC=-300 [latest-25016]2025-02-06T00:58:06.337Z <app:null> Configured locale (undefined); selected locale(s) en-US.UTF-8 [latest-25016]2025-02-06T00:58:06.532Z <app:null> Loaded locale en-US for en-US [latest-25016]2025-02-06T00:58:06.534Z <app:null> Local date/time using configured timezone and locale formatting is "2/5/2025, 7:58:06 PM" [latest-25016]2025-02-06T00:58:07.077Z <Structure:null> Module Structure v24287 [latest-25016]2025-02-06T00:58:07.086Z <Capabilities:null> Module Capabilities v24312 [latest-25016]2025-02-06T00:58:07.289Z <Capabilities:NOTICE> System capabilities loaded from core distribution, data version 25004 revision 1 [latest-25016]2025-02-06T00:58:07.784Z <Plugin:null> Module Plugin v22300 [latest-25016]2025-02-06T00:58:08.260Z <TimerBroker:null> Module TimerBroker v22283 [latest-25016]2025-02-06T00:58:08.284Z <Entity:null> Module Entity v25014 [latest-25016]2025-02-06T00:58:08.455Z <Controller:null> Module Controller v25014 [latest-25016]2025-02-06T00:58:08.786Z <default:null> Module Ruleset v24288 [latest-25016]2025-02-06T00:58:08.789Z <default:null> Module Rulesets v24220 [latest-25016]2025-02-06T00:58:09.072Z <GlobalExpression:null> Module GlobalExpression v24209 [latest-25016]2025-02-06T00:58:09.216Z <Predicate:null> Module Predicate v24350 [latest-25016]2025-02-06T00:58:09.274Z <AlertManager:null> Module AlertManager v24099 [latest-25016]2025-02-06T00:58:09.310Z <Rule:null> Module Rule v24329 [latest-25016]2025-02-06T00:58:09.348Z <GlobalReaction:null> Module GlobalReaction v24220 [latest-25016]2025-02-06T00:58:09.368Z <Engine:null> Module Engine v24344 [latest-25016]2025-02-06T00:58:09.422Z <httpapi:null> Module httpapi v24298 [latest-25016]2025-02-06T00:58:09.517Z <wsapi:null> Module wsapi v25016 [latest-25016]2025-02-06T00:58:09.520Z <app:NOTICE> Starting Structure... [latest-25016]2025-02-06T00:58:09.548Z <Structure:NOTICE> Structure#1 plugin ID influx disabled; skipping [latest-25016]2025-02-06T00:58:09.553Z <Structure:INFO> Structure#1 loading controller interface hass (HassController) [latest-25016]2025-02-06T00:58:09.796Z <HassController:null> Module HassController v25010 [latest-25016]2025-02-06T00:58:12.086Z <Structure:INFO> Structure#1 loading controller interface groups (DynamicGroupController) [latest-25016]2025-02-06T00:58:12.119Z <DynamicGroupController:null> Module DynamicGroupController v24279 [latest-25016]2025-02-06T00:58:12.157Z <Structure:INFO> Structure#1 loading controller interface reactor_system (SystemController) [latest-25016]2025-02-06T00:58:12.177Z <SystemController:null> Module SystemController v24279 [latest-25016]2025-02-06T00:58:12.202Z <Structure:INFO> Starting controller HassController#hass [latest-25016]2025-02-06T00:58:12.203Z <HassController:NOTICE> HassController#hass starting... [latest-25016]2025-02-06T00:58:12.205Z <Structure:INFO> Starting controller DynamicGroupController#groups [latest-25016]2025-02-06T00:58:12.218Z <Controller:NOTICE> Controller DynamicGroupController#groups is now online. [latest-25016]2025-02-06T00:58:12.218Z <Structure:INFO> Starting controller SystemController#reactor_system [latest-25016]2025-02-06T00:58:12.226Z <Controller:NOTICE> Controller SystemController#reactor_system is now online. [latest-25016]2025-02-06T00:58:12.515Z <Engine:null> [Engine]Engine#1 config [Object]{ "enabled": true, "startup_wait": 120000, "monitored_entities": [ "vera>device_XXX" ] } [latest-25016]2025-02-06T00:58:12.563Z <HassController:INFO> HassController#hass performing one-time initialization for HassController class [latest-25016]2025-02-06T00:58:12.598Z <Controller:INFO> HassController#hass loaded hass capabilities ver 25004 rev 1 format 1 [latest-25016]2025-02-06T00:58:12.686Z <Controller:INFO> HassController#hass loaded implementation data ver 25004 rev 2 format 1 [latest-25016]2025-02-06T00:58:12.715Z <HassController:INFO> HassController#hass device mapping data loaded; checking... [latest-25016]2025-02-06T00:58:12.752Z <HassController:NOTICE> HassController#hass connecting to wss://192.168.2.163:8123/api/websocket [latest-25016]2025-02-06T00:58:12.818Z <app:NOTICE> Starting HTTP server and API... [latest-25016]2025-02-06T00:58:12.861Z <httpapi:NOTICE> [HTTPAPI]#1 starting HTTP service on port 8111 [latest-25016]2025-02-06T00:58:12.874Z <app:NOTICE> Starting Reaction Engine... [latest-25016]2025-02-06T00:58:12.876Z <Engine:INFO> Reaction Engine starting [latest-25016]2025-02-06T00:58:12.878Z <Engine:INFO> Checking rule sets... [latest-25016]2025-02-06T00:58:12.907Z <Engine:INFO> Checking rules... [latest-25016]2025-02-06T00:58:12.921Z <Rule:5:Rule.js:209> Rule#rule-134 cleaning loaded condition states [latest-25016]2025-02-06T00:58:12.931Z <Rule:5:Rule.js:209> Rule#rule-136 cleaning loaded condition states
At 00:58:15z Sending reaction request to hass failed
[latest-25016]2025-02-06T00:58:15.289Z <Engine:5:Engine.js:1786> [Engine]Engine#1 reaction rule-m6rz6ol1:S step 0 perform [Object]{ "entity": "hass>switch_plug_in_outlet_floater", "action": "power_switch.on" } [latest-25016]2025-02-06T00:58:15.293Z <HassController:INFO> HassController#hass perform power_switch.on on Switch#hass>switch_plug_in_outlet_floater with [Object]{ } [latest-25016]2025-02-06T00:58:15.296Z <HassController:WARN> HassController#hass unknown service homeassistant.turn_on in power_switch.on action on Switch#hass>switch_plug_in_outlet_floater [latest-25016]2025-02-06T00:58:15.296Z <HassController:INFO> HassController#hass no entity/target for homeassistant.(undefined) [latest-25016]2025-02-06T00:58:15.296Z <HassController:INFO> HassController#hass: sending payload for power_switch.on on Switch#hass>switch_plug_in_outlet_floater action: [Object]{ "type": "call_service", "service_data": { }, "domain": "homeassistant", "service": "turn_on" } [latest-25016]2025-02-06T00:58:15.301Z <Engine:5:Engine.js:1641> _process_reaction_queue() task returned, new status 3; task 1, history 86213 [latest-25016]2025-02-06T00:58:15.303Z <HassController:ERR> HassController#hass request 1738803495298<2/5/2025, 7:58:15 PM> (call_service) failed: [Error] WebSocket is not open: readyState 0 (CONNECTING) [-] [latest-25016]2025-02-06T00:58:15.304Z <Engine:5:Engine.js:1688> _process_reaction_queue ending with 1 in queue; none delayed/ready; waiting [latest-25016]2025-02-06T00:58:15.305Z <HassController:WARN> HassController#hass action power_switch.on([Object]{ }) on Switch#hass>switch_plug_in_outlet_floater failed! [latest-25016]2025-02-06T00:58:15.306Z <HassController:INFO> Service call payload: {"type":"call_service","service_data":{},"domain":"homeassistant","service":"turn_on","id":1738803495298} [latest-25016]2025-02-06T00:58:15.307Z <HassController:INFO> Service data: {} [latest-25016]2025-02-06T00:58:15.309Z <Engine:ERR> [Engine]Engine#1 reaction rule-m6rz6ol1:S step 0 perform power_switch.on failed: [Error] WebSocket is not open: readyState 0 (CONNECTING) [-] [latest-25016]2025-02-06T00:58:15.309Z <Engine:INFO> [Engine]Engine#1 action args: [Object]{ } [latest-25016]2025-02-06T00:58:15.310Z <Engine:5:Engine.js:1688> _process_reaction_queue() wake-up! [latest-25016]2025-02-06T00:58:15.311Z <Engine:5:Engine.js:1627> _process_reaction_queue() running task 1: [Object]{ "tid": 1, "id": "rule-m6rz6ol1:S", "rule": "rule-m6rz6ol1", "__reaction": [RuleReaction#rule-m6rz6ol1:S], "next_step": 1, "status": 1, "ts": 1738803495021, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "attempts": 0, "history_id": 86213 } [latest-25016]2025-02-06T00:58:15.313Z <Engine:INFO> Resuming reaction rule-m6rz6ol1<SET> (rule-m6rz6ol1:S) from step 1 [latest-25016]2025-02-06T00:58:15.313Z <Engine:INFO> rule-m6rz6ol1<SET> all actions completed. [latest-25016]2025-02-06T00:58:15.314Z <Engine:5:Engine.js:1641> _process_reaction_queue() task returned, new status -1; task 1, history 86213 [latest-25016]2025-02-06T00:58:15.323Z <Engine:5:Engine.js:1688> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
After that I have several socket up and down message until 00:58:52z where it seemed to stabilised.
Error: Hub reports it is starting but not yet ready at /opt/reactor/server/lib/HassController.js:1291:66 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) [latest-25016]2025-02-06T00:58:30.573Z <HassController:NOTICE> HassController#hass websocket closing, 1006 [latest-25016]2025-02-06T00:58:35.574Z <HassController:NOTICE> HassController#hass connecting to wss://192.168.2.163:8123/api/websocket [latest-25016]2025-02-06T00:58:35.892Z <HassController:NOTICE> HassController#hass connected, starting protocol [latest-25016]2025-02-06T00:58:35.900Z <HassController:INFO> HassController#hass successful authentication with wss://192.168.2.163:8123; fetching initial data... [latest-25016]2025-02-06T00:58:35.908Z <HassController:INFO> HassController#hass Hass reports version "2025.1.0" location Maison timezone America/Toronto state NOT_RUNNING safe_mode false [latest-25016]2025-02-06T00:58:35.909Z <HassController:ERR> HassController#hass failed to complete startup: [Error] Hub reports it is starting but not yet ready [-] [latest-25016]2025-02-06T00:58:35.910Z <HassController:CRIT> Error: Hub reports it is starting but not yet ready [-] Error: Hub reports it is starting but not yet ready at /opt/reactor/server/lib/HassController.js:1291:66 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) [latest-25016]2025-02-06T00:58:35.912Z <HassController:NOTICE> HassController#hass websocket closing, 1006 [latest-25016]2025-02-06T00:58:40.918Z <HassController:NOTICE> HassController#hass connecting to wss://192.168.2.163:8123/api/websocket [latest-25016]2025-02-06T00:58:40.954Z <HassController:NOTICE> HassController#hass connected, starting protocol [latest-25016]2025-02-06T00:58:40.959Z <HassController:INFO> HassController#hass successful authentication with wss://192.168.2.163:8123; fetching initial data... [latest-25016]2025-02-06T00:58:40.963Z <HassController:INFO> HassController#hass Hass reports version "2025.1.0" location Maison timezone America/Toronto state NOT_RUNNING safe_mode false [latest-25016]2025-02-06T00:58:40.964Z <HassController:ERR> HassController#hass failed to complete startup: [Error] Hub reports it is starting but not yet ready [-] [latest-25016]2025-02-06T00:58:40.964Z <HassController:CRIT> Error: Hub reports it is starting but not yet ready [-] Error: Hub reports it is starting but not yet ready at /opt/reactor/server/lib/HassController.js:1291:66 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) [latest-25016]2025-02-06T00:58:40.966Z <HassController:NOTICE> HassController#hass websocket closing, 1006 [latest-25016]2025-02-06T00:58:45.969Z <HassController:NOTICE> HassController#hass connecting to wss://192.168.2.163:8123/api/websocket [latest-25016]2025-02-06T00:58:46.716Z <HassController:NOTICE> HassController#hass connected, starting protocol [latest-25016]2025-02-06T00:58:46.735Z <HassController:INFO> HassController#hass successful authentication with wss://192.168.2.163:8123; fetching initial data... [latest-25016]2025-02-06T00:58:46.747Z <HassController:INFO> HassController#hass Hass reports version "2025.1.0" location Maison timezone America/Toronto state NOT_RUNNING safe_mode false [latest-25016]2025-02-06T00:58:46.748Z <HassController:ERR> HassController#hass failed to complete startup: [Error] Hub reports it is starting but not yet ready [-] [latest-25016]2025-02-06T00:58:46.748Z <HassController:CRIT> Error: Hub reports it is starting but not yet ready [-] Error: Hub reports it is starting but not yet ready at /opt/reactor/server/lib/HassController.js:1291:66 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) [latest-25016]2025-02-06T00:58:46.750Z <HassController:NOTICE> HassController#hass websocket closing, 1006 [latest-25016]2025-02-06T00:58:51.756Z <HassController:NOTICE> HassController#hass connecting to wss://192.168.2.163:8123/api/websocket [latest-25016]2025-02-06T00:58:51.898Z <HassController:NOTICE> HassController#hass connected, starting protocol [latest-25016]2025-02-06T00:58:51.930Z <HassController:INFO> HassController#hass successful authentication with wss://192.168.2.163:8123; fetching initial data... [latest-25016]2025-02-06T00:58:52.055Z <HassController:INFO> HassController#hass Hass reports version "2025.1.0" location Maison timezone America/Toronto state RUNNING safe_mode false [latest-25016]2025-02-06T00:58:52.935Z <Rule:5:Rule.js:366> Rule#rule-grpol1jp4l Summer Day At Home requesting eval; entity-changed from Entity#hass>input_select_house_mode [latest-25016]2025-02-06T00:58:52.936Z <Rule:5:Rule.js:366> Rule#rule-grp15p0yq5k Summer Evening At Home requesting eval; entity-changed from Entity#hass>input_select_house_mode [latest-25016]2025-02-06T00:58:52.936Z <Rule:5:Rule.js:366> Rule#rule-grpol67dc7 Summer Night At Home requesting eval; entity-chang
-
You must have
wait_all_controllers: true
in your config orstartup_wait
isn't used at all.The
controllers
section is an array. Make sure DynamicGroupController and SystemController are the last two entries in the array. Use yamllint.com or a similar tool to make sure the format of your config file is perfect. -
All right, that did the trick.
I can clearly see in the log where it is waiting for the connection to be stable and sending the request only after. This is great!
The 3 alarm are still showing when I use the "reboot reactor" from the Tools menu. It seems that it is only transitory since a screen refresh or re-starting the browser clears it. This is also fine.
Just making sure that I understand the process. Please correct me where I am wrong.
-
without adding wait_all_controllers: true to the engine subsection, there is no delay
-
with the wait_all_controllers: true the default delay is 60 second
-
If the default delay is not enough then we can use startup_wait: xxxx to change the default delay
-
In all cases the delay is only the maximum delay and the wait will be terminated when the connections is made.
-
If I have 5 controllers, are they all treated individually or the slowest one need to be up before anything happen?
@toggledbits said in Hass websocket falsely reporting ready on boot??:
The controllers section is an array. Make sure DynamicGroupController and SystemController are the last two entries in the array.
I am not sure I understand this one. I never played with the reactor.yaml file, I simply took the template and fill it up. I fail to see why these 2 controller need to be last. In my case I had 2 unused one between the two like it is in the template. I did move them but I am not sure that it really did anything.
Many thanks for your support
-
-
All right, that did the trick.
I can clearly see in the log where it is waiting for the connection to be stable and sending the request only after. This is great!
The 3 alarm are still showing when I use the "reboot reactor" from the Tools menu. It seems that it is only transitory since a screen refresh or re-starting the browser clears it. This is also fine.
Just making sure that I understand the process. Please correct me where I am wrong.
-
without adding wait_all_controllers: true to the engine subsection, there is no delay
-
with the wait_all_controllers: true the default delay is 60 second
-
If the default delay is not enough then we can use startup_wait: xxxx to change the default delay
-
In all cases the delay is only the maximum delay and the wait will be terminated when the connections is made.
-
If I have 5 controllers, are they all treated individually or the slowest one need to be up before anything happen?
@toggledbits said in Hass websocket falsely reporting ready on boot??:
The controllers section is an array. Make sure DynamicGroupController and SystemController are the last two entries in the array.
I am not sure I understand this one. I never played with the reactor.yaml file, I simply took the template and fill it up. I fail to see why these 2 controller need to be last. In my case I had 2 unused one between the two like it is in the template. I did move them but I am not sure that it really did anything.
Many thanks for your support
@vezinpi said in Hass websocket falsely reporting ready on boot??:
Just making sure that I understand the process. Please correct me where I am wrong.
without adding wait_all_controllers: true to the engine subsection, there is no delay
with the wait_all_controllers: true the default delay is 60 second
If the default delay is not enough then we can use startup_wait: xxxx to change the default delay
In all cases the delay is only the maximum delay and the wait will be terminated when the connections is made.
This is all correct.
If I have 5 controllers, are they all treated individually or the slowest one need to be up before anything happen?
wait_all_controllers
means it is waiting until the slowest controller signals on line.I did move them but I am not sure that it really did anything.
It affects the startup order. DynamicGroupController in particular is very sensitive to its position, since its configuration rules refer to devices owned by other controllers.
-
-
As I sometimes seen the Controller off-line message I thought to give this a try. Added wait_all_controllers and startup_wait. When I then restart Reactor in Tools, I get a controller offline in the status window for all controllers!?! All of them are up as I am only touching reactor. I took the two options out again and status messages gone. Oddly in the reactor.log no message about off-line controllers.
[latest-25016]2025-02-07T09:08:01.620Z <app:null> Reactor build latest-25016-d47fea38 starting on v22.12.0 /usr/local/bin/node [latest-25016]2025-02-07T09:08:01.620Z <app:null> Process ID 1 user/group 0/0; docker; platform linux/x64 #72806 SMP Thu Sep 5 13:41:01 CST 2024; locale (undefined) [latest-25016]2025-02-07T09:08:01.621Z <app:null> Basedir /opt/reactor; data in /var/reactor/storage [latest-25016]2025-02-07T09:08:01.621Z <app:null> NODE_PATH=/opt/reactor:/opt/reactor/node_modules [latest-25016]2025-02-07T09:08:01.644Z <app:null> Resolved timezone=Europe/Amsterdam, environment TZ=Europe/Amsterdam; offset minutes from UTC=60 [latest-25016]2025-02-07T09:08:01.647Z <app:null> Configured locale (undefined); selected locale(s) en-US.UTF-8 [latest-25016]2025-02-07T09:08:01.664Z <app:null> Loaded locale en-US for en-US [latest-25016]2025-02-07T09:08:01.665Z <app:null> Local date/time using configured timezone and locale formatting is "2/7/2025, 10:08:01 AM" [latest-25016]2025-02-07T09:08:01.714Z <Structure:null> Module Structure v24287 [latest-25016]2025-02-07T09:08:01.716Z <Capabilities:null> Module Capabilities v24312 [latest-25016]2025-02-07T09:08:01.736Z <Capabilities:NOTICE> System capabilities loaded from core distribution, data version 25004 revision 1 [latest-25016]2025-02-07T09:08:01.747Z <Plugin:null> Module Plugin v22300 [latest-25016]2025-02-07T09:08:01.767Z <TimerBroker:null> Module TimerBroker v22283 [latest-25016]2025-02-07T09:08:01.770Z <Entity:null> Module Entity v25014 [latest-25016]2025-02-07T09:08:01.773Z <Controller:null> Module Controller v25014 [latest-25016]2025-02-07T09:08:01.784Z <default:null> Module Ruleset v24288 [latest-25016]2025-02-07T09:08:01.784Z <default:null> Module Rulesets v24220 [latest-25016]2025-02-07T09:08:01.789Z <GlobalExpression:null> Module GlobalExpression v24209 [latest-25016]2025-02-07T09:08:01.800Z <Predicate:null> Module Predicate v24350 [latest-25016]2025-02-07T09:08:01.806Z <AlertManager:null> Module AlertManager v24099 [latest-25016]2025-02-07T09:08:01.809Z <Rule:null> Module Rule v24329 [latest-25016]2025-02-07T09:08:01.813Z <GlobalReaction:null> Module GlobalReaction v24220 [latest-25016]2025-02-07T09:08:01.814Z <Engine:null> Module Engine v24344 [latest-25016]2025-02-07T09:08:01.819Z <httpapi:null> Module httpapi v24298 [latest-25016]2025-02-07T09:08:01.831Z <wsapi:null> Module wsapi v25016 [latest-25016]2025-02-07T09:08:01.832Z <app:NOTICE> Starting Structure... [latest-25016]2025-02-07T09:08:01.855Z <InfluxFeed:null> Module InfluxFeed v23341 [latest-25016]2025-02-07T09:08:01.857Z <Structure:INFO> Structure#1 starting plugin influx (InfluxFeed) [latest-25016]2025-02-07T09:08:01.857Z <Structure:INFO> Structure#1 loading controller interface openLuup (VeraController) [latest-25016]2025-02-07T09:08:01.881Z <TaskQueue:null> Module TaskQueue 24138 [latest-25016]2025-02-07T09:08:01.924Z <VeraController:null> Module VeraController v25014 [latest-25016]2025-02-07T09:08:01.979Z <Structure:INFO> Structure#1 loading controller interface hubitat-C8 (HubitatController) [latest-25016]2025-02-07T09:08:01.995Z <HubitatController:null> Module HubitatController v24355 [latest-25016]2025-02-07T09:08:02.035Z <Structure:INFO> Structure#1 loading controller interface hubitat-C7 (HubitatController) [latest-25016]2025-02-07T09:08:02.048Z <Structure:INFO> Structure#1 loading controller interface hass (HassController) [latest-25016]2025-02-07T09:08:02.057Z <HassController:null> Module HassController v25010 [latest-25016]2025-02-07T09:08:02.282Z <Structure:INFO> Structure#1 loading controller interface groups (DynamicGroupController) [latest-25016]2025-02-07T09:08:02.288Z <DynamicGroupController:null> Module DynamicGroupController v24279 [latest-25016]2025-02-07T09:08:02.291Z <Structure:INFO> Structure#1 loading controller interface reactor_system (SystemController) [latest-25016]2025-02-07T09:08:02.294Z <SystemController:null> Module SystemController v24279 [latest-25016]2025-02-07T09:08:02.298Z <Structure:INFO> Starting controller VeraController#openLuup [latest-25016]2025-02-07T09:08:02.298Z <VeraController:NOTICE> VeraController#openLuup starting... [latest-25016]2025-02-07T09:08:02.298Z <Structure:INFO> Starting controller HubitatController#hubitat-C8 [latest-25016]2025-02-07T09:08:02.299Z <Structure:INFO> Starting controller HubitatController#hubitat-C7 [latest-25016]2025-02-07T09:08:02.299Z <Structure:INFO> Starting controller HassController#hass [latest-25016]2025-02-07T09:08:02.299Z <HassController:NOTICE> HassController#hass starting... [latest-25016]2025-02-07T09:08:02.299Z <Structure:INFO> Starting controller DynamicGroupController#groups [latest-25016]2025-02-07T09:08:02.301Z <Controller:NOTICE> Controller DynamicGroupController#groups is now online. [latest-25016]2025-02-07T09:08:02.301Z <Structure:INFO> Starting controller SystemController#reactor_system [latest-25016]2025-02-07T09:08:02.302Z <Controller:NOTICE> Controller SystemController#reactor_system is now online. [latest-25016]2025-02-07T09:08:02.367Z <Engine:null> [Engine]Engine#1 config [Object]{ "enabled": true, "wait_all_controllers": true, "startup_wait": 60000, "monitored_entities": [ "vera>device_XXX" ] } [latest-25016]2025-02-07T09:08:02.371Z <VeraController:INFO> VeraController#openLuup performing one-time initialization for VeraController class [latest-25016]2025-02-07T09:08:02.378Z <Controller:INFO> VeraController#openLuup loaded vera capabilities ver 22253 rev 1 format 1 [latest-25016]2025-02-07T09:08:02.398Z <Controller:INFO> VeraController#openLuup loaded implementation data ver 25014 rev 1 format 1 [latest-25016]2025-02-07T09:08:02.398Z <HubitatController:INFO> HubitatController#hubitat-C8 performing one-time initialization for HubitatController class [latest-25016]2025-02-07T09:08:02.399Z <Controller:INFO> HubitatController#hubitat-C8 loaded hubitat capabilities ver 24279 rev 1 format 1 [latest-25016]2025-02-07T09:08:02.407Z <Controller:INFO> HubitatController#hubitat-C8 loaded implementation data ver 24345 rev 1 format 1 [latest-25016]2025-02-07T09:08:02.407Z <HassController:INFO> HassController#hass performing one-time initialization for HassController class [latest-25016]2025-02-07T09:08:02.408Z <Controller:INFO> HassController#hass loaded hass capabilities ver 25004 rev 1 format 1 [latest-25016]2025-02-07T09:08:02.414Z <Controller:INFO> HassController#hass loaded implementation data ver 25004 rev 2 format 1 [latest-25016]2025-02-07T09:08:02.417Z <HassController:INFO> HassController#hass device mapping data loaded; checking... [latest-25016]2025-02-07T09:08:02.421Z <HassController:NOTICE> HassController#hass connecting to ws://192.168.178.201:8123/api/websocket [latest-25016]2025-02-07T09:08:02.424Z <app:NOTICE> Waiting for controllers to start up... [latest-25016]2025-02-07T09:08:02.429Z <HubitatController:NOTICE> HubitatController#hubitat-C8 performing initial connection and inventory [latest-25016]2025-02-07T09:08:02.430Z <HubitatController:NOTICE> HubitatController#hubitat-C7 performing initial connection and inventory [latest-25016]2025-02-07T09:08:02.444Z <HassController:NOTICE> HassController#hass connected, starting protocol [latest-25016]2025-02-07T09:08:02.445Z <HassController:INFO> HassController#hass successful authentication with ws://192.168.178.201:8123; fetching initial data... [latest-25016]2025-02-07T09:08:02.490Z <HassController:INFO> HassController#hass Hass reports version "2025.2.0" location Home timezone Europe/Amsterdam state RUNNING safe_mode false [latest-25016]2025-02-07T09:08:02.493Z <HassController:ERR> HassController#hass reported Hass version "2025.2.0" is not supported! [latest-25016]2025-02-07T09:08:02.519Z <HassController:NOTICE> HassController#hass no signature match for conversation.home_assistant [latest-25016]2025-02-07T09:08:02.528Z <HassController:NOTICE> HassController#hass no signature match for sun.sun [latest-25016]2025-02-07T09:08:02.535Z <HassController:NOTICE> HassController#hass no signature match for tts.google_en_com [latest-25016]2025-02-07T09:08:02.536Z <HassController:NOTICE> HassController#hass no signature match for event.hue_switch_1_button_4 [latest-25016]2025-02-07T09:08:02.536Z <HassController:NOTICE> HassController#hass no signature match for event.hue_switch_1_button_3 [latest-25016]2025-02-07T09:08:02.537Z <HassController:NOTICE> HassController#hass no signature match for event.hue_switch_1_button_1 [latest-25016]2025-02-07T09:08:02.537Z <HassController:NOTICE> HassController#hass no signature match for event.hue_switch_1_button_2 [latest-25016]2025-02-07T09:08:02.561Z <HassController:NOTICE> HassController#hass no signature match for update.hacs_update [latest-25016]2025-02-07T09:08:02.562Z <HassController:NOTICE> HassController#hass no signature match for update.entso_e_transparency_platform_update [latest-25016]2025-02-07T09:08:02.563Z <HassController:NOTICE> HassController#hass no signature match for update.hubitat_update [latest-25016]2025-02-07T09:08:02.564Z <HassController:NOTICE> HassController#hass no signature match for update.power_flow_card_update [latest-25016]2025-02-07T09:08:02.564Z <HassController:NOTICE> HassController#hass no signature match for update.apexcharts_card_update [latest-25016]2025-02-07T09:08:02.574Z <HassController:NOTICE> HassController#hass no signature match for update.netdrive_dsm_update [latest-25016]2025-02-07T09:08:02.605Z <HassController:NOTICE> HassController#hass no signature match for event.sun_screens [latest-25016]2025-02-07T09:08:02.615Z <HassController:NOTICE> HassController#hass no signature match for remote.woonkamer [latest-25016]2025-02-07T09:08:02.642Z <HassController:NOTICE> HassController#hass no signature match for update.fritz_box_5590_fiber_fritz_os [latest-25016]2025-02-07T09:08:02.647Z <HassController:NOTICE> HassController#hass no signature match for event.garage_door_motor_button_1 [latest-25016]2025-02-07T09:08:02.647Z <HassController:NOTICE> HassController#hass no signature match for event.garage_door_motor_button_2 [latest-25016]2025-02-07T09:08:02.686Z <HassController:NOTICE> HassController#hass no signature match for hubitat.hub [latest-25016]2025-02-07T09:08:02.688Z <HassController:NOTICE> HassController#hass no signature match for image.fritz_box_5590_fiber_rbguestaccess [latest-25016]2025-02-07T09:08:02.764Z <Controller:INFO> HassController#hass 0 dead entities older than 86400000s purged [latest-25016]2025-02-07T09:08:02.770Z <Controller:NOTICE> Controller HassController#hass is now online. [latest-25016]2025-02-07T09:08:02.779Z <HubitatController:INFO> HubitatController#hubitat-C7 Maker API responded with 21 devices [latest-25016]2025-02-07T09:08:02.814Z <HubitatController:WARN> HubitatController#hubitat-C7 native capability URL no definition data; skipped [latest-25016]2025-02-07T09:08:02.827Z <Controller:INFO> HubitatController#hubitat-C7 0 dead entities older than 86400000s purged [latest-25016]2025-02-07T09:08:02.827Z <HubitatController:NOTICE> HubitatController#hubitat-C7 A connection health probe device was not configured. A randomly-selected device will be used. [latest-25016]2025-02-07T09:08:02.827Z <HubitatController:NOTICE> Please refer to the HubitatController configuration docs for more information. [latest-25016]2025-02-07T09:08:02.829Z <HubitatController:INFO> HubitatController#hubitat-C7 connecting to hub's eventsocket WebSocket API at ws://192.168.178.107/eventsocket [latest-25016]2025-02-07T09:08:02.833Z <HubitatController:INFO> HubitatController#hubitat-C8 Maker API responded with 66 devices [latest-25016]2025-02-07T09:08:02.881Z <HubitatController:WARN> HubitatController#hubitat-C8 native capability URL no definition data; skipped [latest-25016]2025-02-07T09:08:02.899Z <Controller:INFO> HubitatController#hubitat-C8 0 dead entities older than 86400000s purged [latest-25016]2025-02-07T09:08:02.899Z <HubitatController:NOTICE> HubitatController#hubitat-C8 A connection health probe device was not configured. A randomly-selected device will be used. [latest-25016]2025-02-07T09:08:02.899Z <HubitatController:NOTICE> Please refer to the HubitatController configuration docs for more information. [latest-25016]2025-02-07T09:08:02.900Z <HubitatController:INFO> HubitatController#hubitat-C8 connecting to hub's eventsocket WebSocket API at ws://192.168.178.104/eventsocket [latest-25016]2025-02-07T09:08:02.993Z <Controller:INFO> VeraController#openLuup 0 dead entities older than 86400000s purged [latest-25016]2025-02-07T09:08:02.994Z <Controller:NOTICE> Controller VeraController#openLuup is now online. [latest-25016]2025-02-07T09:08:03.015Z <HubitatController:INFO> HubitatController#hubitat-C8 successful connection to ws://192.168.178.104/eventsocket [latest-25016]2025-02-07T09:08:03.016Z <HubitatController:INFO> HubitatController#hubitat-C7 successful connection to ws://192.168.178.107/eventsocket [latest-25016]2025-02-07T09:08:03.078Z <HubitatController:NOTICE> HubitatController#hubitat-C8 current mode is Home (65) [latest-25016]2025-02-07T09:08:03.117Z <VeraController:NOTICE> VeraController#openLuup reload detected (status query with LoadTime 1733911518 in response; expected "1469238424") [latest-25016]2025-02-07T09:08:03.164Z <HubitatController:NOTICE> HubitatController#hubitat-C7 current mode is Home (6) [latest-25016]2025-02-07T09:08:03.168Z <Controller:NOTICE> Controller HubitatController#hubitat-C8 is now online. [latest-25016]2025-02-07T09:08:03.185Z <HubitatController:WARN> HubitatController#hubitat-C7 'Allow control of HSM' appears to be disabled in your Maker API configuration [latest-25016]2025-02-07T09:08:03.186Z <Controller:NOTICE> Controller HubitatController#hubitat-C7 is now online. [latest-25016]2025-02-07T09:08:03.186Z <DynamicGroupController:INFO> All controllers ready, setting up dynamic groups [latest-25016]2025-02-07T09:08:03.199Z <app:NOTICE> All 6 controllers successfully started.
Cheers Rene
-
Did you refresh the page?
-
Yes, clear status messages. Click reload. Wait until I see Connected and then go to the status page to see them in alerts.
@mrFarmer said in [SOLVED]Hass websocket falsely reporting ready on boot??:
Yes, clear status messages. Click reload. Wait until I see Connected and then go to the status page to see them in alerts.
When you say reload do you mean "Restart Reactor" from the "Tool" menu? If so, the alarm will show right back until you refresh the page or restart your browser again. In my case the messages are only transitory following a "Restart Reactor" and are gone after I refresh the page.
-
@mrFarmer said in [SOLVED]Hass websocket falsely reporting ready on boot??:
Yes, clear status messages. Click reload. Wait until I see Connected and then go to the status page to see them in alerts.
When you say reload do you mean "Restart Reactor" from the "Tool" menu? If so, the alarm will show right back until you refresh the page or restart your browser again. In my case the messages are only transitory following a "Restart Reactor" and are gone after I refresh the page.
-
The alerts persisting is a sync problem with the alerts data object. I've found and (hopefully) fixed it for the next build. Both it and the Controller Status widget need special handing when the API connection is restarted.