Need Testers
-
Build 24133 userauth
- Force logging to be synchronous, to work around many long-standing issues with the naturally asynchronous nature of nodejs streams.
- Enhance diagnostic reporting for short timers (temporarily, in this branch only).
- Fix some issues with post-login redirection (if you were pushed to the login page by the dashboard or admin UI).
- VirtualEntityController: preserve attribute values if possible across system updates that affect capability definitions or implementations.
- DynamicGroupController: it is now possible to set the primary attribute of a dynamic group, and determine its value dynamically. Trivial example: add the
binary_sensor.stateattribute to a group to show true when any light in the group is on. Refer to the docs for DynamicGroupController. - The
dist-configdirectory is now copied to the user data virtual path target when running in docker containers so that its contents are more easily accessible to docker users. - Fixed an issue in the core related to deleting certain objects (a Global Reaction was reported, but could have been many object types).
- Dashboard: further improvements to widget type guessing if we're not told by the entity configuration.
- Bring
dist-configversion ofusers.yamlinto line with current reality. - Fix the
rpi-status.shtool to work better with HTTPS enabled. - HassController: Bless Hass to 2024.5.2
Note that this build incorporates all changes for
userauthas well aslatestbranch changes not yet deployed for everyone else.Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.
-
Build 24133 userauth
- Force logging to be synchronous, to work around many long-standing issues with the naturally asynchronous nature of nodejs streams.
- Enhance diagnostic reporting for short timers (temporarily, in this branch only).
- Fix some issues with post-login redirection (if you were pushed to the login page by the dashboard or admin UI).
- VirtualEntityController: preserve attribute values if possible across system updates that affect capability definitions or implementations.
- DynamicGroupController: it is now possible to set the primary attribute of a dynamic group, and determine its value dynamically. Trivial example: add the
binary_sensor.stateattribute to a group to show true when any light in the group is on. Refer to the docs for DynamicGroupController. - The
dist-configdirectory is now copied to the user data virtual path target when running in docker containers so that its contents are more easily accessible to docker users. - Fixed an issue in the core related to deleting certain objects (a Global Reaction was reported, but could have been many object types).
- Dashboard: further improvements to widget type guessing if we're not told by the entity configuration.
- Bring
dist-configversion ofusers.yamlinto line with current reality. - Fix the
rpi-status.shtool to work better with HTTPS enabled. - HassController: Bless Hass to 2024.5.2
Note that this build incorporates all changes for
userauthas well aslatestbranch changes not yet deployed for everyone else.@toggledbits I think you also forgot to push userauth-amd64. thanks.
-
@tunnus said in Need Testers:
Not sure if others are experiencing the same, but with this build (userauth-24120-7745fb8d) if I go to Manual (i.e. http://reactor-ip:8111/docs/), it takes a very long time before search can be used as it stays in "initializing search" state. At least I haven't noticed the same with earlier releases. Browser is Chrome.
Anyone else noticed this? @noelab, @Pabla? Other thing I found out today was that there's some kind of a log problem going on, Docker logs claim that reactor.log file cannot be found:
2024/05/11 21:48:36 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:48:32 stdout [Reactor Log Panic] FileLogStream("/var/reactor/logs/reactor.log") error: Error [ERR_STREAM_WRITE_AFTER_END]: write after end 2024/05/11 21:48:32 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:32 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/11 21:48:09 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:48:08 stdout [Reactor Log Panic] FileLogStream("/var/reactor/logs/reactor.log") error: Error [ERR_STREAM_WRITE_AFTER_END]: write after end 2024/05/11 21:48:08 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:48:08 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:08 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:08 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:48:08 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/11 21:46:50 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:46:45 stdout [Reactor Log Panic] FileLogStream("/var/reactor/logs/reactor.log") error: Error [ERR_STREAM_WRITE_AFTER_END]: write after end 2024/05/11 21:46:45 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening stream 2024/05/11 21:46:45 stdout /var/reactor/logs/reactor.log not found; reopening streamBut reactor.log file seems to in place when checked via terminal:
@tunnus said in Need Testers:
@tunnus said in Need Testers:
Not sure if others are experiencing the same, but with this build (userauth-24120-7745fb8d) if I go to Manual (i.e. http://reactor-ip:8111/docs/), it takes a very long time before search can be used as it stays in "initializing search" state. At least I haven't noticed the same with earlier releases. Browser is Chrome.
Anyone else noticed this? @noelab, @Pabla? Other thing I found out today was that there's some kind of a log problem going on, Docker logs claim that reactor.log file cannot be found:
Just quickly tested this and yes it says initializing search. I am using Safari
-
Build 24133 userauth
- Force logging to be synchronous, to work around many long-standing issues with the naturally asynchronous nature of nodejs streams.
- Enhance diagnostic reporting for short timers (temporarily, in this branch only).
- Fix some issues with post-login redirection (if you were pushed to the login page by the dashboard or admin UI).
- VirtualEntityController: preserve attribute values if possible across system updates that affect capability definitions or implementations.
- DynamicGroupController: it is now possible to set the primary attribute of a dynamic group, and determine its value dynamically. Trivial example: add the
binary_sensor.stateattribute to a group to show true when any light in the group is on. Refer to the docs for DynamicGroupController. - The
dist-configdirectory is now copied to the user data virtual path target when running in docker containers so that its contents are more easily accessible to docker users. - Fixed an issue in the core related to deleting certain objects (a Global Reaction was reported, but could have been many object types).
- Dashboard: further improvements to widget type guessing if we're not told by the entity configuration.
- Bring
dist-configversion ofusers.yamlinto line with current reality. - Fix the
rpi-status.shtool to work better with HTTPS enabled. - HassController: Bless Hass to 2024.5.2
Note that this build incorporates all changes for
userauthas well aslatestbranch changes not yet deployed for everyone else.@toggledbits can confirm that this new build (24133) fixes "delete problem", i.e. global reactions can now be deleted without them reappearing. Not seeing those "Reactor Log Panic" messages, but other errors:
2024/05/13 18:51:08 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:51:08 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:51:08 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:51:08 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:51:08 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:51:08 stdout Error: Delay Source Traceback 2024/05/13 18:51:08 stdout [userauth-24133]2024-05-13T15:51:08.837Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:51:08 stdout [userauth-24133]2024-05-13T15:51:08.837Z <Timer:null> Timer#rule-ktmrcd6d just a note: I'm setting a delay of only 8ms (from 1715615468837<5/13/2024, 6:51:08 PM> to 1715615468845<5/13/2024, 6:51:08 PM>) 2024/05/13 18:51:00 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:51:00 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:50:03 stdout [userauth-24133]2024-05-13T15:50:03.915Z <wsapi:CRIT> wsapi: client "172.18.0.1#5" sending authreq 2024/05/13 18:50:02 stdout [userauth-24133]2024-05-13T15:50:02.092Z <wsapi:CRIT> wsapi: client "172.18.0.1#4" sending authreq 2024/05/13 18:49:33 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:49:33 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:48:15 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:48:15 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:47:07 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:47:07 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:46:29 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:46:29 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:46:25 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:46:25 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:46:25 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:46:25 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:46:25 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:46:25 stdout Error: Delay Source Traceback 2024/05/13 18:46:25 stdout [userauth-24133]2024-05-13T15:46:25.384Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:46:25 stdout [userauth-24133]2024-05-13T15:46:25.384Z <Timer:null> Timer#rule-ktmrcd6d just a note: I'm setting a delay of only 8ms (from 1715615185384<5/13/2024, 6:46:25 PM> to 1715615185392<5/13/2024, 6:46:25 PM>) 2024/05/13 18:45:10 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:45:10 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:44:15 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:44:15 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:44:15 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:44:15 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:44:15 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:44:15 stdout Error: Delay Source Traceback 2024/05/13 18:44:15 stdout [userauth-24133]2024-05-13T15:44:15.282Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:44:15 stdout [userauth-24133]2024-05-13T15:44:15.281Z <Timer:null> Timer#rule-grp11myuubg just a note: I'm setting a delay of only 5ms (from 1715615055281<5/13/2024, 6:44:15 PM> to 1715615055286<5/13/2024, 6:44:15 PM>) 2024/05/13 18:44:00 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:44:00 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:43:44 stdout [userauth-24133]2024-05-13T15:43:44.182Z <wsapi:CRIT> wsapi: client "172.18.0.1#3" sending authreq 2024/05/13 18:43:36 stdout [userauth-24133]2024-05-13T15:43:36.850Z <wsapi:CRIT> wsapi: client "172.18.0.1#2" sending authreq 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.574Z <default:null> Module NotifyTelegram v21221 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.564Z <wsapi:CRIT> wsapi: client "172.18.0.1#1" sending authreq 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.293Z <Notifier:null> Module Notifier v22283 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.989Z <SystemController:null> Module SystemController v24076 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.980Z <OWMWeatherController:null> Module OWMWeatherController v22294 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.893Z <HubitatController:null> Module HubitatController v24076 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.830Z <HassController:null> Module HassController v24128 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.526Z <MQTTController:null> Module MQTTController v24120 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.488Z <VirtualEntityController:null> Module VirtualEntityController v24117 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.431Z <VeraController:null> Module VeraController v24050 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.431Z <TaskQueue:null> Module TaskQueue 24113 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.416Z <InfluxFeed:null> Module InfluxFeed v23341 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.312Z <wsapi:null> Module wsapi v24115 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.284Z <httpapi:null> Module httpapi v24121 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.275Z <Engine:null> Module Engine v24113 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.273Z <GlobalReaction:null> Module GlobalReaction v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.268Z <Rule:null> Module Rule v24115 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.265Z <AlertManager:null> Module AlertManager v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.259Z <Predicate:null> Module Predicate v23093 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.243Z <GlobalExpression:null> Module GlobalExpression v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.232Z <default:null> Module Rulesets v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.231Z <default:null> Module Ruleset v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.219Z <Controller:null> Module Controller v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.215Z <Entity:null> Module Entity v24108 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.208Z <TimerBroker:null> Module TimerBroker v22283 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.180Z <Plugin:null> Module Plugin v22300 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.115Z <Capabilities:null> Module Capabilities v23331 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.112Z <Structure:null> Module Structure v24110 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.999Z <app:null> Local date/time using configured timezone and locale formatting is "5/13/2024, 6:43:20 PM" 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.998Z <app:null> Loaded locale en-US for en-US 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.969Z <app:null> Configured locale (undefined); selected locale(s) en-US.UTF-8 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.966Z <app:null> Resolved timezone=Europe/Helsinki, environment TZ=Europe/Helsinki; offset minutes from UTC=180 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.814Z <app:null> NODE_PATH=/opt/reactor:/opt/reactor/node_modules 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.814Z <app:null> Basedir /opt/reactor; data in /var/reactor/storage 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.813Z <app:null> Process ID 1 user/group 0/0; docker; platform linux/x64 #69057 SMP Fri Jan 12 17:02:28 CST 2024; locale (undefined) 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.770Z <app:null> Reactor build userauth-24133-a2bf8846 starting on v20.10.0 /usr/local/bin/node 2024/05/13 18:43:20 stdout NODE_PATH /opt/reactor:/opt/reactor/node_modules 2024/05/13 18:43:20 stdout Reactor userauth-24133-a2bf8846 app [33m24127[39m configuration from /var/reactor/configAlso that manual/docs related problem ("initializing search") is still there, but that was expected as there were no mention of it being fixed.
-
@toggledbits can confirm that this new build (24133) fixes "delete problem", i.e. global reactions can now be deleted without them reappearing. Not seeing those "Reactor Log Panic" messages, but other errors:
2024/05/13 18:51:08 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:51:08 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:51:08 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:51:08 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:51:08 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:51:08 stdout Error: Delay Source Traceback 2024/05/13 18:51:08 stdout [userauth-24133]2024-05-13T15:51:08.837Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:51:08 stdout [userauth-24133]2024-05-13T15:51:08.837Z <Timer:null> Timer#rule-ktmrcd6d just a note: I'm setting a delay of only 8ms (from 1715615468837<5/13/2024, 6:51:08 PM> to 1715615468845<5/13/2024, 6:51:08 PM>) 2024/05/13 18:51:00 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:51:00 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:50:03 stdout [userauth-24133]2024-05-13T15:50:03.915Z <wsapi:CRIT> wsapi: client "172.18.0.1#5" sending authreq 2024/05/13 18:50:02 stdout [userauth-24133]2024-05-13T15:50:02.092Z <wsapi:CRIT> wsapi: client "172.18.0.1#4" sending authreq 2024/05/13 18:49:33 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:49:33 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:48:15 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:48:15 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:47:07 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:47:07 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:46:29 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:46:29 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:46:25 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:46:25 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:46:25 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:46:25 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:46:25 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:46:25 stdout Error: Delay Source Traceback 2024/05/13 18:46:25 stdout [userauth-24133]2024-05-13T15:46:25.384Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:46:25 stdout [userauth-24133]2024-05-13T15:46:25.384Z <Timer:null> Timer#rule-ktmrcd6d just a note: I'm setting a delay of only 8ms (from 1715615185384<5/13/2024, 6:46:25 PM> to 1715615185392<5/13/2024, 6:46:25 PM>) 2024/05/13 18:45:10 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:45:10 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:44:15 stdout at async /opt/reactor/server/lib/Rule.js:885:17 2024/05/13 18:44:15 stdout at process.processTicksAndRejections (node:internal/process/task_queues:95:5) 2024/05/13 18:44:15 stdout at Rule._evaluate (/opt/reactor/server/lib/Rule.js:943:69) 2024/05/13 18:44:15 stdout at Timer.delayms (/opt/reactor/server/lib/Timer.js:151:132) 2024/05/13 18:44:15 stdout at Timer.at (/opt/reactor/server/lib/Timer.js:147:381) 2024/05/13 18:44:15 stdout Error: Delay Source Traceback 2024/05/13 18:44:15 stdout [userauth-24133]2024-05-13T15:44:15.282Z <Timer:CRIT> Error: Delay Source Traceback [-] 2024/05/13 18:44:15 stdout [userauth-24133]2024-05-13T15:44:15.281Z <Timer:null> Timer#rule-grp11myuubg just a note: I'm setting a delay of only 5ms (from 1715615055281<5/13/2024, 6:44:15 PM> to 1715615055286<5/13/2024, 6:44:15 PM>) 2024/05/13 18:44:00 stdout stream /var/reactor/logs/reactor.log not open boolean [33mfalse[39m 2024/05/13 18:44:00 stdout /var/reactor/logs/reactor.log size hit rotation limit, rotating 2024/05/13 18:43:44 stdout [userauth-24133]2024-05-13T15:43:44.182Z <wsapi:CRIT> wsapi: client "172.18.0.1#3" sending authreq 2024/05/13 18:43:36 stdout [userauth-24133]2024-05-13T15:43:36.850Z <wsapi:CRIT> wsapi: client "172.18.0.1#2" sending authreq 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.574Z <default:null> Module NotifyTelegram v21221 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.564Z <wsapi:CRIT> wsapi: client "172.18.0.1#1" sending authreq 2024/05/13 18:43:27 stdout [userauth-24133]2024-05-13T15:43:27.293Z <Notifier:null> Module Notifier v22283 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.989Z <SystemController:null> Module SystemController v24076 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.980Z <OWMWeatherController:null> Module OWMWeatherController v22294 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.893Z <HubitatController:null> Module HubitatController v24076 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.830Z <HassController:null> Module HassController v24128 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.526Z <MQTTController:null> Module MQTTController v24120 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.488Z <VirtualEntityController:null> Module VirtualEntityController v24117 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.431Z <VeraController:null> Module VeraController v24050 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.431Z <TaskQueue:null> Module TaskQueue 24113 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.416Z <InfluxFeed:null> Module InfluxFeed v23341 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.312Z <wsapi:null> Module wsapi v24115 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.284Z <httpapi:null> Module httpapi v24121 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.275Z <Engine:null> Module Engine v24113 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.273Z <GlobalReaction:null> Module GlobalReaction v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.268Z <Rule:null> Module Rule v24115 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.265Z <AlertManager:null> Module AlertManager v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.259Z <Predicate:null> Module Predicate v23093 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.243Z <GlobalExpression:null> Module GlobalExpression v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.232Z <default:null> Module Rulesets v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.231Z <default:null> Module Ruleset v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.219Z <Controller:null> Module Controller v24099 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.215Z <Entity:null> Module Entity v24108 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.208Z <TimerBroker:null> Module TimerBroker v22283 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.180Z <Plugin:null> Module Plugin v22300 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.115Z <Capabilities:null> Module Capabilities v23331 2024/05/13 18:43:21 stdout [userauth-24133]2024-05-13T15:43:21.112Z <Structure:null> Module Structure v24110 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.999Z <app:null> Local date/time using configured timezone and locale formatting is "5/13/2024, 6:43:20 PM" 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.998Z <app:null> Loaded locale en-US for en-US 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.969Z <app:null> Configured locale (undefined); selected locale(s) en-US.UTF-8 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.966Z <app:null> Resolved timezone=Europe/Helsinki, environment TZ=Europe/Helsinki; offset minutes from UTC=180 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.814Z <app:null> NODE_PATH=/opt/reactor:/opt/reactor/node_modules 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.814Z <app:null> Basedir /opt/reactor; data in /var/reactor/storage 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.813Z <app:null> Process ID 1 user/group 0/0; docker; platform linux/x64 #69057 SMP Fri Jan 12 17:02:28 CST 2024; locale (undefined) 2024/05/13 18:43:20 stdout [userauth-24133]2024-05-13T15:43:20.770Z <app:null> Reactor build userauth-24133-a2bf8846 starting on v20.10.0 /usr/local/bin/node 2024/05/13 18:43:20 stdout NODE_PATH /opt/reactor:/opt/reactor/node_modules 2024/05/13 18:43:20 stdout Reactor userauth-24133-a2bf8846 app [33m24127[39m configuration from /var/reactor/configAlso that manual/docs related problem ("initializing search") is still there, but that was expected as there were no mention of it being fixed.
@tunnus The log snippets you are posting appear to be from something other than the log files produced by Reactor. This looks like console log for a container, and I'm not interested in looking at that, mostly because they are a limited subset of message severity and, as I said earlier, drop a lot of other context is valuable to me in evaluating what I'm seeing. Reactor produces its own log files for a reason. If you want to post snippets from that, with context in accordance with the posting guidelines, I'm ready to look at those any time.
Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.
-
@tunnus The log snippets you are posting appear to be from something other than the log files produced by Reactor. This looks like console log for a container, and I'm not interested in looking at that, mostly because they are a limited subset of message severity and, as I said earlier, drop a lot of other context is valuable to me in evaluating what I'm seeing. Reactor produces its own log files for a reason. If you want to post snippets from that, with context in accordance with the posting guidelines, I'm ready to look at those any time.
@toggledbits ok, sorry about that snippet, it was indeed a console log for a container.
I looked through reactor logs, but couldn't see any errors there. A bit challenging as there's a lot going on (a couple of variables update very often, every 1-3 seconds and those cause a lot of log events as rules referencing them get evaluated). Btw, there's a related request/question in this thread.
-
@tunnus If your specific concern is the Timer messages, don't be concerned. Long story shortened: these Timer objects were originally used for long intervals and the warning was put in place to help identify bugs in computing the length of those intervals, but they ended up being used for short intervals, too, and there are some conditions where those intervals can randomly be so short that they trigger the warning. I think it's time for this warning to be relegated to debug level or removed.
You clearly have something that's logging a lot, and that's causing frequent log rotations. This not only wastes time/cycles and bytes on the disk, but it also makes debugging anything on your system harder for the reason you stated: you can't find the errors, likely because (a) it's logging too much (you're sipping from a firehose), and (b) it's rotating so frequently that you're losing useful data quickly.
What I'd suggest is that you identify the affected rules (i.e. those that are responding to the frequent entity attribute changes), and increase their specific log levels to reduce the log output. You can do that for an individual rule. You need to get the rule ID, which you can derive from the UI by opening the rule's state in the list. You can also see it logged. Let's pick on
rule-ktmrcd6d... we modifyconfig/logging.yamlby adding the following:# The line below is indented two spaces; the line after is indented four spaces. "Rule#rule-ktmrcd6d": level: 3This puts the logging minimum level at "NOTICE", so all of the INFO messages associated with rule evaluation will be suppressed for that rule only (other rules will not be affected). That should considerably reduce your log traffic.
I saw your question about the frequent updates as it relates to InfluxDB, and that's a sticky business. I'll respond to that over there.
Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.
-
@tunnus If your specific concern is the Timer messages, don't be concerned. Long story shortened: these Timer objects were originally used for long intervals and the warning was put in place to help identify bugs in computing the length of those intervals, but they ended up being used for short intervals, too, and there are some conditions where those intervals can randomly be so short that they trigger the warning. I think it's time for this warning to be relegated to debug level or removed.
You clearly have something that's logging a lot, and that's causing frequent log rotations. This not only wastes time/cycles and bytes on the disk, but it also makes debugging anything on your system harder for the reason you stated: you can't find the errors, likely because (a) it's logging too much (you're sipping from a firehose), and (b) it's rotating so frequently that you're losing useful data quickly.
What I'd suggest is that you identify the affected rules (i.e. those that are responding to the frequent entity attribute changes), and increase their specific log levels to reduce the log output. You can do that for an individual rule. You need to get the rule ID, which you can derive from the UI by opening the rule's state in the list. You can also see it logged. Let's pick on
rule-ktmrcd6d... we modifyconfig/logging.yamlby adding the following:# The line below is indented two spaces; the line after is indented four spaces. "Rule#rule-ktmrcd6d": level: 3This puts the logging minimum level at "NOTICE", so all of the INFO messages associated with rule evaluation will be suppressed for that rule only (other rules will not be affected). That should considerably reduce your log traffic.
I saw your question about the frequent updates as it relates to InfluxDB, and that's a sticky business. I'll respond to that over there.
-
@tunnus If your specific concern is the Timer messages, don't be concerned. Long story shortened: these Timer objects were originally used for long intervals and the warning was put in place to help identify bugs in computing the length of those intervals, but they ended up being used for short intervals, too, and there are some conditions where those intervals can randomly be so short that they trigger the warning. I think it's time for this warning to be relegated to debug level or removed.
You clearly have something that's logging a lot, and that's causing frequent log rotations. This not only wastes time/cycles and bytes on the disk, but it also makes debugging anything on your system harder for the reason you stated: you can't find the errors, likely because (a) it's logging too much (you're sipping from a firehose), and (b) it's rotating so frequently that you're losing useful data quickly.
What I'd suggest is that you identify the affected rules (i.e. those that are responding to the frequent entity attribute changes), and increase their specific log levels to reduce the log output. You can do that for an individual rule. You need to get the rule ID, which you can derive from the UI by opening the rule's state in the list. You can also see it logged. Let's pick on
rule-ktmrcd6d... we modifyconfig/logging.yamlby adding the following:# The line below is indented two spaces; the line after is indented four spaces. "Rule#rule-ktmrcd6d": level: 3This puts the logging minimum level at "NOTICE", so all of the INFO messages associated with rule evaluation will be suppressed for that rule only (other rules will not be affected). That should considerably reduce your log traffic.
I saw your question about the frequent updates as it relates to InfluxDB, and that's a sticky business. I'll respond to that over there.
@toggledbits thanks for the tip, now logging traffic is considerably slower (log rotation ca. 10 minutes)
-
userauth build 24137
- Updated the documentation theme and its supporting plugins; improved the appearance of code snippets with syntax highlighting in most cases; add line highlighting in many code snippets to draw attention to certain elements or changes.
- Dashboard: added new Thermostat type (supported by Level.updown layout) for capabilities hvac_heating_unit/hvac_cooling_unit. Evolving; further improvements coming.
- VirtualEntityController: Support for time-series data collection and aggregation. See the docs). As of this build, not all aggregators have been tested.
- Remove spurious debug warning about short timers.
- Fix detection of local docs and handling of static HTML files in the local installation.
- HassController: Bless Hass to 2024.5.3
Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.
-
userauth build 24137
- Updated the documentation theme and its supporting plugins; improved the appearance of code snippets with syntax highlighting in most cases; add line highlighting in many code snippets to draw attention to certain elements or changes.
- Dashboard: added new Thermostat type (supported by Level.updown layout) for capabilities hvac_heating_unit/hvac_cooling_unit. Evolving; further improvements coming.
- VirtualEntityController: Support for time-series data collection and aggregation. See the docs). As of this build, not all aggregators have been tested.
- Remove spurious debug warning about short timers.
- Fix detection of local docs and handling of static HTML files in the local installation.
- HassController: Bless Hass to 2024.5.3
@toggledbits thanks, can confirm that (local) manual is fixed now, no more "initializing search"
-
@toggledbits I think the
restart reactorbutton is down again. When I click it I'm pushed back to the user login screen and immediately login to see the Status screen loading normally... not showingDisconnectedas it usually does as it restarts. Logs provided in Dropbox. -
Does it do that every time you use it?
-
Does it do that every time you use it?
@toggledbits Yessir.
-
OK. That's normal behavior if the login/session cookie expires or is no longer valid. And it's all browser-side, so the logs aren't of any value there. And it's working for me, so we may have to dig a little. Next time you are tempted to use the Restart button, just do a plain refresh on your browser and see (report) what happens.
Also, what browser are you using? And, please upload your users.yaml file (redact any plaintext passwords)
-
OK. That's normal behavior if the login/session cookie expires or is no longer valid. And it's all browser-side, so the logs aren't of any value there. And it's working for me, so we may have to dig a little. Next time you are tempted to use the Restart button, just do a plain refresh on your browser and see (report) what happens.
Also, what browser are you using? And, please upload your users.yaml file (redact any plaintext passwords)
@toggledbits Using Brave browser. Redacted
users.yamlon it's way. -
If you just refresh the page instead of hitting the button, does it refresh, or go to the login page?
