I may have posted this in the wrong section. MSR running on Bare metal Debian bullseye. Both Openluup and MSR are on the same device (an Intel NUC) at IP 192.168.70.249. Any suggestions as to where I go to resolve?
TIA
Happy new year, everyone! Hope all are well!
Looking for some pointers troubleshooting a slightly puzzling to me issue. When digging around on a different issue I noticed this happening regularly in the MSR logs:
[latest-24366]2025-01-10T19:50:07.630Z <Engine:NOTICE> Starting reaction Garden lights on when the doors are open<SET> (rule-lb2h69nb:S) [latest-24366]2025-01-10T19:50:07.630Z <VeraController:INFO> VeraController#vera perform action power_switch.on on Switch#vera>device_20060 with [Object]{ } [latest-24366]2025-01-10T19:50:07.630Z <VeraController:INFO> VeraController#vera perform action power_switch.set on Switch#vera>device_20060 with [Object]{ "state": true } [latest-24366]2025-01-10T19:50:07.670Z <VeraController:NOTICE> VeraController#vera action power_switch.set([Object]{ "state": true }) on Switch#vera>device_20060 succeeded [latest-24366]2025-01-10T19:50:07.671Z <Engine:INFO> Resuming reaction Garden lights on when the doors are open<SET> (rule-lb2h69nb:S) from step 1 [latest-24366]2025-01-10T19:50:07.672Z <Engine:NOTICE> Garden lights on when the doors are open<SET> delaying until 1736538787672<10/01/2025, 19:53:07> [latest-24366]2025-01-10T19:50:19.595Z <Rule:INFO> Garden lights on when the doors are open (rule-lb2h69nb in Outside Lights) evaluated; rule state transition from SET to RESET! [latest-24366]2025-01-10T19:52:16.506Z <Rule:INFO> Garden lights on when the doors are open (rule-lb2h69nb in Outside Lights) evaluated; rule state transition from RESET to SET! [latest-24366]2025-01-10T19:52:16.515Z <Engine:INFO> [Engine]Engine#1 not enqueueing rule-lb2h69nb:S: already in queue with status 2 [latest-24366]2025-01-10T19:52:20.823Z <Rule:INFO> Garden lights on when the doors are open (rule-lb2h69nb in Outside Lights) evaluated; rule state transition from SET to RESET! [latest-24366]2025-01-10T19:53:07.676Z <Engine:INFO> Resuming reaction Garden lights on when the doors are open<SET> (rule-lb2h69nb:S) from step 2 [latest-24366]2025-01-10T19:53:07.677Z <VeraController:INFO> VeraController#vera perform action power_switch.off on Switch#vera>device_20060 with [Object]{ } [latest-24366]2025-01-10T19:53:07.678Z <VeraController:INFO> VeraController#vera perform action power_switch.set on Switch#vera>device_20060 with [Object]{ "state": false } [latest-24366]2025-01-10T19:53:07.719Z <VeraController:NOTICE> VeraController#vera action power_switch.set([Object]{ "state": false }) on Switch#vera>device_20060 succeeded [latest-24366]2025-01-10T19:53:07.720Z <Engine:INFO> Resuming reaction Garden lights on when the doors are open<SET> (rule-lb2h69nb:S) from step 3 [latest-24366]2025-01-10T19:53:07.721Z <Engine:INFO> Garden lights on when the doors are open<SET> all actions completed. [latest-24366]2025-01-10T19:55:04.468Z <VeraController:ERR> VeraController#vera update request failed: [FetchError] network timeout at: http://192.168.70.249:3480/data_request?id=status&Timeout=15&DataVersion=416912953&MinimumDelay=50&output_format=json&_r=1736538886459 [-] [latest-24366]2025-01-10T19:55:09.646Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20050: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20050) [-] [latest-24366]2025-01-10T19:55:09.646Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.646Z <VeraController:CRIT> *Entity#vera>device_20050 [latest-24366]2025-01-10T19:55:09.656Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20570: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20570) [-] [latest-24366]2025-01-10T19:55:09.656Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.656Z <VeraController:CRIT> *Entity#vera>device_20570 [latest-24366]2025-01-10T19:55:09.678Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20610: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20610) [-] [latest-24366]2025-01-10T19:55:09.679Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.679Z <VeraController:CRIT> *Entity#vera>device_20610 [latest-24366]2025-01-10T19:55:09.744Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20631: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20631) [-] [latest-24366]2025-01-10T19:55:09.744Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.744Z <VeraController:CRIT> *Entity#vera>device_20631 [latest-24366]2025-01-10T19:55:09.889Z <VeraController:NOTICE> VeraController#vera reload detected! [latest-24366]2025-01-10T19:55:09.910Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20050: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20050) [-] [latest-24366]2025-01-10T19:55:09.910Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.910Z <VeraController:CRIT> *Entity#vera>device_20050 [latest-24366]2025-01-10T19:55:09.935Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20570: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20570) [-] [latest-24366]2025-01-10T19:55:09.936Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.936Z <VeraController:CRIT> *Entity#vera>device_20570 [latest-24366]2025-01-10T19:55:09.937Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20610: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20610) [-] [latest-24366]2025-01-10T19:55:09.937Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.937Z <VeraController:CRIT> *Entity#vera>device_20610 [latest-24366]2025-01-10T19:55:09.939Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20631: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20631) [-] [latest-24366]2025-01-10T19:55:09.939Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.939Z <VeraController:CRIT> *Entity#vera>device_20631 [latest-24366]2025-01-10T19:55:09.968Z <Controller:INFO> VeraController#vera 0 dead entities older than 86400000s purged [latest-24366]2025-01-10T19:55:10.037Z <VeraController:NOTICE> VeraController#vera reload detected!That repeats until something like this:
[latest-24366]2025-01-10T19:55:10.049Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20050: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20050) [-] [latest-24366]2025-01-10T19:55:10.049Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:10.049Z <VeraController:CRIT> *Entity#vera>device_20050 [latest-24366]2025-01-10T19:55:10.053Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20570: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20570) [-] [latest-24366]2025-01-10T19:55:10.053Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:10.053Z <VeraController:CRIT> *Entity#vera>device_20570 [latest-24366]2025-01-10T19:55:10.062Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20610: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20610) [-] [latest-24366]2025-01-10T19:55:10.062Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:10.062Z <VeraController:CRIT> *Entity#vera>device_20610 [latest-24366]2025-01-10T19:55:10.112Z <VeraController:WARN> VeraController#vera failed to apply attribute scene_activation.scene_id to Entity#vera>device_20631: [TypeError] Can't set NaN on attribute scene_activation.scene_id (vera>device_20631) [-] [latest-24366]2025-01-10T19:55:10.112Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:10.113Z <VeraController:CRIT> *Entity#vera>device_20631 [latest-24366]2025-01-10T20:00:05.003Z <Engine:INFO> [Engine]Engine#1 master timer tick, local time "10/01/2025 20:00:05" (TZ offset 0 mins from UTC) [latest-24366]2025-01-10T20:13:51.872Z <Rule:INFO> No motion in Cinema (rule-m4ocglke in Cinema Environment) evaluated; rule state transition from SET to RESET! [latest-24366]2025-01-10T20:13:51.882Z <Rule:INFO> Cinema Heater On (rule-m4ocf1di in Cinema Environment) evaluated; rule state transition from RESET to SET! [latest-24366]2025-01-10T20:13:51.888Z <Engine:INFO> Enqueueing "Cinema Heater On<SET>" (rule-m4ocf1di:S)And the errors / reloads just stop.
From Openluup:
2025-01-10 19:49:56.379 luup_log:63: BroadLink_Mk2 debug: RM3 Mini - IR 1: urn:schemas-micasaverde-com:device:IrTransmitter:1 2025-01-10 19:50:00.085 luup_log:0: 14Mb, 1.7%cpu, 36.1days 2025-01-10 19:50:07.591 luup.variable_set:: 20160.urn:micasaverde-com:serviceId:EnergyMetering1.KWH was: 18.6793008 now: 18.6805008 #hooks:0 2025-01-10 19:50:07.591 luup.variable_set:: 20160.urn:micasaverde-com:serviceId:EnergyMetering1.KWHReading was: 1736538000 now: 1736538600 #hooks:0 2025-01-10 19:50:07.591 luup.variable_set:: 20160.urn:micasaverde-com:serviceId:EnergyMetering1.Watts was: 7.4 now: 7.3 #hooks:0 2025-01-10 19:50:07.591 luup.variable_set:: 20170.urn:micasaverde-com:serviceId:EnergyMetering1.KWH was: 32.2417984 now: 32.2470016 #hooks:0 2025-01-10 19:50:07.591 luup.variable_set:: 20170.urn:micasaverde-com:serviceId:EnergyMetering1.KWHReading was: 1736538000 now: 1736538600 #hooks:0 2025-01-10 19:50:07.591 luup.variable_set:: 20330.urn:micasaverde-com:serviceId:EnergyMetering1.KWHReading was: 1736538000 now: 1736538600 #hooks:0 2025-01-10 19:50:07.592 luup.variable_set:: 20770.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 0 now: 1 #hooks:0 2025-01-10 19:50:07.592 luup.variable_set:: 20770.urn:micasaverde-com:serviceId:SecuritySensor1.LastTrip was: 1736534850 now: 1736538607 #hooks:0 2025-01-10 19:50:07.593 openLuup.server:: request completed (3392 bytes, 1 chunks, 12875 ms) tcp{client}: 0x55c3299a9cf8 2025-01-10 19:50:07.618 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c3299a9cf8 2025-01-10 19:50:07.624 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329d0a5b8 2025-01-10 19:50:07.624 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912906&MinimumDelay=50&output_format=json&_r=1736538607623 HTTP/1.1 tcp{client}: 0x55c329d0a5b8 2025-01-10 19:50:07.632 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c3292ed678 2025-01-10 19:50:07.633 openLuup.server:: GET /data_request?newTargetValue=1&DeviceNum=20060&id=action&serviceId=urn%3Aupnp-org%3AserviceId%3ASwitchPower1&action=SetTarget&output_format=json&_r=1736538607631 HTTP/1.1 tcp{client}: 0x55c3 292ed678 2025-01-10 19:50:07.633 luup.call_action:: 20060.urn:upnp-org:serviceId:SwitchPower1.SetTarget 2025-01-10 19:50:07.633 luup.call_action:: action will be handled by parent: 37 2025-01-10 19:50:07.633 luup.variable_set:: 20060.urn:upnp-org:serviceId:SwitchPower1.Target was: 0 now: 1 #hooks:0 2025-01-10 19:50:07.669 openLuup.server:: request completed (35 bytes, 1 chunks, 35 ms) tcp{client}: 0x55c3292ed678 2025-01-10 19:50:07.673 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c3292ed678 2025-01-10 19:50:07.776 openLuup.server:: request completed (821 bytes, 1 chunks, 151 ms) tcp{client}: 0x55c329d0a5b8 2025-01-10 19:50:07.784 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329d0a5b8 2025-01-10 19:50:07.795 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c3287bc8f8 2025-01-10 19:50:07.796 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912907&MinimumDelay=50&output_format=json&_r=1736538607794 HTTP/1.1 tcp{client}: 0x55c3287bc8f8 2025-01-10 19:50:08.644 luup.variable_set:: 20060.urn:upnp-org:serviceId:SwitchPower1.Status was: 0 now: 1 #hooks:0 2025-01-10 19:50:08.950 openLuup.server:: request completed (821 bytes, 1 chunks, 1154 ms) tcp{client}: 0x55c3287bc8f8 2025-01-10 19:50:08.958 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c3287bc8f8 2025-01-10 19:50:08.969 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c3297e95a8 2025-01-10 19:50:08.970 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912908&MinimumDelay=50&output_format=json&_r=1736538608969 HTTP/1.1 tcp{client}: 0x55c3297e95a8 2025-01-10 19:50:19.181 luup.variable_set:: 20770.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 1 now: 0 #hooks:0 2025-01-10 19:50:19.585 openLuup.server:: request completed (832 bytes, 1 chunks, 10615 ms) tcp{client}: 0x55c3297e95a8 2025-01-10 19:50:19.602 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c3297e95a8 2025-01-10 19:50:19.605 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328d298a8 2025-01-10 19:50:19.605 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912909&MinimumDelay=50&output_format=json&_r=1736538619604 HTTP/1.1 tcp{client}: 0x55c328d298a8 2025-01-10 19:50:34.950 openLuup.server:: request completed (593 bytes, 1 chunks, 15344 ms) tcp{client}: 0x55c328d298a8 2025-01-10 19:50:34.953 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c328d298a8 2025-01-10 19:50:34.965 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328c48a58 2025-01-10 19:50:34.966 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912909&MinimumDelay=50&output_format=json&_r=1736538634964 HTTP/1.1 tcp{client}: 0x55c328c48a58 2025-01-10 19:50:34.989 luup.variable_set:: 25019.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 0 now: 1 #hooks:0 2025-01-10 19:50:34.990 luup.variable_set:: 25019.urn:micasaverde-com:serviceId:SecuritySensor1.LastTrip was: 1736534437 now: 1736538634 #hooks:0 2025-01-10 19:50:35.094 openLuup.server:: request completed (975 bytes, 1 chunks, 127 ms) tcp{client}: 0x55c328c48a58 2025-01-10 19:50:35.101 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c328c48a58 2025-01-10 19:50:35.113 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c32985e298 2025-01-10 19:50:35.113 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912911&MinimumDelay=50&output_format=json&_r=1736538635111 HTTP/1.1 tcp{client}: 0x55c32985e298 2025-01-10 19:50:40.255 luup.variable_set:: 25021.urn:micasaverde-com:serviceId:LightSensor1.CurrentLevel was: 0 now: 30 #hooks:1 2025-01-10 19:50:40.256 scheduler.watch_callback:: 25021.urn:micasaverde-com:serviceId:LightSensor1.CurrentLevel called [20]DataWatcherCallback() function: 0x55c3288a8d20 2025-01-10 19:50:40.460 openLuup.server:: request completed (835 bytes, 1 chunks, 5346 ms) tcp{client}: 0x55c32985e298 2025-01-10 19:50:40.472 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c32985e298 2025-01-10 19:50:40.478 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329b28238 2025-01-10 19:50:40.479 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912912&MinimumDelay=50&output_format=json&_r=1736538640478 HTTP/1.1 tcp{client}: 0x55c329b28238 2025-01-10 19:50:44.471 luup.variable_set:: 25007.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 0 now: 1 #hooks:1 2025-01-10 19:50:44.472 luup.variable_set:: 25007.urn:micasaverde-com:serviceId:SecuritySensor1.LastTrip was: 1736538400 now: 1736538644 #hooks:0 2025-01-10 19:50:44.472 scheduler.watch_callback:: 25007.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped called [20]DataWatcherCallback() function: 0x55c3288a8d20 2025-01-10 19:50:44.775 openLuup.server:: request completed (975 bytes, 1 chunks, 4296 ms) tcp{client}: 0x55c329b28238 2025-01-10 19:50:44.775 openLuup.server:: request completed (975 bytes, 1 chunks, 4296 ms) tcp{client}: 0x55c329b28238 2025-01-10 19:50:44.782 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329b28238 2025-01-10 19:50:44.793 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328f1e968 2025-01-10 19:50:44.793 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912914&MinimumDelay=50&output_format=json&_r=1736538644791 HTTP/1.1 tcp{client}: 0x55c328f1e968 2025-01-10 19:51:00.122 openLuup.server:: request completed (593 bytes, 1 chunks, 15328 ms) tcp{client}: 0x55c328f1e968 2025-01-10 19:51:00.125 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c328f1e968 2025-01-10 19:51:00.136 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c32995b318 2025-01-10 19:51:00.136 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912914&MinimumDelay=50&output_format=json&_r=1736538660134 HTTP/1.1 tcp{client}: 0x55c32995b318 2025-01-10 19:51:15.481 openLuup.server:: request completed (593 bytes, 1 chunks, 15344 ms) tcp{client}: 0x55c32995b318 2025-01-10 19:51:15.484 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c32995b318 2025-01-10 19:51:15.495 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c32998b068 2025-01-10 19:51:15.497 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912914&MinimumDelay=50&output_format=json&_r=1736538675493 HTTP/1.1 tcp{client}: 0x55c32998b068 2025-01-10 19:51:30.869 openLuup.server:: request completed (593 bytes, 1 chunks, 15371 ms) tcp{client}: 0x55c32998b068 2025-01-10 19:51:30.872 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c32998b068 2025-01-10 19:51:30.884 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c32905bda8 2025-01-10 19:51:30.885 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912914&MinimumDelay=50&output_format=json&_r=1736538690882 HTTP/1.1 tcp{client}: 0x55c32905bda8 2025-01-10 19:51:32.886 luup.variable_set:: 20380.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 21 now: 22 #hooks:0 2025-01-10 19:51:33.090 openLuup.server:: request completed (841 bytes, 1 chunks, 2205 ms) tcp{client}: 0x55c32905bda8 2025-01-10 19:51:33.100 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c32905bda8 2025-01-10 19:51:33.112 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328de0d58 2025-01-10 19:51:33.112 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912915&MinimumDelay=50&output_format=json&_r=1736538693111 HTTP/1.1 tcp{client}: 0x55c328de0d58 2025-01-10 19:51:36.064 luup.variable_set:: 25007.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 1 now: 0 #hooks:1 2025-01-10 19:51:36.065 scheduler.watch_callback:: 25007.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped called [20]DataWatcherCallback() function: 0x55c3288a8d20 2025-01-10 19:51:36.369 openLuup.server:: request completed (832 bytes, 1 chunks, 3256 ms) tcp{client}: 0x55c328de0d58 2025-01-10 19:51:36.377 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c328de0d58 2025-01-10 19:51:36.387 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329054188 2025-01-10 19:51:36.388 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912916&MinimumDelay=50&output_format=json&_r=1736538696386 HTTP/1.1 tcp{client}: 0x55c329054188 2025-01-10 19:51:37.134 luup.variable_set:: 20380.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 22 now: 21 #hooks:0 2025-01-10 19:51:37.540 openLuup.server:: request completed (841 bytes, 1 chunks, 1152 ms) tcp{client}: 0x55c329054188 2025-01-10 19:51:37.553 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329054188 2025-01-10 19:51:37.566 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328d97568 2025-01-10 19:51:37.566 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912917&MinimumDelay=50&output_format=json&_r=1736538697564 HTTP/1.1 tcp{client}: 0x55c328d97568 2025-01-10 19:51:41.367 luup.variable_set:: 20380.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 21 now: 22 #hooks:0 2025-01-10 19:51:41.874 openLuup.server:: request completed (841 bytes, 1 chunks, 4307 ms) tcp{client}: 0x55c328d97568 2025-01-10 19:51:41.884 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c328d97568 2025-01-10 19:51:41.895 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329385678 2025-01-10 19:51:41.896 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912918&MinimumDelay=50&output_format=json&_r=1736538701894 HTTP/1.1 tcp{client}: 0x55c329385678 2025-01-10 19:51:57.168 openLuup.server:: request completed (593 bytes, 1 chunks, 15272 ms) tcp{client}: 0x55c329385678 2025-01-10 19:51:57.171 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329385678 2025-01-10 19:51:57.183 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329b092b8 2025-01-10 19:51:57.184 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912918&MinimumDelay=50&output_format=json&_r=1736538717182 HTTP/1.1 tcp{client}: 0x55c329b092b8 2025-01-10 19:52:00.124 luup_log:0: 14Mb, 1.6%cpu, 36.1days 2025-01-10 19:52:00.476 openLuup.server:: request completed (1841 bytes, 1 chunks, 3292 ms) tcp{client}: 0x55c329b092b8 2025-01-10 19:52:00.483 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329b092b8 2025-01-10 19:52:00.495 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c3297be088 2025-01-10 19:52:00.495 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912929&MinimumDelay=50&output_format=json&_r=1736538720494 HTTP/1.1 tcp{client}: 0x55c3297be088 2025-01-10 19:52:09.867 luup.variable_set:: 25021.urn:micasaverde-com:serviceId:LightSensor1.CurrentLevel was: 30 now: 0 #hooks:1 2025-01-10 19:52:09.868 scheduler.watch_callback:: 25021.urn:micasaverde-com:serviceId:LightSensor1.CurrentLevel called [20]DataWatcherCallback() function: 0x55c3288a8d20 2025-01-10 19:52:10.071 openLuup.server:: request completed (834 bytes, 1 chunks, 9575 ms) tcp{client}: 0x55c3297be088 2025-01-10 19:52:10.079 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c3297be088 2025-01-10 19:52:10.088 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c329c16a08 2025-01-10 19:52:10.089 openLuup.server:: GET /data_request?id=status&Timeout=15&DataVersion=416912930&MinimumDelay=50&output_format=json&_r=1736538730087 HTTP/1.1 tcp{client}: 0x55c329c16a08 2025-01-10 19:52:16.194 luup.variable_set:: 20770.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 0 now: 1 #hooks:0 2025-01-10 19:52:16.195 luup.variable_set:: 20770.urn:micasaverde-com:serviceId:SecuritySensor1.LastTrip was: 1736538607 now: 1736538736 #hooks:0 2025-01-10 19:52:16.498 openLuup.server:: request completed (976 bytes, 1 chunks, 6409 ms) tcp{client}: 0x55c329c16a08 2025-01-10 19:52:16.515 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x55c329c16a08 2025-01-10 19:52:16.516 openLuup.io.server:: HTTP:3480 connection from 192.168.70.249 tcp{client}: 0x55c328dbad18Nothing I can see indicating that Openluup is reloading?
.249 IP address is the internal IP of the NUC that hosts both Openluup and MSR.
Any thoughts as to how I can troubleshoot this? It's not a big deal, but would like to get to the bottom of it.
I should add that all the devices listed in entries like this:
[latest-24366]2025-01-10T19:55:09.744Z <VeraController:INFO> VeraController#vera class scene_controller meta [Object]{ "source": "urn:micasaverde-com:serviceId:SceneController1/sl_SceneActivated", "expr": "int(value)" } orig final NaN [latest-24366]2025-01-10T19:55:09.744Z <VeraController:CRIT> *Entity#vera>device_20631Are the tamper switches on Fibaro FGMS001 multifunction detectors, of which I have 4, and they correspond exactly to the devices listed.
TIA
C
And then MSR...
My first issue: I'm logged into the msr CT as reactor (I used the suggested username just to keep things simple as this is new space for me and I was high off my success of migrating HA over).
When I run
docker pull toggledbits/reactor:latest-amd64... it assigns the \reactor\ subdirectory where installed root ownership. I am absolutely logged in with the correct non-root user.
1c58aead-85ca-4b2c-8f48-c3d1f57d7fe3-image.png
Second issue: I copied over the following folders:
67e7e4a5-cee8-4de1-90c7-1df35f1070b9-image.png
When MSR loads, all of my Global Expressions are missing.
Third issue:
All controllers connect wonderfully (Hubitat, etc)... except HA.
After changing ownership of the logs to reactor again I can see this when MSR calls HA:
Yes, I created a fresh new long-lived access token for the MSR containerized install and updated the reactor.yaml config file correctly.
Honestly, all-in-all, for my total lack of expertise here I'm very pleased that I only have these three issues. But they are def blockers atm.
My RPi bare metal install of MSR hooked right up to the new HA and is humming along just fine (I used hostnames were possible and shuffled some IPs in other places so I wouldn't run into things later that were mapped incorrectly that I'd forgotten about.)
Proxmox 8.3.2 MSR lives in an Ubuntu 24.04 Proxmox container MSR is latest docker versionWhat else can I provide to those smarter than me here?
Hi
I was looking at an old rule and I wanted to edit it, to add another Constraint, however I cannot seem to do it.
On this screen shot you can see an existing entry in the Constraints and on its pull down menu the "Changes" option is available.
09735de3-8e92-4e12-bfa2-5191f48924a7-image.png
However on the new line I just added I have no changes option in its pull down menu.
d85c4067-880e-4281-a12b-dac4d316a4da-image.png
Here is the original now locked post about this topic.
https://smarthome.community/topic/395/contact-sensor-opened-1-minute-ago-how?_=1736354690742
If you look on the old screen shots on that post, I was using the "changes" operator. Like this:
a1262e01-d3fd-4723-872f-872f1f6d9899-image.png
However today when I edited this rule the operators are showing as == and not as changes on all the entries in the Constraints area.
Also the old entries now say -- and the value is blank. But on the new line I just added it says that is not valid, so not sure how the old lines are like that.
a458d52d-214d-4862-a2b7-d31009f89cde-image.png
So I am a bit confused what happened.
Thanks
Build 21228 has been released. Docker images available from DockerHub as usual, and bare-metal packages here.
Home Assistant up to version 2021.8.6 supported; the online version of the manual will now state the current supported versions; Fix an error in OWMWeatherController that could cause it to stop updating; Unify the approach to entity filtering on all hub interface classes (controllers); this works for device entities only; it may be extended to other entities later; Improve error detail in messages for EzloController during auth phase; Add isRuleSet() and isRuleEnabled() functions to expressions extensions; Implement set action for lock and passage capabilities (makes them more easily scriptable in some cases); Fix a place in the UI where 24-hour time was not being displayed.@toggledbits I understand that you do not perform testing on Mac computers but thought I'd share the following with you in case something can be done.
I started seeing these errors with version 24302. I thought that upgrading to 24343 would have fixed the issue but unfortunately not. I either have to close the browser or clear the cache for the errors to stop popping-up but they slowly come back.
I see these errors on the following browsers:
Safari 16.6.1 on macOS Big Sur Safari 18.1.1 on MacOS Sonoma DuckDuckGo 1.118.0 on macOS Big Sur and Sonoma Firefox 133.0.3 on macOS Big Sur Chrome 131.0.6778 on macOS Big SurHere are the errors
Safari while creating/updating an expression
@http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:543:91 makeExprMenu@http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:537:28 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:92:64 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:89:68 each@http://192.168.0.13:8111/node_modules/jquery/dist/jquery.min.js:2:3133 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:89:35 @http://192.168.0.13:8111/client/MessageBus.js:98:44 forEach@[native code] @http://192.168.0.13:8111/client/MessageBus.js:95:54 @http://192.168.0.13:8111/client/MessageBus.js:106:44 @http://192.168.0.13:8111/client/Observable.js:78:28 signalModified@http://192.168.0.13:8111/reactor/en-ca/lib/js/ee.js:146:21 signalModified@http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:40:29 reindexExpressions@http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:71:32 @http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:608:40 dispatch@http://192.168.0.13:8111/node_modules/jquery/dist/jquery.min.js:2:40040DuckDuckGo while clicking on status
http://192.168.0.13:8111/reactor/en-ca/lib/js/reactor-ui-status.js:789:44 asyncFunctionResume@[native code] saveGridLayout@[native code] dispatchEvent@[native code] _triggerEvent@http://192.168.0.13:8111/node_modules/gridstack/dist/gridstack.js:1401:30 _triggerAddEvent@http://192.168.0.13:8111/node_modules/gridstack/dist/gridstack.js:1383:31 makeWidget@http://192.168.0.13:8111/node_modules/gridstack/dist/gridstack.js:968:30 addWidget@http://192.168.0.13:8111/node_modules/gridstack/dist/gridstack.js:388:24 placeWidgetAdder@http://192.168.0.13:8111/reactor/en-ca/lib/js/reactor-ui-status.js:183:44Firefox while updating a rule
@http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:543:91 makeExprMenu@http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:537:28 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:92:64 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:89:68 each@http://192.168.0.13:8111/node_modules/jquery/dist/jquery.min.js:2:3133 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reaction-editor.js:89:35 @http://192.168.0.13:8111/client/MessageBus.js:98:44 forEach@[native code] @http://192.168.0.13:8111/client/MessageBus.js:95:54 @http://192.168.0.13:8111/client/MessageBus.js:106:44 @http://192.168.0.13:8111/client/Observable.js:78:28 notifySaved@http://192.168.0.13:8111/reactor/en-ca/lib/js/ee.js:82:21 notifySaved@http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:47:26 @http://192.168.0.13:8111/reactor/en-ca/lib/js/reactor-ui-rules.js:1460:39 forEach@[native code] @http://192.168.0.13:8111/reactor/en-ca/lib/js/reactor-ui-rules.js:1459:58Chrome while creating/updating an expression
TypeError: Cannot read properties of undefined (reading 'getEditor') at RuleEditor.makeExprMenu (http://192.168.0.13:8111/reactor/en-ca/lib/js/rule-editor.js:1788:86) at Object.handler (http://192.168.0.13:8111/reactor/en-ca/lib/js/rule-editor.js:2174:54) at http://192.168.0.13:8111/client/MessageBus.js:98:44 at Array.forEach (<anonymous>) at MessageBus._sendToBus (http://192.168.0.13:8111/client/MessageBus.js:95:54) at MessageBus.send (http://192.168.0.13:8111/client/MessageBus.js:106:44) at ExpressionEditor.publish (http://192.168.0.13:8111/client/Observable.js:78:28) at ExpressionEditor.signalModified (http://192.168.0.13:8111/reactor/en-ca/lib/js/ee.js:146:14) at ExpressionEditor.signalModified (http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:40:15) at ExpressionEditor.reindexExpressions (http://192.168.0.13:8111/reactor/en-ca/lib/js/expression-editor.js:71:18) ``Not sure that it is the same issue but just got this on built 24302 when running a reaction for testing purpose. Despite the error message, the reaction ran properly.
Error: Command timeout (195 start_reaction)
at _ClientAPI._commandTimeout (http://192.168.2.163:8111/client/ClientAPI.js:552:136)
1a3422eb-d760-4609-a740-a40d04a6bab2-Screenshot 2024-12-29 231851.png
Thanks to @toggledbits for adding a custom CSS. I've started doing a darker Reactor style.
Here's the file: https://gist.github.com/dbochicchio/825098ac13b7f8cac22012eae37ff7ce
A couple of things are still too bright and I'll eventually catch-up. Just place it under your /config directory, naming the file as customstyles.css. Hard refresh your browser.
Hi
Having to rebuild my Linux Debian box as the SSD failed. And I have forgotten exactly what I did the first time to get it all setup.
I have Debian 12 up and running on the new SSD, I only have console no Desktop GUI.
I am trying to do the bare metal install for MSR. However I am not sure if I am meant to install nodejs whlist logged in as the root user or as the none root user with my name ?
I used putty and connected via SSH and logged in as root and I installed nodejs but I think this was wrong as when logged in as my user name and I do a node -v command it says node is not installed or doesn't show any version number anyway.
But when logged in as root and I do a node -v command it does show me its installed and displays the version number. maybe its a path issue for my username and he can't see node is installed?
So now I am thinking I should of installed node whilst logged in as my user name and not as the root user.
This is how I installed nodejs as whilst logged in as root
ac7bf6c3-23ad-46fc-8ada-44af6704e63e-image.png
Thanks in advance.
As the title says, here's my OpenAI Controller for Reactor:
OpenAI Controller per Reactor. Contribute to dbochicchio/reactor-openai development by creating an account on GitHub.
It supports both OpenAI and Azure OpenAI endpoints. You'll need keys/endpoints, according to each service.
The controller supports multiple models, and each one could be mapped as an entity.
It's quite easy to use, and responses can be stored in variables, for easy access. Or sent to another action (Text To Speech, another endpoint, etc).
9013ae50-fd68-42a2-87c3-97479132e465-image.png
80a88eec-7c89-464a-8196-690b4b72d044-image.png
Have fun with LLM into your scenes!
In Home Assistant I have an integration that if I add entities to it, I will get the following error in MSR as certain entity values I'm using in expressions are null for a moment. This is more or less cosmetic issue and happens very rarely as I rarely modify that integration on the hass side.
Screenshot 2024-11-28 at 22.20.41.png
And the expression is
Screenshot 2024-11-28 at 22.38.19.png
Could I "wrap" hass-entity shown above somewhat differently to prevent this error from happening? Using build 24302.
Hello
I am trying to set up Multi System Reactor to automate routines across multiple smart home devices & platforms (e.g., Home Assistant, SmartThings, and Hubitat). While I have successfully linked the systems; I am facing issues with:
-Delays in triggering actions on secondary devices.
-Inconsistent execution of complex logic conditions.
-Synchronization of states between devices when one system updates.
Is there a recommended way to optimize performance & confirm seamless state sharing across systems?
I have checked https://smarthome.community/category/22/multi-system-reactor-msbi guide for reference but still need advice.
Any tips on debugging or log analysis to pinpoint where the issue arises would also be appreciated.
Thank you !
I've managed to use MSR UI on iOS devices to some degree*, so that although UI elements (e.g. rule sets) are not visible in portrait mode, you've seen them in landscape. Now with recents builds (24302) this does not work anymore, elements (rule sets, entities) are not anymore visible in landscape mode.
Does anyone have similar experiences? Using iOS 18 and Safari/Chrome browser.
( *Drag & drop of rule conditions have never worked on a mobile)
@toggledbits Since I have upgraded ZWaveJSController to 24293 from 24257 I am seeing entries related to registering action set_volume, but action is not defined by the capability 143 every time I restart Reactor.
The Siren seems to be doing what it is supposed to do. The volume levels are fine. Should I worry about it?
Reactor version 24302
ZWaveJSController version 24293
Z-Wave JS UI version 9.27.4
zwave-js version 14.3.4
I have the following ACL defined:
groups: admin: users: - admin applications: true api_acls: # This ACL allows users in the "admin" group to access the API - url: "/api" group: admin allow: true log: true # This ACL allows anyone/thing to access the /api/v1/alive API endpoint - url: "/api/v1/alive" allow: trueAnd I have authenticated to MSR as "admin" user. However, I'm getting "access denied" when trying to access http://*******:8111/api/v1/log
So what I'm missing, is my ACL incorrectly defined?
Using build 24302 on Docker.
Hi
I have just connected a bunch of EzloPi controllers to MSR to import some ESP based devices etc.
They all seemed to have worked and imported in to MSR apart from I have one missing device. It is a Digital Gas Sensor device.
This is how that device looks in the Ezlo API.
Devices Info:
_id: "10696001" deviceTypeId: "ezlopi" parentDeviceId: "10696000" category: "level_sensor" subcategory: "" gatewayId: "457a5069" batteryPowered: false name: "Gas Sensor Digital" type: "sensor" reachable: true persistent: true serviceNotification: false armed: false roomId: "" security: "no" ready: true status: "idle" parentRoom: true protectConfig: "default"Items Info:
_id: "20696001" deviceId: "10696001" hasGetter: true hasSetter: false name: "smoke_density" show: true valueType: "substance_amount" scale: "parts_per_million" value: 2.7472610473632812 valueFormatted: "2.75" status: "idle"There is also an Analog Gas sensor that one did import in to MSR OK.
68d63dab-b871-4f44-912b-cf6e0b9eb4c6-image.png
Devices Info:
_id: "10696000" deviceTypeId: "ezlopi" parentDeviceId: "10696000" category: "security_sensor" subcategory: "gas" gatewayId: "457a5069" batteryPowered: false name: "Gas Sensor Analog" type: "sensor" reachable: true persistent: true serviceNotification: false armed: false roomId: "" security: "no" ready: true status: "idle" parentRoom: true protectConfig: "default"Items Info:
_id: "20696000" deviceId: "10696000" hasGetter: true hasSetter: false name: "gas_alarm" show: true valueType: "token" enum: 0: "no_gas" 1: "combustible_gas_detected" 2: "toxic_gas_detected" 3: "unknown" valueFormatted: "no_gas" value: "no_gas" status: "idle"And this is how this MQ2 Gas Sensor looks like on their dashboard:
Digital
cb77dfa3-4af5-4d06-9635-89207a716a89-image.png
Analog
4fb4da1b-e946-4b89-876c-bcd9f5699b6c-image.png
They have an EzloPi website here you can create your own sensor projects using ESP boards, which is very interesting stuff!
And I just wrote on the Ezlo forum here, how to connect an EzloPi controller to MSR.
THANKS.
Constraints (no data) rule actions have never run
-
Hi
I have a problem rule it seems. Its set to turn off my Festoon lights at 23:55pm and in the constraints checks if those lights are already turned on ?
And the reaction is to turn them off.
Since I setup the rule my lights have never turned off.
In the summary card I can see (no data)
On this screen shot it says the power switch state is TRUE.
The switch is actually OFF at the moment, I have hard refreshed the browser but it still says True.I can go to Scope and add a trace on this device and it does track if its turned on or off OK.
The device is one side of a Fibaro Dual Relay module.
Any clues?
Thanks
-
Changes to devices or other dependencies in the Constraints do not cause evaluation of the rule's conditions (triggers or constraints). Only Triggers do that. You would have to wait until after 23:55, which is the only trigger, for the Constraints to be evaluated.
-
@toggledbits OK think that makes sense.
Not sure why my rules action is not running then.
This is the trigger
I have pressed the Play button in the Set Reaction area and it does actually turn off the light OK.
I've had this rule setup for maybe 3 days and my Festoon lights have never turned off and have been left on all night.
-
Have you looked in the log at around the time the rule would be expected to trigger? There may be something logged. Remember to adjust for time zone if your host's configured time zone is different from your browser/desktop (i.e. it's not unusual to have a Pi, for example, default to UTC, so all times logged will be UTC and thus maybe different from your local time).
-
I have other Schedules in MSR for certain times in the morning to open window coverings they are now all working fine and open on the time I set in their triggers.
If I use the command "date" on the Pi in putty it does say the correct time as of now:
Fri 26 Feb 13:15:22 GMT 2021
I'll have a look in the Reactor logs
Thanks
-
Looking in reactor.log I searched this rules ID code kljc5802:
2021-02-25T19:00:05.003Z <Engine:INFO> Engine#1 master timer tick, local time "2/25/2021, 19:00:05" (TZ offset 0 mins from UTC) false false2021-02-25T19:34:00.006Z <Rule:5:Rule.js:635> Rule#rule-kljc5802 launching eval from timer-trigger notification by Timer#cond57lqecd false false2021-02-25T19:34:00.009Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex false false2021-02-25T19:34:00.012Z <Rule:5:Rule.js:635> Rule#rule-kljbrk9g launching eval from timer-trigger notification by Timer#cond57lqecd false false2021-02-25T19:34:00.014Z <Rule:5:Rule.js:697> Rule#rule-kljbrk9g (Schedule - Lawn Lights OFF) evaluate() acquiring mutex false false2021-02-25T19:34:00.017Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating false false2021-02-25T19:34:00.021Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 0/min limit 60/min false false2021-02-25T19:34:00.023Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions false false2021-02-25T19:34:00.025Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/25/2021, 23:55:00 edt=2/25/2021, 19:34:00 now=2/25/2021, 19:34:00 false false2021-02-25T19:34:00.028Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/25/2021, 23:55:00, 15659 secs from now false false2021-02-25T19:34:00.030Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false) false false
2021-02-25T20:13:27.338Z <Engine:5:Engine.js:550> Engine#1 (re-)starting rule Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) 2021-02-25T20:13:27.340Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex
2021-02-25T20:13:27.513Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-25T20:13:27.515Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-25T20:13:27.517Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started
2021-02-25T20:13:27.761Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-25T20:13:27.762Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 0/min limit 60/min 2021-02-25T20:13:27.765Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-25T20:13:27.767Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/25/2021, 23:55:00 edt=2/25/2021, 20:13:00 now=2/25/2021, 20:13:27 2021-02-25T20:13:27.771Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/25/2021, 23:55:00, 13292 secs from now 2021-02-25T20:13:27.774Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false)
2021-02-26T00:00:00.129Z <Rule:5:Rule.js:635> Rule#rule-kljc5802 launching eval from timer-trigger notification by Timer#cond57lqecd 2021-02-26T00:00:00.131Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T00:00:00.136Z <Rule:5:Rule.js:635> Rule#rule-kljbrk9g launching eval from timer-trigger notification by Timer#cond57lqecd 2021-02-26T00:00:00.139Z <Rule:5:Rule.js:697> Rule#rule-kljbrk9g (Schedule - Lawn Lights OFF) evaluate() acquiring mutex 2021-02-26T00:00:00.141Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T00:00:00.145Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 0/min limit 60/min 2021-02-26T00:00:00.147Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T00:00:00.150Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 00:00:00 now=2/26/2021, 00:00:00 2021-02-26T00:00:00.152Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 86099 secs from now 2021-02-26T00:00:00.154Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false)
2021-02-26T11:02:14.128Z <Rule:NOTICE> Rule#rule-kljc5802 configuration changed; reloading 2021-02-26T11:02:14.147Z <Rule:5:Rule.js:600> Rule#rule-kljc5802 reloading with new data 2021-02-26T11:02:14.150Z <Rule:NOTICE> Rule#rule-kljc5802 stopping rule 2021-02-26T11:02:14.152Z <Rule:5:Rule.js:581> Rule#rule-kljc5802 acquiring mutex 2021-02-26T11:02:14.157Z <Rule:5:Rule.js:584> Rule#rule-kljc5802 mutex acquired; unsubscribing from condition dependencies 2021-02-26T11:02:14.169Z <Rule:5:Rule.js:586> Rule#rule-kljc5802 saving states 2021-02-26T11:02:14.176Z <Rule:5:Rule.js:590> Rule#rule-kljc5802 stopped 2021-02-26T11:02:14.178Z <Rule:NOTICE> Rule Rule#rule-kljc5802 stopped 2021-02-26T11:02:14.180Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex 2021-02-26T11:02:14.183Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-26T11:02:14.185Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-26T11:02:14.378Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started 2021-02-26T11:02:14.381Z <Rule:5:Rule.js:567> Rule#rule-kljc5802 start() dependencies resolved, performing initial evaluation 2021-02-26T11:02:14.509Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T11:02:14.511Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:02:14.518Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 0/min limit 60/min 2021-02-26T11:02:14.520Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:02:14.523Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:02:00 now=2/26/2021, 11:02:14 2021-02-26T11:02:14.527Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46365 secs from now 2021-02-26T11:02:14.529Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false) 2021-02-26T11:02:52.786Z <Rule:NOTICE> Rule#rule-kljc5802 configuration changed; reloading 2021-02-26T11:02:52.792Z <Rule:5:Rule.js:600> Rule#rule-kljc5802 reloading with new data 2021-02-26T11:02:52.794Z <Rule:NOTICE> Rule#rule-kljc5802 stopping rule 2021-02-26T11:02:52.797Z <Rule:5:Rule.js:581> Rule#rule-kljc5802 acquiring mutex 2021-02-26T11:02:52.803Z <Rule:5:Rule.js:584> Rule#rule-kljc5802 mutex acquired; unsubscribing from condition dependencies 2021-02-26T11:02:52.816Z <Rule:5:Rule.js:586> Rule#rule-kljc5802 saving states 2021-02-26T11:02:52.823Z <Rule:5:Rule.js:590> Rule#rule-kljc5802 stopped 2021-02-26T11:02:52.824Z <Rule:NOTICE> Rule Rule#rule-kljc5802 stopped 2021-02-26T11:02:52.828Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex 2021-02-26T11:02:52.831Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-26T11:02:52.833Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-26T11:02:52.835Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started 2021-02-26T11:02:52.838Z <Rule:5:Rule.js:567> Rule#rule-kljc5802 start() dependencies resolved, performing initial evaluation 2021-02-26T11:02:52.840Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T11:02:52.844Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:02:52.846Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 1/min limit 60/min 2021-02-26T11:02:52.848Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:02:52.850Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:02:00 now=2/26/2021, 11:02:52 2021-02-26T11:02:52.852Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46327 secs from now 2021-02-26T11:02:52.854Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false) 2021-02-26T11:03:25.898Z <Rule:NOTICE> Rule#rule-kljc5802 configuration changed; reloading 2021-02-26T11:03:25.904Z <Rule:5:Rule.js:600> Rule#rule-kljc5802 reloading with new data 2021-02-26T11:03:25.905Z <Rule:NOTICE> Rule#rule-kljc5802 stopping rule 2021-02-26T11:03:25.908Z <Rule:5:Rule.js:581> Rule#rule-kljc5802 acquiring mutex 2021-02-26T11:03:25.913Z <Rule:5:Rule.js:584> Rule#rule-kljc5802 mutex acquired; unsubscribing from condition dependencies 2021-02-26T11:03:25.922Z <Rule:5:Rule.js:586> Rule#rule-kljc5802 saving states 2021-02-26T11:03:25.929Z <Rule:5:Rule.js:590> Rule#rule-kljc5802 stopped 2021-02-26T11:03:25.930Z <Rule:NOTICE> Rule Rule#rule-kljc5802 stopped 2021-02-26T11:03:25.933Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex 2021-02-26T11:03:25.935Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-26T11:03:25.937Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-26T11:03:25.938Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started 2021-02-26T11:03:25.940Z <Rule:5:Rule.js:567> Rule#rule-kljc5802 start() dependencies resolved, performing initial evaluation 2021-02-26T11:03:25.942Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T11:03:25.944Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:03:25.945Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 1/min limit 60/min 2021-02-26T11:03:25.948Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:03:25.950Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:03:00 now=2/26/2021, 11:03:25 2021-02-26T11:03:25.952Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46294 secs from now 2021-02-26T11:03:25.954Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false) 2021-02-26T11:03:52.673Z <Rule:NOTICE> Rule#rule-kljc5802 configuration changed; reloading 2021-02-26T11:03:52.677Z <Rule:5:Rule.js:600> Rule#rule-kljc5802 reloading with new data 2021-02-26T11:03:52.693Z <Rule:NOTICE> Rule#rule-kljc5802 stopping rule 2021-02-26T11:03:52.695Z <Rule:5:Rule.js:581> Rule#rule-kljc5802 acquiring mutex 2021-02-26T11:03:52.701Z <Rule:5:Rule.js:584> Rule#rule-kljc5802 mutex acquired; unsubscribing from condition dependencies 2021-02-26T11:03:52.721Z <Rule:5:Rule.js:586> Rule#rule-kljc5802 saving states 2021-02-26T11:03:52.729Z <Rule:5:Rule.js:590> Rule#rule-kljc5802 stopped 2021-02-26T11:03:52.731Z <Rule:NOTICE> Rule Rule#rule-kljc5802 stopped 2021-02-26T11:03:52.733Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex 2021-02-26T11:03:52.736Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-26T11:03:52.738Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-26T11:03:52.740Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started 2021-02-26T11:03:52.742Z <Rule:5:Rule.js:567> Rule#rule-kljc5802 start() dependencies resolved, performing initial evaluation 2021-02-26T11:03:52.744Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T11:03:52.747Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:03:52.749Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 1/min limit 60/min 2021-02-26T11:03:52.754Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:03:52.757Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:03:00 now=2/26/2021, 11:03:52 2021-02-26T11:03:52.759Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46267 secs from now 2021-02-26T11:03:52.761Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false) 2021-02-26T11:04:13.259Z <Rule:NOTICE> Rule#rule-kljc5802 configuration changed; reloading 2021-02-26T11:04:13.264Z <Rule:5:Rule.js:600> Rule#rule-kljc5802 reloading with new data 2021-02-26T11:04:13.265Z <Rule:NOTICE> Rule#rule-kljc5802 stopping rule 2021-02-26T11:04:13.266Z <Rule:5:Rule.js:581> Rule#rule-kljc5802 acquiring mutex 2021-02-26T11:04:13.271Z <Rule:5:Rule.js:584> Rule#rule-kljc5802 mutex acquired; unsubscribing from condition dependencies 2021-02-26T11:04:13.274Z <Rule:5:Rule.js:586> Rule#rule-kljc5802 saving states 2021-02-26T11:04:13.281Z <Rule:5:Rule.js:590> Rule#rule-kljc5802 stopped 2021-02-26T11:04:13.282Z <Rule:NOTICE> Rule Rule#rule-kljc5802 stopped 2021-02-26T11:04:13.284Z <Rule:5:Rule.js:555> Rule#rule-kljc5802 start(), awaiting mutex 2021-02-26T11:04:13.286Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 restored states: trig=false, rule=false 2021-02-26T11:04:13.287Z <Rule:5:Rule.js:563> Rule#rule-kljc5802 subscribing to dependencies 2021-02-26T11:04:13.289Z <Rule:INFO> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) started 2021-02-26T11:04:13.290Z <Rule:5:Rule.js:567> Rule#rule-kljc5802 start() dependencies resolved, performing initial evaluation 2021-02-26T11:04:13.292Z <Rule:5:Rule.js:697> Rule#rule-kljc5802 (Schedule - Festoon Lights OFF) evaluate() acquiring mutex 2021-02-26T11:04:13.293Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:04:13.295Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 2/min limit 60/min 2021-02-26T11:04:13.297Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:04:13.299Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:04:00 now=2/26/2021, 11:04:13 2021-02-26T11:04:13.300Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46246 secs from now 2021-02-26T11:04:13.302Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false)
2021-02-26T11:04:15.369Z <Rule:5:Rule.js:700> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:04:15.371Z <Rule:5:Rule.js:704> Rule#rule-kljc5802 update rate is 3/min limit 60/min 2021-02-26T11:04:15.373Z <Rule:5:Rule.js:654> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:04:15.375Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:04:00 now=2/26/2021, 11:04:15 2021-02-26T11:04:15.377Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 46244 secs from now 2021-02-26T11:04:15.379Z <Rule:5:Rule.js:714> Rule#rule-kljc5802.evaluate() trigger state false (was false)
2021-02-26T11:18:29.114Z <Rule:5:Rule.js:680> Rule#rule-kljc5802.evaluate() mutex acquired, evaluating 2021-02-26T11:18:29.117Z <Rule:5:Rule.js:684> Rule#rule-kljc5802 update rate is 1/min limit 60/min 2021-02-26T11:18:29.119Z <Rule:5:Rule.js:634> Rule#rule-kljc5802 evaluateExpressions() with 0 expressions 2021-02-26T11:18:29.124Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd trange after sdt=2/26/2021, 23:55:00 edt=2/26/2021, 11:18:00 now=2/26/2021, 11:18:29 2021-02-26T11:18:29.127Z <Rule:null> Rule#rule-kljc5802 cond cond57lqecd timer now scheduled for 2/26/2021, 23:55:00, 45390 secs from now 2021-02-26T11:18:29.130Z <Rule:5:Rule.js:694> Rule#rule-kljc5802.evaluate() trigger state false (was false)
-
Grep'ing out specific lines of the log isn't really a productive thing to do, as there are other lines surrounding in context that may not contain the search string but are needed to show the full activity. It would not, for example, show an exception thrown. Just gzip the log and email it to me at the address given in the "SUPPORT" section of the about page; I'll take a look later this morning.
-
Not related but I am seeing these errors in the log:
Expression compilation error for deviceclass heatonly_thermostat hvac_control.mode: Error: Parse error on line 1: ...tochangeover:'auto'}[lower(value)] ?? va
Device 190 is the Secure Boiler Relay Switch related to the Secure Thermostat device.
2021-02-25T18:03:47.240Z <VeraController:ERR> Exception/error while updating Entity#vera>device_190 2021-02-25T18:03:47.242Z <VeraController:CRIT> ReferenceError: expr is not defined ReferenceError: expr is not defined
-
Are you in 21056?
-
@toggledbits Yes
Two more rules here both are set to run at 9am
One worked this morning OK and did its action, the other rule the bottom one in the screen shot, that didn't run its action.
This is the rule that didn't run, have I done something wrong ?
I've just updated to the latest version of MSR (reactor-0.1.21057-f143fd3-generic.tar) and now that rule that didn't run this morning looks like this:
-
I have created a lot of other rules, some of them also with Constraints and none of those rules say null or no data in the Constraints in the rules summary card.
I've gone through them all now again looking and it seems I only have two rules which I have highlighted above that don't run and they say or have said null or no data in Constraints.
All my other garden lights have turned on and off OK, but they are using a sunset offset not a specific set time.
But that rule to turn off the Festoon lights at 23:55pm has never run since I created it.
I also have rules for the window coverings setup for specific times in the morning and generally they have all run at their set times OK.
I will see what happens tomorrow at 9am with this "Lounge Blind Slats" one ?
Thanks
-
The 11:55pm rule that never worked since I created it, I deleted it. I then created it again exactly the same as I did before. Looking at its Summary card the Constraints stated no data / null etc. I then edited the rule and changed its time to 9:00am and saved. I then edited the rule again and set it back to 11:55pm and saved.
The rule now runs and turns off my lights at 11:55pm or it did last night at least anyway. So assume it will work every night now.
I created another new rule not related to run every night at 10:30pm and that one worked first time no problems, so not sure why I have had issues with a few rules.
The 9am rule to open the Lounge Blind Slats didn't run this morning again, so I've deleted it and recreated it, see what happens with that tomorrow morning ?
-
Remember two things:
- Log files are pretty good at telling what's going on, and really good at help me determine what's going on;
- Open PRs are my highest priority.
-
OK. Not seeing an email yet... you used the address in the "Support" section of the About page?