Navigation

    Discussion Forum to share and further the development of home control and automation, independent of platforms.

    SmartHome Community

    • Register
    • Login
    • Search
    • Categories
    • Recent
    • Tags
    • Popular
    • Unsolved
    (Last Updated: October 8, 2021)
    • Adding remotes, scene controllers as entities to MSR

      A

      EDIT: 2022.07.01

      So I will try to remake this thread to some kind of guide for future use, or in worst case a documentation of my failure. At least that could also be useful for letting someone know what didn't work...
      I have zero knowledge of programming, so every time I need to edit a config file in HomeAssistant or similar it requires a good portion of googletime and read, re-reading instructions.
      Also is english not my native language, so bear with me.

      Two goals!
      1: Get MSR to take notice (and then actions of course) of pressed buttons on remotes.
      2: Document what I do in hope I can help someone else in the future.

      I will use a Fibaro Keyfob as described below, but what I understand from Togglebits answers most type of remotes should work in similar ways.

      Original thread:
      Fibaro Keyfob support in MSR? (thru Hassio & Z-wave JS)
      Hi

      I just bought a Fibaro Keyfob FGKF-601 and plan to give this to my son so he can control some stuff in his own room. Primary some lightning and Sonos, maybe blinds in the future.

      As the noob I am it will, of course, not work as I expected.👶🏻

      The remote handle 1x, 2x, 3x clicks per button (six of them) and "release button"
      I thought that it would appear like some "scene controller" in HA and that I could make Rules in MSR depending on what scene-entety that was triggered.
      So is not the case, and if that is because of HA, Z-wave JS or MSR I have no idea.
      I found a HA Blueprint that works in HA, but of course I would prefer to keep all automation in MSR.
      I guess a workaround could be using HA virtual switches "Helpers" that I suppose will come up as an on/off trigger in MSR, but before going this way I would like to check with the wisdom of your guys if there is a better way of doing this.

      I am using:
      MSR 22168 on windows.
      Home Assistant Core 2022.6.7
      Home Assistant Supervisor 2022.05.3
      Home Assistant OS 7.6
      Z-Wave JS version: 0.1.64

      Multi-System Reactor
    • Constraints under triggers or under constraints, what is the difference?

      A

      Need to ask, have thougth about this since the move from Rector to MSR I think.

      What is the difference between putting constraints under trigger groups, like this
      23b4a249-3292-41cd-9927-7f49c9bf1d07-image.png

      Compared to this similar rule, but the time limits is under contraints instead?
      ee596c9f-f52b-4a39-9605-f5932f3d9ed5-image.png

      I think the Constraints parts in manual is still to be done because I can only find in the chapter menu, but it is not mentioned anywhere else.

      Multi-System Reactor
    • The Home Remote with MSR

      MikeReadington

      Did anyone do/start any work on a full integration with The Home Remote application yet?

      Multi-System Reactor
    • Condition must occur after -restriction not working

      tunnus

      Running MSR 22123 in Docker container and trying to use "condition must occur after" option. Will update to the latest build and log a PR if needed, but wanted to poll first if anyone is using this option successfully?

      I have the following rules:

      Screenshot 2022-06-28 at 15.18.50.png

      Notification activity connected to "Alarm disabled" rule did not trigger. I also did another test with quite simple rules and that didn't work either (FWIIW - when observing that test in "real-time", I didn't see any timer running on the second rule while the first rule was true).

      As said, before going further with debug/logs, nice to know if someone is using this option/restriction (successfully).

      Multi-System Reactor
    • Reactor (Multi-System/Multi-Hub) Announcements

      toggledbits

      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.
      Multi-System Reactor
    • [Solved] Changes in 22178 for HASS sensor no longer provide a value in topic "value", MQTTController echo capability

      Crille

      Before updating to 22178 there was a primary value echoed in MQTTControllers echo capability, can I tell the controller which value to put as primary from HASS sensors after this change as it now is null? or is it a bug?

      I have not changed the

      primary_attributes: true

      mqtt_value.PNG

      Reactor latest-22178 bare metal
      Hass 2022.6.7

      Edit: Solved in build 22179

      Multi-System Reactor
    • Using InfluxDB with MSR

      wmarcolin

      Hi!

      I have a system that I consider pretty stable, running in a VM Ubuntu 20.04, it has some communication failures, but I think more by HE than by the OS/MSR.

      I'm thinking of taking the next step to get more advantages from the system, and I'm thinking of using InfluxDB maybe for queries or to extend rules.

      The question is, I would like practical examples of what really helps to install InfluxDB? What would you be doing that really makes a difference with this installation? Can you post examples of features or information?

      Thanks

      Multi-System Reactor
    • git hub docker container not available?

      Black Cat

      @toggledbits - what now?

      Re: Cheapest platform on which to run MSR

      21aaf68e-c031-414d-847d-d8bec01d57e7-Clipboard01.jpg

      Multi-System Reactor
    • Synology NAS docker image replacement

      MikeReadington

      Hi Everyone,

      MSR had a docker image file naming convention change, and I am not exactly sure how to swap the image out. I'm sure it's not rocket science, I've just never done this before.

      I am using a Synology NAS, and under the environment tab there is a "REACTOR_IMAGE" variable. Can I just change the image name to the new image naming convention and clear the container, or should I launch a new container and populate the volume location from the previous reactor?

      Thanks in advance

      Multi-System Reactor
    • Cheapest platform on which to run MSR

      T

      Please can anyone give me advice on a cheap way to run MSR (both initial cost and ongoing electricity cost). I currently run it on my QNAP network drive (which works very well incidentally). However, this draws a constant 35Watts (£90/yr @ 30p/kWh) and given the recent rise in fuel costs I am evaluating the best way forwards. Note, I only really need to turn my QNAP on for an hour a week to back-up my computer data. I understand that MSR can run on a Raspberry PI, but I am not competent with Linux! Thanks.

      Multi-System Reactor
    • Copying configuraiton and rules from QNAP install to Raspberry PI 4 install

      T

      I have made good progress setting up a new Raspberry PI 4 with the latest OS (64bit) and latest Reactor images in Docker. However I am not able to copy my configuraiton files (.yml) and reactor reactions over. I am not yet that confident with linux commands, so I have tired to drag and drop the files from a USB drive to the working folders in my new Raspberry PI. I am getting a popup in the GUI stating 'The file operation was completed with errors.' and Errors occured: "rule-xxxxxx.json: Error opening file "/home/pi/reactor/....................................json":Permission denied.

      I suspect it's something to do with permissions?

      Is there an easier way to copy my configuration over??

      Multi-System Reactor
    • Alexa TTS via Home Assistant?

      T

      Hello All -

      I'm gradually moving away from Vera to Home Assistant. I've recently gotten the Alexa and Mini Media Player setup in Home Assistant and everything is working well.

      Is there a way to call this service from Reactor? My goal is to send TTS requests to HAAS upon certain events within Reactor (e.g. "Front Door Opened")

      Multi-System Reactor
    • Integrate UPS with MSR

      wmarcolin

      I have a Tripp-Lite UPS (https://www.tripplite.com/smartpro-lcd-120v-1500va-900w-line-interactive-ups-avr-tower-lcd-usb-10-outlets~smart1500lcdt) that connected by a USB cable to my computer, reports various power supply and failure information, as shown in the panel below.

      b9f0ea34-d654-4b26-b968-4f8cf0a4e0c1-image.png

      afa73913-5318-42c6-af9a-02d36e2e6ea1-image.png

      The application I installed runs Java and opens the console to send the information.

      Has anyone tried to bring the information into the MSR? Or even a VeraPlus?

      Thanks.

      Multi-System Reactor
    • Reactor as tab in Hass sidebar

      Matohl

      panel_iframe in configuration.yaml. If you access MSR with HTTP it works in HA with HTTP to Reactor and HTTPS to HTTPS obviously.

      configuration.yaml

      # ============ SIDEBAR ============ panel_iframe: reactor: title: "Reactor" url: "http://192.168.0.23:8111/reactor/sv-SE/"
      Multi-System Reactor
    • Documentation>Network Status

      S

      It appears that in the Manual, under Management>Network Status is for Reactor on Vera. Is the Internet check functionality available with MSR and if so is there updated instructions? I do see a variable reactor_system.internet.ok but the value is null.
      I am looking for a way to check for internet status with MSR before installing an extra app on a hub to get the information.

      Synology Docker latest-22149

      Multi-System Reactor
    • MSR Upgrade from 22119 to 22136 fails, service wont start

      W

      Windows Server 2022 Build 20348
      Nodejs v16.14.0
      Currently running Reactor (Multi-hub) stable-22119-ae7212f
      Linked to Hass 2022.0.5.4 (on a different box)
      Windows server is dedicated to MSR and doesn't do anything else.

      I'd like to upgrade to 22136 to take advantage of the SSL feature added recently, and also to bring my current version of Hass into the 'supported' column with MSR.

      Following the instructions here: link text, section "Upgrade Windows Bare Metal"

      Stop Reactor Service Extract the zip, overwriting the reactor folder in c:\reactor\reactor There is no package-lock.json file so I skip that. Run "npm install --no-save --omit dev"

      Next step is to start the service. I start the service and it immediately stops. "Windows could not start the Reactor service on Local Computer. Error 1067: The process terminated unexpectedly".

      Tried rebooting, service won't stay running.

      I suspect I'm missing something, it's probably obvious but I've not been able to figure it out.

      I rolled back the reactor folder version (Windows Shadow copies) and then the service starts fine.

      Anyone else running Windows and know what I'm missing?

      Tail of log file from running OK version, before upgrade attempt [stable-22119]2022-06-01T22:20:19.081Z <Rule:INFO> Lounge Billy Ambient Lighting - Turn On (Rule#rule-l0ki453b) evaluation complete [stable-22119]2022-06-01T22:20:19.082Z <httpapi:NOTICE> HTTP API v1 22021 base URL http://172.16.128.6:8111; listening [stable-22119]2022-06-01T22:20:19.228Z <app:NOTICE> HTTP server running; registering proxy endpoints. [stable-22119]2022-06-01T22:20:19.228Z <app:NOTICE> Starting WSAPI... [stable-22119]2022-06-01T22:20:19.229Z <wsapi:NOTICE> wsapi: starting version 21334 [stable-22119]2022-06-01T22:20:19.656Z <Engine:INFO> [Engine]Engine#1 master timer tick, local time "6/2/2022, 8:20:19 AM" (TZ offset 600 mins from UTC) [stable-22119]2022-06-01T22:27:54.788Z <wsapi:INFO> wsapi: connection from ::ffff:172.16.128.5 Tail of log file from failed to start after upgrade (is identical, ii.e. nothing has been appended to it) [stable-22119]2022-06-01T22:20:19.081Z <Rule:INFO> Lounge Billy Ambient Lighting - Turn On (Rule#rule-l0ki453b) evaluation complete [stable-22119]2022-06-01T22:20:19.082Z <httpapi:NOTICE> HTTP API v1 22021 base URL http://172.16.128.6:8111; listening [stable-22119]2022-06-01T22:20:19.228Z <app:NOTICE> HTTP server running; registering proxy endpoints. [stable-22119]2022-06-01T22:20:19.228Z <app:NOTICE> Starting WSAPI... [stable-22119]2022-06-01T22:20:19.229Z <wsapi:NOTICE> wsapi: starting version 21334 [stable-22119]2022-06-01T22:20:19.656Z <Engine:INFO> [Engine]Engine#1 master timer tick, local time "6/2/2022, 8:20:19 AM" (TZ offset 600 mins from UTC) [stable-22119]2022-06-01T22:27:54.788Z <wsapi:INFO> wsapi: connection from ::ffff:172.16.128.5 reactor.wrapper.log (log file the failed to start event points to) 2022-06-02 08:19:23 - Stopping reactor.exe 2022-06-02 08:19:23 - ProcessKill 3628 2022-06-02 08:19:25 - Shutdown exception Message:A system shutdown is in progress. Stacktrace: at System.Runtime.InteropServices.Marshal.ThrowExceptionForHRInternal(Int32 errorCode, IntPtr errorInfo) at System.Management.ManagementScope.InitializeGuts(Object o) at System.Management.ManagementScope.Initialize() at System.Management.ManagementObjectSearcher.Initialize() at System.Management.ManagementObjectSearcher.Get() at winsw.WrapperService.GetChildPids(Int32 pid) at winsw.WrapperService.StopProcessAndChildren(Int32 pid) at winsw.WrapperService.StopIt() at winsw.WrapperService.OnShutdown() 2022-06-02 08:20:11 - Starting C:\Program Files\nodejs\node.exe C:\reactor\reactor\node_modules\node-windows\lib\wrapper.js --file C:\reactor\reactor\app.js --scriptoptions= --log "Reactor wrapper" --grow 0.25 --wait 1 --maxrestarts 3 --abortonerror n --stopparentfirst undefined 2022-06-02 08:20:11 - Started 3272 2022-06-02 08:30:54 - Stopping reactor.exe 2022-06-02 08:30:54 - ProcessKill 3272 2022-06-02 08:30:54 - Found child process: 3280 Name: conhost.exe 2022-06-02 08:30:54 - Found child process: 3504 Name: node.exe 2022-06-02 08:30:54 - Stopping process 3280 2022-06-02 08:30:54 - Send SIGINT 3280 2022-06-02 08:30:54 - SIGINT to 3280 failed - Killing as fallback 2022-06-02 08:30:54 - Stopping process 3504 2022-06-02 08:30:54 - Send SIGINT 3504 2022-06-02 08:30:54 - SIGINT to 3504 failed - Killing as fallback 2022-06-02 08:30:54 - Stopping process 3272 2022-06-02 08:30:54 - Send SIGINT 3272 2022-06-02 08:30:54 - SIGINT to 3272 failed - Killing as fallback 2022-06-02 08:30:54 - Finished reactor.exe 2022-06-02 08:33:41 - Starting C:\Program Files\nodejs\node.exe C:\reactor\reactor\node_modules\node-windows\lib\wrapper.js --file C:\reactor\reactor\app.js --scriptoptions= --log "Reactor wrapper" --grow 0.25 --wait 1 --maxrestarts 3 --abortonerror n --stopparentfirst undefined 2022-06-02 08:33:41 - Started 4184 2022-06-02 08:36:57 - Starting C:\Program Files\nodejs\node.exe C:\reactor\reactor\node_modules\node-windows\lib\wrapper.js --file C:\reactor\reactor\app.js --scriptoptions= --log "Reactor wrapper" --grow 0.25 --wait 1 --maxrestarts 3 --abortonerror n --stopparentfirst undefined 2022-06-02 08:36:57 - Started 3100 Windows event log event: Child process [4184 - C:\Program Files\nodejs\node.exe C:\reactor\reactor\node_modules\node-windows\lib\wrapper.js --file C:\reactor\reactor\app.js --scriptoptions= --log "Reactor wrapper" --grow 0.25 --wait 1 --maxrestarts 3 --abortonerror n --stopparentfirst undefined] finished with 1
      Multi-System Reactor
    • [Solved] suninfo.period "night" and rule trigger for sunset are at different times

      Crille

      I'm just curious, what's the difference between suninfo.period changing from "day" to "night" vs "after sunset" with no offset?
      suninfo.period changes to "night" 7 minutes and 33 seconds before "after sunset" is triggered in my latest-22149 bare metal setup.

      Multi-System Reactor
    • Status page rule history length.

      MikeReadington

      Hello Patrick,

      On the status page rule history is there any adjustably on length of the history shown? I had an occasion where it would have been helpful to go a few notches farther back than it does as currently configured.

      I don't know if this is a log parser or if it is a separate smaller data set. If it is a log parser, any chance for maybe something like a "more" button?

      Thanks,
      Mike

      Multi-System Reactor
    • [Solved] New device on Ezlo is not added in Reactor

      Crille

      I can't find any posts or reference in docs for this log message

      <EzloController:NOTICE> EzloController#ezlo received notice of new device, but auto-rediscover is OFF; ignoring

      I've restarted MSR and hard refreshed browser but the new entity is not added. Can I set auto-rediscover to ON or how do I get the new device added into Reactor?

      Edit:
      Bare metal latest-22142
      The device is a Xiaomi Mini Switch, it's publishing correct values in ezmqtt.

      Edit 2: The Xiaomi Aqara Mini Switch is now mapped in build 22149.

      Multi-System Reactor
    • Disk Warning on Multisystem Reactor

      S

      334ccd7a-9499-4dea-8a4a-2347609dce62-image.png

      For the life of me I cannot figure this out.
      when I run the du -hs command (from the host) for the mapped volume I get 25M
      (/home/seth/ReactorConfig maps to /var/reactor)

      Inside the container I ran du -hs for each of the folders that the ui is complaining about
      /opt/reactor = 71.2M
      /var/reactor/storage = 2.9M
      /var/reactor/logs = 17.6M

      If I run df on the docker container I get this. Disk space is not critical
      1f5d230c-0792-468b-b3b7-9f45e31581c5-image.png

      What gives?

      Multi-System Reactor
    For those who registered but didn't received the confirmation email, please send an email to support@smarthome.community with the email you used

    EzloController error

    Multi-System Reactor
    3
    20
    169
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • Crille
      Crille @toggledbits last edited by

      @toggledbits Today I got a false positive from Reactor saying my Ezlo Plus was offline, a restart of Reactor solved it.
      This was found in the log before the restart:

      2021-10-01T06:32:29.441Z <EzloController:ERR> EzloController#ezlo ws_message handler failed: RangeError: Maximum call stack size exceeded
      2021-10-01T06:32:29.441Z <EzloController:CRIT> RangeError: Maximum call stack size exceeded
      RangeError: Maximum call stack size exceeded
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1134:127)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
          at EzloController._now.ws_message [as refreshTime] (/home/user/reactor/server/lib/EzloController.js:1138:54)
      2021-10-01T06:32:38.985Z <EzloController:ERR> EzloController#ezlo request "17c3a8dccaf" (hub.info.get) failed: TimedPromise timeout
      2021-10-01T06:32:38.985Z <EzloController:ERR> EzloController#ezlo failed to complete inventory: TimedPromise timeout
      2021-10-01T06:32:38.985Z <EzloController:CRIT> !TimedPromise timeout
      2021-10-01T06:32:38.988Z <EzloController:NOTICE> EzloController#ezlo connection closed: 1002
      

      Reactor latest-21270-48528ec, updated to latest-21270-46679ac just now.

      Crille 1 Reply Last reply Reply Quote 0
      • toggledbits
        toggledbits last edited by toggledbits

        When posting error messages from the logs it's really helpful to post several dozen lines from before the message, as well as the message itself. This gives the message more context and usually exposes what was going on at the time the error occurred. Can you post a bit of context for me? It would also be helpful to know what version of MSR you are running.

        Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

        1 Reply Last reply Reply Quote 0
        • Crille
          Crille @Crille last edited by

          @crille said in EzloController error:

          Reactor latest-21270-48528ec, updated to latest-21270-46679ac just now.

          One of my rules executed at the time uses set variable and I was running the version without the fix. I'm guessing the controller was unreachable for a short time but Reactor never caught the online status cause of the "Maximum call stack size exceeded".

          The hub responded but was offline in Reactor until I restarted Reactor.

          2021-10-01T04:00:00.002Z <Rule:INFO> Schema - Vitrinskåp (Rule#rule-kmusx4kh) SET!
          2021-10-01T04:00:00.003Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:00.003Z <Engine:INFO> Enqueueing "Schema - Vitrinskåp<SET>" (rule-kmusx4kh:S)
          2021-10-01T04:00:00.007Z <Engine:5:Engine.js:1219> Engine#1 enqueued reaction rule-kmusx4kh:S as 428
          2021-10-01T04:00:00.007Z <Engine:5:Engine.js:1359> _process_reaction_queue() ending with 1 in queue; waiting for 1633060800007<10/1/2021, 6:00:00 AM> (next delayed task)
          2021-10-01T04:00:00.008Z <Rule:INFO> Schema - Larm: Nattläge (Rule#rule-ksvitzde) RESET!
          2021-10-01T04:00:00.009Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:00.009Z <Engine:INFO> Enqueueing "Schema - Larm: Nattläge<RESET>" (rule-ksvitzde:R)
          2021-10-01T04:00:00.009Z <Engine:5:Engine.js:1219> Engine#1 enqueued reaction rule-ksvitzde:R as 429
          2021-10-01T04:00:00.010Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 428 { "tid": 428, "id": "rule-kmusx4kh:S", "rule": "rule-kmusx4kh", "__reaction": [RuleReaction#rule-kmusx4kh:S], "next_step": 0, "status": 0, "ts": 1633060800003, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
          2021-10-01T04:00:00.010Z <Engine:NOTICE> Starting reaction Schema - Vitrinskåp<SET> (rule-kmusx4kh:S)
          2021-10-01T04:00:00.010Z <Engine:5:Engine.js:1421> Engine#1 reaction rule-kmusx4kh:S step 0 perform { "entity": "ezlo>device_603a0363129e0715cf4a75fe", "action": "power_switch.on" }
          2021-10-01T04:00:00.011Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status 3; task 428
          2021-10-01T04:00:00.012Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 429 { "tid": 429, "id": "rule-ksvitzde:R", "rule": "rule-ksvitzde", "__reaction": [RuleReaction#rule-ksvitzde:R], "next_step": 0, "status": 0, "ts": 1633060800009, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
          2021-10-01T04:00:00.012Z <Engine:NOTICE> Starting reaction Schema - Larm: Nattläge<RESET> (rule-ksvitzde:R)
          2021-10-01T04:00:00.012Z <Engine:5:Engine.js:1421> Engine#1 reaction rule-ksvitzde:R step 0 perform { "entity": "vera>device_10050", "action": "x_vera_plugin_housemodes.set_house_mode", "args": { "new_mode": "1" } }
          2021-10-01T04:00:00.013Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status 3; task 429
          2021-10-01T04:00:00.013Z <VeraController:null> VeraController#vera enqueue task for Entity#vera>device_10050 action x_vera_plugin_housemodes.set_house_mode: task { "newHModeValue": 1, "DeviceNum": 10050, "id": "action", "serviceId": "urn:micasaverde-com:serviceId:HouseModes1", "action": "SetHMode" }
          2021-10-01T04:00:00.014Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 2 in queue; none delayed/ready; waiting
          2021-10-01T04:00:00.014Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:00:00.015Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:00:00.017Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:00.017Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 429 { "tid": 429, "id": "rule-ksvitzde:R", "rule": "rule-ksvitzde", "__reaction": [RuleReaction#rule-ksvitzde:R], "next_step": 1, "status": 1, "ts": 1633060800009, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "attempts": 1 }
          2021-10-01T04:00:00.017Z <Engine:NOTICE> Resuming reaction Schema - Larm: Nattläge<RESET> (rule-ksvitzde:R) from step 1
          2021-10-01T04:00:00.018Z <Engine:INFO> Schema - Larm: Nattläge<RESET> all actions completed.
          2021-10-01T04:00:00.018Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status -1; task 429
          2021-10-01T04:00:00.019Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 1 in queue; none delayed/ready; waiting
          2021-10-01T04:00:00.025Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:00:00.026Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:00:00.146Z <Engine:5:Engine.js:1083> Engine#1 var HouseMode dependency entity-changed Entity#vera>device_10050
          2021-10-01T04:00:00.148Z <default:CRIT> Error: Object does not exist
          Error: Object does not exist
              at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:135:27)
              at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1084:59)
              at /home/username/reactor/server/lib/MessageBus.js:103:200
              at Array.forEach (<anonymous>)
              at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:100:46)
              at Immediate._onImmediate (/home/username/reactor/server/lib/MessageBus.js:113:34)
              at processImmediate (internal/timers.js:461:21)
          2021-10-01T04:00:00.149Z <Engine:5:Engine.js:1083> Engine#1 var hm dependency entity-changed Entity#vera>housemode
          2021-10-01T04:00:00.151Z <default:CRIT> Error: Object does not exist
          Error: Object does not exist
              at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:135:27)
              at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1084:59)
              at /home/username/reactor/server/lib/MessageBus.js:103:200
              at Array.forEach (<anonymous>)
              at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:100:46)
              at Immediate._onImmediate (/home/username/reactor/server/lib/MessageBus.js:113:34)
              at processImmediate (internal/timers.js:461:21)
          2021-10-01T04:00:00.156Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>housemode) ctx=other
          2021-10-01T04:00:00.156Z <Rule:INFO> Notifiering - House mode (Rule#rule-ksw26xod) SET!
          2021-10-01T04:00:00.165Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:00.166Z <Engine:INFO> Enqueueing "Notifiering - House mode<SET>" (rule-ksw26xod:S)
          2021-10-01T04:00:00.167Z <Engine:5:Engine.js:1219> Engine#1 enqueued reaction rule-ksw26xod:S as 430
          2021-10-01T04:00:00.167Z <Engine:5:Engine.js:1359> _process_reaction_queue() ending with 2 in queue; waiting for 1633060800167<10/1/2021, 6:00:00 AM> (next delayed task)
          2021-10-01T04:00:00.170Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>housemode) ctx=other
          2021-10-01T04:00:00.178Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:00.179Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 430 { "tid": 430, "id": "rule-ksw26xod:S", "rule": "rule-ksw26xod", "__reaction": [RuleReaction#rule-ksw26xod:S], "next_step": 0, "status": 0, "ts": 1633060800166, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
          2021-10-01T04:00:00.179Z <Engine:NOTICE> Starting reaction Notifiering - House mode<SET> (rule-ksw26xod:S)
          2021-10-01T04:00:00.179Z <Engine:5:Engine.js:1470> Engine#1 reaction rule-ksw26xod:S step 0 notify Pushover with { "message": "Larmet ändrades från night till home.", "profile": "MSR", "title": "Larmet ändrade status", "priority": "0" }
          2021-10-01T04:00:00.180Z <NotifyPushover:5:NotifyPushover.js:228> NotifyPushover sending profile MSR notification request: Larmet ändrades från night till home.
          2021-10-01T04:00:00.182Z <Engine:INFO> Notifiering - House mode<SET> all actions completed.
          2021-10-01T04:00:00.182Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status -1; task 430
          2021-10-01T04:00:00.185Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 1 in queue; none delayed/ready; waiting
          2021-10-01T04:00:01.171Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>housemode) ctx=other
          2021-10-01T04:00:01.171Z <Rule:INFO> Notifiering - House mode (Rule#rule-ksw26xod) RESET!
          2021-10-01T04:00:01.171Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:01.172Z <Engine:INFO> Enqueueing "Notifiering - House mode<RESET>" (rule-ksw26xod:R)
          2021-10-01T04:00:01.173Z <Engine:5:Engine.js:1219> Engine#1 enqueued reaction rule-ksw26xod:R as 431
          2021-10-01T04:00:01.173Z <Engine:5:Engine.js:1359> _process_reaction_queue() ending with 2 in queue; waiting for 1633060801173<10/1/2021, 6:00:01 AM> (next delayed task)
          2021-10-01T04:00:01.184Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:01.184Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 431 { "tid": 431, "id": "rule-ksw26xod:R", "rule": "rule-ksw26xod", "__reaction": [RuleReaction#rule-ksw26xod:R], "next_step": 0, "status": 0, "ts": 1633060801172, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
          2021-10-01T04:00:01.185Z <Engine:NOTICE> Starting reaction Notifiering - House mode<RESET> (rule-ksw26xod:R)
          2021-10-01T04:00:01.185Z <Engine:5:Engine.js:1597> Engine#1 reaction rule-ksw26xod:R step 0 set variable prevHouseMode=${{housemode}} (string home)
          2021-10-01T04:00:01.185Z <Engine:5:Engine.js:1161> Engine#1 global set variable prevHouseMode = (string) home
          2021-10-01T04:00:01.185Z <Engine:5:Engine.js:1167> Engine#1 var prevHouseMode set/changed to (string)home
          2021-10-01T04:00:01.185Z <Engine:INFO> Notifiering - House mode<RESET> all actions completed.
          2021-10-01T04:00:01.186Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status -1; task 431
          2021-10-01T04:00:01.186Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 1 in queue; none delayed/ready; waiting
          2021-10-01T04:00:01.186Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>housemode) ctx=other
          2021-10-01T04:00:01.187Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>housemode) ctx=other
          2021-10-01T04:00:05.003Z <Engine:INFO> Engine#1 master timer tick, local time "10/1/2021, 6:00:05 AM" (TZ offset 120 mins from UTC)
          2021-10-01T04:00:10.233Z <NotifyPushover:ERR> NotifyPushover failure response from endpoint: 520 (undefined)
          2021-10-01T04:00:10.233Z <NotifyPushover:INFO> NotifyPushover request URL: https://api.pushover.net/1/messages.json
          2021-10-01T04:00:10.234Z <NotifyPushover:INFO> NotifyPushover request body: token=xxxxxxxxxxxxxxxxxxxx&user=xxxxxxxxxxxxxxxxxxxxxxxxx&priority=0&title=Larmet%20%C3%A4ndrade%20status&message=Larmet%20%C3%A4ndrades%20fr%C3%A5n%20night%20till%20home.
          2021-10-01T04:00:10.234Z <NotifyPushover:ERR> NotifyPushover request to https://api.pushover.net/1/messages.json failed: Error: NotifyPushover request failed
          2021-10-01T04:00:10.234Z <Engine:ERR> Engine#1 reaction rule-ksw26xod:S step 0 notification (Pushover) failed: Error: NotifyPushover request failed
          2021-10-01T04:00:13.164Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:13.165Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:13.167Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:13.168Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:13.169Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:13.170Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:13.171Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:00:15.015Z <EzloController:ERR> EzloController#ezlo request "17c3a02460b" ({ "method": "hub.item.value.set", "api": "1.0" }) failed: TimedPromise timeout
          2021-10-01T04:00:15.017Z <EzloController:WARN> EzloController#ezlo action power_switch.on on Entity#ezlo>device_603a0363129e0715cf4a75fe failed!
          2021-10-01T04:00:15.018Z <Engine:ERR> Engine#1 reaction rule-kmusx4kh:S step 0 perform power_switch.on failed: TimedPromise timeout
          2021-10-01T04:00:15.018Z <Engine:INFO> Engine#1 action args: {  }
          2021-10-01T04:00:15.018Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:00:15.020Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 428 { "tid": 428, "id": "rule-kmusx4kh:S", "rule": "rule-kmusx4kh", "__reaction": [RuleReaction#rule-kmusx4kh:S], "next_step": 1, "status": 1, "ts": 1633060800003, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "attempts": 1 }
          2021-10-01T04:00:15.020Z <Engine:NOTICE> Resuming reaction Schema - Vitrinskåp<SET> (rule-kmusx4kh:S) from step 1
          2021-10-01T04:00:15.021Z <Engine:INFO> Schema - Vitrinskåp<SET> all actions completed.
          2021-10-01T04:00:15.021Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status -1; task 428
          2021-10-01T04:00:15.023Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
          2021-10-01T04:00:57.033Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:57.033Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:57.035Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:57.035Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:57.036Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:57.037Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:57.038Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:00:58.167Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:58.168Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:00:58.172Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:58.173Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:58.174Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:58.176Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:00:58.176Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:01:00.004Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 1ms and returned 22 entities
          2021-10-01T04:01:00.009Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 1ms and returned 22 entities
          2021-10-01T04:01:00.018Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:01:00.023Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 5ms and returned 22 entities
          2021-10-01T04:01:12.961Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:12.961Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:12.961Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:12.962Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:12.962Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:12.963Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:12.963Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:01:13.165Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:13.165Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:13.167Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:13.168Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:13.168Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:13.169Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:13.170Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:01:56.999Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:56.999Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:57.000Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:57.000Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:57.000Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:57.001Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:57.001Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:01:58.169Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:58.170Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:01:58.172Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:58.173Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:58.174Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:58.175Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:01:58.176Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:02:00.004Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:02:00.005Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:02:00.015Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:02:00.016Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:02:13.427Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:13.428Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:13.430Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:13.431Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:13.431Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:13.433Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:13.433Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:02:34.912Z <EzloController:NOTICE> EzloController#ezlo connection closed: 1006
          2021-10-01T04:02:39.918Z <EzloController:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
          2021-10-01T04:02:39.918Z <EzloController:INFO> EzloController#ezlo opening hub connection to "XXXXXXXX" at wss://192.168.1.100:17000
          2021-10-01T04:02:39.920Z <EzloController:NOTICE> EzloController#ezlo connecting via WS to wss://192.168.1.100:17000
          2021-10-01T04:02:40.007Z <EzloController:INFO> EzloController#ezlo hub websocket connected (wss://192.168.1.100:17000)
          2021-10-01T04:02:40.007Z <EzloController:INFO> EzloController#ezlo hub websocket connected; inventory hub...
          2021-10-01T04:02:55.016Z <EzloController:ERR> EzloController#ezlo request "17c3a04b708" (hub.info.get) failed: TimedPromise timeout
          2021-10-01T04:02:55.017Z <EzloController:ERR> EzloController#ezlo failed to complete inventory: TimedPromise timeout
          2021-10-01T04:02:55.018Z <EzloController:CRIT> !TimedPromise timeout
          2021-10-01T04:02:55.025Z <EzloController:NOTICE> EzloController#ezlo connection closed: 1002
          2021-10-01T04:02:56.933Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:56.933Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:56.933Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:56.934Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:56.934Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:56.934Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:56.934Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:02:58.144Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:58.144Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:02:58.144Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:58.145Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:58.145Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:58.145Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:02:58.145Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:03:00.003Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 1ms and returned 22 entities
          2021-10-01T04:03:00.005Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:03:00.015Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 1ms and returned 22 entities
          2021-10-01T04:03:00.016Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
          2021-10-01T04:03:00.025Z <EzloController:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
          2021-10-01T04:03:00.025Z <EzloController:INFO> EzloController#ezlo opening hub connection to "XXXXXXXX" at wss://192.168.1.100:17000
          2021-10-01T04:03:00.025Z <EzloController:NOTICE> EzloController#ezlo connecting via WS to wss://192.168.1.100:17000
          2021-10-01T04:03:00.110Z <EzloController:INFO> EzloController#ezlo hub websocket connected (wss://192.168.1.100:17000)
          2021-10-01T04:03:00.110Z <EzloController:INFO> EzloController#ezlo hub websocket connected; inventory hub...
          2021-10-01T04:03:13.125Z <Engine:5:Engine.js:1083> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:03:13.125Z <Engine:5:Engine.js:1083> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
          2021-10-01T04:03:13.126Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:03:13.126Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:03:13.126Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:03:13.126Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_30005) ctx=global
          2021-10-01T04:03:13.126Z <Engine:5:Engine.js:942> Engine#1 getEntity(vera>device_52) ctx=global
          2021-10-01T04:03:15.112Z <EzloController:ERR> EzloController#ezlo request "17c3a05058e" (hub.info.get) failed: TimedPromise timeout
          2021-10-01T04:03:15.113Z <EzloController:ERR> EzloController#ezlo failed to complete inventory: TimedPromise timeout
          2021-10-01T04:03:15.113Z <EzloController:CRIT> !TimedPromise timeout
          2021-10-01T04:03:15.117Z <EzloController:NOTICE> EzloController#ezlo connection closed: 1002
          2021-10-01T04:03:15.119Z <EzloController:ERR> Controller EzloController#ezlo is off-line!
          2021-10-01T04:03:15.129Z <Rule:INFO> Notifiering - Ezlo status (Rule#rule-ktsucjh1) SET!
          2021-10-01T04:03:15.132Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:03:15.132Z <Engine:INFO> Enqueueing "Notifiering - Ezlo status<SET>" (rule-ktsucjh1:S)
          2021-10-01T04:03:15.133Z <Engine:5:Engine.js:1219> Engine#1 enqueued reaction rule-ktsucjh1:S as 432
          2021-10-01T04:03:15.133Z <Engine:5:Engine.js:1359> _process_reaction_queue() ending with 1 in queue; waiting for 1633060995133<10/1/2021, 6:03:15 AM> (next delayed task)
          2021-10-01T04:03:15.144Z <Engine:5:Engine.js:1359> _process_reaction_queue() wake-up!
          2021-10-01T04:03:15.145Z <Engine:5:Engine.js:1320> _process_reaction_queue() running task 432 { "tid": 432, "id": "rule-ktsucjh1:S", "rule": "rule-ktsucjh1", "__reaction": [RuleReaction#rule-ktsucjh1:S], "next_step": 0, "status": 0, "ts": 1633060995132, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
          2021-10-01T04:03:15.145Z <Engine:NOTICE> Starting reaction Notifiering - Ezlo status<SET> (rule-ktsucjh1:S)
          2021-10-01T04:03:15.145Z <Engine:5:Engine.js:1470> Engine#1 reaction rule-ktsucjh1:S step 0 notify Pushover with { "message": "Ezlo Plus svarar inte, troligen nere.", "profile": "MSR", "title": "Ezlo Plus nere!", "priority": "0" }
          2021-10-01T04:03:15.145Z <NotifyPushover:5:NotifyPushover.js:228> NotifyPushover sending profile MSR notification request: Ezlo Plus svarar inte, troligen nere.
          2021-10-01T04:03:15.146Z <Engine:INFO> Notifiering - Ezlo status<SET> all actions completed.
          2021-10-01T04:03:15.146Z <Engine:5:Engine.js:1324> _process_reaction_queue() task returned, new status -1; task 432
          2021-10-01T04:03:15.147Z <Engine:5:Engine.js:1359> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
          2021-10-01T04:03:16.289Z <NotifyPushover:5:NotifyPushover.js:236> NotifyPushover successful endpoint exchange (message sent)
          2021-10-01T04:03:20.122Z <EzloController:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
          2021-10-01T04:03:20.123Z <EzloController:INFO> EzloController#ezlo opening hub connection to "XXXXXXXX" at wss://192.168.1.100:17000
          2021-10-01T04:03:20.124Z <EzloController:NOTICE> EzloController#ezlo connecting via WS to wss://192.168.1.100:17000
          2021-10-01T04:03:20.214Z <EzloController:INFO> EzloController#ezlo hub websocket connected (wss://192.168.1.100:17000)
          2021-10-01T04:03:20.214Z <EzloController:INFO> EzloController#ezlo hub websocket connected; inventory hub...
          2021-10-01T04:03:20.456Z <EzloController:INFO> EzloController#ezlo hub "XXXXXXXX" is h2.1 (undefined) firmware "2.0.19.1714.2"
          2021-10-01T04:03:20.489Z <EzloController:ERR> EzloController#ezlo ws_message handler failed: RangeError: Maximum call stack size exceeded
          2021-10-01T04:03:20.490Z <EzloController:CRIT> RangeError: Maximum call stack size exceeded
          RangeError: Maximum call stack size exceeded
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1136:43)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
              at EzloController._now.ws_message [as refreshTime] (/home/username/reactor/server/lib/EzloController.js:1138:54)
          2021-10-01T04:03:35.461Z <EzloController:ERR> EzloController#ezlo request "17c3a05550c" ({ "method": "hub.modes.get", "api": "2.0" }) failed: TimedPromise timeout
          2021-10-01T04:03:35.462Z <EzloController:ERR> EzloController#ezlo failed to complete inventory: TimedPromise timeout
          2021-10-01T04:03:35.462Z <EzloController:CRIT> !TimedPromise timeout
          2021-10-01T04:03:35.468Z <EzloController:NOTICE> EzloController#ezlo connection closed: 1002
          2021-10-01T04:03:40.474Z <EzloController:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
          2021-10-01T04:03:40.474Z <EzloController:INFO> EzloController#ezlo opening hub connection to "XXXXXXXX" at wss://192.168.1.100:17000
          2021-10-01T04:03:40.475Z <EzloController:NOTICE> EzloController#ezlo connecting via WS to wss://192.168.1.100:17000
          2021-10-01T04:03:40.563Z <EzloController:INFO> EzloController#ezlo hub websocket connected (wss://192.168.1.100:17000)
          2021-10-01T04:03:40.563Z <EzloController:INFO> EzloController#ezlo hub websocket connected; inventory hub...
          2021-10-01T04:03:40.596Z <EzloController:ERR> EzloController#ezlo ws_message handler failed: RangeError: Maximum call stack size exceeded
          2021-10-01T04:03:40.597Z <EzloController:CRIT> RangeError: Maximum call stack size exceeded
          RangeError: Maximum call stack size exceeded...
          
          1 Reply Last reply Reply Quote 0
          • toggledbits
            toggledbits last edited by

            The Set Variable issue is specific to Vera controllers only and does not apply to eZLO or any other.

            The variable hm associated with rule Notifiering - House mode (Rule#rule-ksw26xod): can you tell me if that's a rule variable, or a global variable?

            Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

            Crille 1 Reply Last reply Reply Quote 0
            • Crille
              Crille @toggledbits last edited by

              @toggledbits Yes, in one of the rules I set the openLuup house mode via house mode plugin to push the mode to my Vera (That is otherwise primary for openLuup's house mode).

              The variable hm is an old test I did and does no longer exist and is not referenced anywhere visible to me?

              1 Reply Last reply Reply Quote 0
              • toggledbits
                toggledbits last edited by

                Variables hm and HouseMode both are referenced somewhere, but appear to not be global. If you don't see hm in the list of global variables, it's probably buried in a rule somewhere. What about HouseMode? Global or rule?

                Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                Crille 1 Reply Last reply Reply Quote 0
                • Crille
                  Crille @toggledbits last edited by

                  @toggledbits After going through every Rule Set I have, I deleted the global HouseMode hours before I got this error since it was not referenced anywhere.
                  hm was a local in Notifiering - House mode (Rule#rule-ksw26xod) but was replaced weeks ago with a new local named housemode

                  rule_1.PNG rule_2.PNG

                  This rule has been untouched for weaks and never failed, the thing I changed yesterday was the Trigger from housemode plugin to vera>housemode since it seems you fixed the housemode change issue from openLuup and native is snappier than the polling plugin.

                  1 Reply Last reply Reply Quote 0
                  • toggledbits
                    toggledbits last edited by

                    OK. Great detail. That helps, thank you. Let me see what I can do here...

                    Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                    Crille 1 Reply Last reply Reply Quote 0
                    • Crille
                      Crille @toggledbits last edited by Crille

                      @toggledbits I'm still having some problem with variables being referenced when deleted. Looks like the Engine is looking for an old global expression (undefined)? that I think I had a time ago with matchEntities
                      and
                      @ 2021-10-04T14:11:00.003Z
                      This rule triggers: Rule:INFO Notifiering - Ezlo devices (Rule#rule-ku32xyj5) SET!
                      ezlo_triggers.PNG ezlo_expression.PNG

                      I've now put a sustianed for 3 secs on the first variable trigger to ignore flapping.

                      global_expressions.PNG

                      None of the other rules triggered in the log snippet has any local expression or referenced global expressions and the "Error: Object does not exist" is present from:

                      2021-10-04T10:31:08.900Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:31:08.901Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:31:08.905Z <Engine:5:Engine.js:948> Engine#1 set global Medeltemp; value=(number)22
                      2021-10-04T10:31:08.908Z <Engine:5:Engine.js:948> Engine#1 set global Luftfuktighet; value=(number)0.8148148148148148
                      2021-10-04T10:31:10.074Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:31:10.075Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:31:25.061Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:31:25.061Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:00.014Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                      2021-10-04T10:32:00.027Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                      2021-10-04T10:32:09.094Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:09.095Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:10.297Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:10.297Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:24.996Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:32:24.996Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:00.002Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                      2021-10-04T10:33:00.015Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                      2021-10-04T10:33:09.142Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:09.143Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:09.148Z <Engine:5:Engine.js:948> Engine#1 set global Luftfuktighet; value=(number)0.7901234567901234
                      2021-10-04T10:33:10.387Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:10.388Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:25.394Z <Engine:5:Engine.js:1108> Engine#1 var Medeltemp dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:25.394Z <Engine:5:Engine.js:1108> Engine#1 var Luftfuktighet dependency entity-changed Entity#vera>device_30005
                      2021-10-04T10:33:30.894Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a0373129e0715cf4a765f
                      2021-10-04T10:33:30.897Z <default:CRIT> Error: Object does not exist
                      Error: Object does not exist
                          at Function.getInstance (/home/homebridge/reactor/server/lib/GlobalExpression.js:130:27)
                          at Engine._expr_dependency (/home/homebridge/reactor/server/lib/Engine.js:1109:59)
                          at /home/homebridge/reactor/server/lib/MessageBus.js:99:208
                          at Array.forEach (<anonymous>)
                          at MessageBus._sendToBus (/home/homebridge/reactor/server/lib/MessageBus.js:96:47)
                          at /home/homebridge/reactor/server/lib/MessageBus.js:109:48
                          at new Promise (<anonymous>)
                          at MessageBus.send (/home/homebridge/reactor/server/lib/MessageBus.js:106:16)
                          at Entity.publish (/home/homebridge/reactor/server/lib/Observable.js:71:44)
                          at Entity.deferNotifies (/home/homebridge/reactor/server/lib/Entity.js:248:207)
                      

                      Where everything above the error is just repeating.

                      Log from rule SET in next post...

                      Crille 1 Reply Last reply Reply Quote 0
                      • Crille
                        Crille @Crille last edited by

                        First lines looks interesting

                        2021-10-04T14:10:33.692Z <EzloController:WARN> EzloController#ezlo warning: update parameter serviceNotification for Entity#ezlo>device_603a0367129e0715cf4a7604 not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:33.693Z <EzloController:WARN> EzloController#ezlo warning: update parameter syncNotification for Entity#ezlo>device_603a0367129e0715cf4a7604 not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:33.694Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a0367129e0715cf4a7604
                        2021-10-04T14:10:33.697Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:10:35.317Z <EzloController:WARN> EzloController#ezlo warning: update parameter serviceNotification for Entity#ezlo>device_603a036a129e0715cf4a761d not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:35.318Z <EzloController:WARN> EzloController#ezlo warning: update parameter syncNotification for Entity#ezlo>device_603a036a129e0715cf4a761d not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:35.318Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036a129e0715cf4a761d
                        2021-10-04T14:10:35.318Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:10:35.439Z <EzloController:WARN> EzloController#ezlo warning: update parameter serviceNotification for Entity#ezlo>device_6107edd0129e071241a25469 not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:35.439Z <EzloController:WARN> EzloController#ezlo warning: update parameter syncNotification for Entity#ezlo>device_6107edd0129e071241a25469 not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:35.440Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_6107edd0129e071241a25469
                        2021-10-04T14:10:35.440Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:10:39.201Z <EzloController:WARN> EzloController#ezlo warning: update parameter serviceNotification for Entity#ezlo>device_603a60dc129e071231a7f95e not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:39.201Z <EzloController:WARN> EzloController#ezlo warning: update parameter syncNotification for Entity#ezlo>device_603a60dc129e071231a7f95e not previously defined! (value now (boolean)false)
                        2021-10-04T14:10:39.203Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a60dc129e071231a7f95e
                        2021-10-04T14:10:39.205Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:11:00.002Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                        2021-10-04T14:11:00.003Z <Rule:INFO> Notifiering - Ezlo devices (Rule#rule-ku32xyj5) SET!
                        2021-10-04T14:11:00.005Z <Engine:5:Engine.js:1386> _process_reaction_queue() wake-up!
                        2021-10-04T14:11:00.005Z <Engine:INFO> Enqueueing "Notifiering - Ezlo devices<SET>" (rule-ku32xyj5:S)
                        2021-10-04T14:11:00.006Z <Engine:5:Engine.js:1246> Engine#1 enqueued reaction rule-ku32xyj5:S as 70
                        2021-10-04T14:11:00.006Z <Engine:5:Engine.js:1386> _process_reaction_queue() ending with 1 in queue; waiting for 1633356660006<10/4/2021, 4:11:00 PM> (next delayed task)
                        2021-10-04T14:11:00.013Z <Engine:INFO> Engine#1 matchEntities({ "controller": [ "ezlo" ], "capability": [ "x_ezlo_device" ], "group": [  ] }) took 0ms and returned 22 entities
                        2021-10-04T14:11:00.014Z <Rule:INFO> Notifiering - Ezlo devices (Rule#rule-ku32xyj5) RESET!
                        2021-10-04T14:11:00.015Z <Engine:5:Engine.js:1386> _process_reaction_queue() wake-up!
                        2021-10-04T14:11:00.015Z <Engine:5:Engine.js:1347> _process_reaction_queue() running task 70 { "tid": 70, "id": "rule-ku32xyj5:S", "rule": "rule-ku32xyj5", "__reaction": [RuleReaction#rule-ku32xyj5:S], "next_step": 0, "status": 0, "ts": 1633356660005, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise], "halt": true }
                        2021-10-04T14:11:00.015Z <Engine:INFO> Halting reaction Notifiering - Ezlo devices<SET> (rule-ku32xyj5:S) at step 0
                        2021-10-04T14:11:00.016Z <Engine:NOTICE> Handling reaction halt request for Notifiering - Ezlo devices<SET> at step 0
                        2021-10-04T14:11:00.016Z <Engine:5:Engine.js:1351> _process_reaction_queue() task returned, new status -1; task 70
                        2021-10-04T14:11:00.016Z <Engine:NOTICE> Engine#1 entry 70 reaction rule-ku32xyj5:S: terminated
                        2021-10-04T14:11:00.016Z <Engine:CRIT> !terminated
                        2021-10-04T14:11:00.017Z <Engine:5:Engine.js:1386> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
                        2021-10-04T14:11:00.021Z <Engine:INFO> Enqueueing "Notifiering - Ezlo devices<RESET>" (rule-ku32xyj5:R)
                        2021-10-04T14:11:00.021Z <Engine:5:Engine.js:1246> Engine#1 enqueued reaction rule-ku32xyj5:R as 71
                        2021-10-04T14:11:00.021Z <Engine:5:Engine.js:1386> _process_reaction_queue() wake-up!
                        2021-10-04T14:11:00.022Z <Engine:5:Engine.js:1347> _process_reaction_queue() running task 71 { "tid": 71, "id": "rule-ku32xyj5:R", "rule": "rule-ku32xyj5", "__reaction": [RuleReaction#rule-ku32xyj5:R], "next_step": 0, "status": 0, "ts": 1633356660021, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
                        2021-10-04T14:11:00.022Z <Engine:NOTICE> Starting reaction Notifiering - Ezlo devices<RESET> (rule-ku32xyj5:R)
                        2021-10-04T14:11:00.023Z <Engine:5:Engine.js:1496> Engine#1 reaction rule-ku32xyj5:R step 0 notify Pushover with { "message": "Alla enheter svarar igen.", "profile": "MSR", "title": "Ezlo-enheter svarar igen.", "priority": "0" }
                        2021-10-04T14:11:00.023Z <NotifyPushover:5:NotifyPushover.js:216> NotifyPushover sending profile MSR notification request: Alla enheter svarar igen.
                        2021-10-04T14:11:00.024Z <Engine:INFO> Notifiering - Ezlo devices<RESET> all actions completed.
                        2021-10-04T14:11:00.024Z <Engine:5:Engine.js:1351> _process_reaction_queue() task returned, new status -1; task 71
                        2021-10-04T14:11:00.025Z <Engine:5:Engine.js:1386> _process_reaction_queue ending with 0 in queue; none delayed/ready; waiting
                        2021-10-04T14:11:00.647Z <NotifyPushover:5:NotifyPushover.js:224> NotifyPushover successful endpoint exchange (message sent)
                        2021-10-04T14:11:03.822Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036e129e0715cf4a763e
                        2021-10-04T14:11:03.825Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:11:03.828Z <Rule:INFO> Tänd i Källaren beroende på Ljus (Rule#rule-kmuwu2tk) RESET!
                        2021-10-04T14:11:03.835Z <Engine:5:Engine.js:1386> _process_reaction_queue() wake-up!
                        2021-10-04T14:11:03.836Z <Engine:INFO> Enqueueing "Tänd i Källaren beroende på Ljus<RESET>" (rule-kmuwu2tk:R)
                        2021-10-04T14:11:03.837Z <Engine:5:Engine.js:1246> Engine#1 enqueued reaction rule-kmuwu2tk:R as 72
                        2021-10-04T14:11:03.838Z <Engine:5:Engine.js:1386> _process_reaction_queue() ending with 1 in queue; waiting for 1633356663837<10/4/2021, 4:11:03 PM> (next delayed task)
                        2021-10-04T14:11:03.840Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036e129e0715cf4a763a
                        2021-10-04T14:11:03.842Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:11:03.845Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036e129e0715cf4a763a
                        2021-10-04T14:11:03.848Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:11:03.850Z <Engine:5:Engine.js:1386> _process_reaction_queue() wake-up!
                        2021-10-04T14:11:03.851Z <Engine:5:Engine.js:1347> _process_reaction_queue() running task 72 { "tid": 72, "id": "rule-kmuwu2tk:R", "rule": "rule-kmuwu2tk", "__reaction": [RuleReaction#rule-kmuwu2tk:R], "next_step": 0, "status": 0, "ts": 1633356663836, "parent": --null--, "__resolve": --function--, "__reject": --function--, "__promise": [object Promise] }
                        2021-10-04T14:11:03.852Z <Engine:NOTICE> Starting reaction Tänd i Källaren beroende på Ljus<RESET> (rule-kmuwu2tk:R)
                        2021-10-04T14:11:03.852Z <Engine:5:Engine.js:1416> Engine#1 reaction rule-kmuwu2tk:R handling group rule-kmuwu2tk:R-7pjfxee constraints state true
                        2021-10-04T14:11:03.852Z <Engine:5:Engine.js:1418> Engine#1 constraints OK for reaction rule-kmuwu2tk:R group rule-kmuwu2tk:R-7pjfxee, queueing
                        2021-10-04T14:11:03.853Z <Engine:5:Engine.js:1430> Engine#1 reaction rule-kmuwu2tk:R group rule-kmuwu2tk:R-7pjfxee enqueued, waiting for completion
                        2021-10-04T14:11:03.853Z <Engine:5:Engine.js:1351> _process_reaction_queue() task returned, new status 3; task 72
                        2021-10-04T14:11:03.855Z <Engine:5:Engine.js:1246> Engine#1 enqueued reaction rule-kmuwu2tk:R-7pjfxee as 73
                        2021-10-04T14:11:03.856Z <Engine:5:Engine.js:1386> _process_reaction_queue() ending with 2 in queue; waiting for 1633356663855<10/4/2021, 4:11:03 PM> (next delayed task)
                        2021-10-04T14:11:03.856Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036e129e0715cf4a763a
                        2021-10-04T14:11:03.857Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                            at Function.getInstance (/home/username/reactor/server/lib/GlobalExpression.js:130:27)
                            at Engine._expr_dependency (/home/username/reactor/server/lib/Engine.js:1109:59)
                            at /home/username/reactor/server/lib/MessageBus.js:99:208
                            at Array.forEach (<anonymous>)
                            at MessageBus._sendToBus (/home/username/reactor/server/lib/MessageBus.js:96:47)
                            at /home/username/reactor/server/lib/MessageBus.js:109:48
                            at new Promise (<anonymous>)
                            at MessageBus.send (/home/username/reactor/server/lib/MessageBus.js:106:16)
                            at Entity.publish (/home/username/reactor/server/lib/Observable.js:71:44)
                            at Entity.deferNotifies (/home/username/reactor/server/lib/Entity.js:248:207)
                        2021-10-04T14:11:03.858Z <Engine:5:Engine.js:1108> Engine#1 var (undefined) dependency entity-changed Entity#ezlo>device_603a036e129e0715cf4a763a
                        2021-10-04T14:11:03.859Z <default:CRIT> Error: Object does not exist
                        Error: Object does not exist
                        
                        1 Reply Last reply Reply Quote 0
                        • toggledbits
                          toggledbits last edited by

                          Is this on 21275?

                          Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                          Crille 1 Reply Last reply Reply Quote 0
                          • Crille
                            Crille @toggledbits last edited by Crille

                            @toggledbits Sorry, yes. latest-21275-df3d784

                            1 Reply Last reply Reply Quote 0
                            • toggledbits
                              toggledbits last edited by

                              OK. I think I see this. I was at least able to reproduce one case. It's not to do with deleting global variables, or global variables at all, really; it. It has to do with the subcontexts that are created by lexpjs in each statements, and the MSR Engine looking for private data in the current context and not realizing that it was operating from a subcontext. And in this case, it was your rule expression that exposed the problem. Sounds messy, but not hard to fix. I think.

                              Build coming later today.

                              FYI, just an observation on what you're doing in this rule expression:

                              join(each name in (each id in (matchEntities( { controller: 'ezlo', capability: 'x_ezlo_device' } )):
                                  getEntity( id ).attributes.x_ezlo_device.reachable == false ? id : null ):
                                      getEntity( name ).name, ', ' )
                              

                              If you use a compound statement (do...done) as the body of a single each loop, and store the getEntity() result in a temporary variable, you only need one loop, it looks a bit cleaner, and runs a lot faster (because you're only fetching the entity once):

                              join( 
                                each id in matchEntities( { controller: 'ezlo', capability: 'x_ezlo_device' } ): do
                                  e=getEntity( id ), 
                                  e.attributes.x_ezlo_device.reachable ? null : e.name
                                done, ", " )
                              

                              This compound statement loop first stores the result of getEntity() into a variable e. This variable, since it is being defined by the loop, can only be used within the loop. But, as you can see on the next line, it can be used both to make the reachable test, and to return name as the loop body result for each. Also note that since the reachable attribute is already a boolean, you can use it directly (without a comparison against another boolean), you just need to reverse the ternary operands (so when reachable is true, null is returned, and when not reachable, the entity name is returned).

                              Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                              Crille 1 Reply Last reply Reply Quote 0
                              • Crille
                                Crille @toggledbits last edited by Crille

                                @toggledbits Ok, great explanation!
                                I do like cleaner expressions and will absolutely switch to do...done, thank you for the example.
                                I knew it was doing double gets but each run took 0ms so I did not bother, but optimization is always welcomed.

                                FYI: I have some devices paired that are not usable yet and they return x_ezlo_device.reachable=null so until they are integrated correctly I'll keep the boolean comparison for now.

                                1 Reply Last reply Reply Quote 1
                                • N
                                  noelab last edited by noelab

                                  Hi, updated MSR latest-21281-c4807c0
                                  I have connection with ezloplus in set_anonymous_access: true

                                  MSR starts to be connected and disconnected.
                                  Ezlo is not connected
                                  sys_system.state=false

                                  `

                                  [latest-21281]2021-10-08T20:29:30.398Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                  [latest-21281]2021-10-08T20:29:33.849Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                  [latest-21281]2021-10-08T20:29:33.850Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                  [latest-21281]2021-10-08T20:29:33.850Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                  [latest-21281]2021-10-08T20:29:38.850Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                  [latest-21281]2021-10-08T20:29:38.851Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                  [latest-21281]2021-10-08T20:29:38.851Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                  [latest-21281]2021-10-08T20:29:59.226Z <Structure:WARN> Structure#1 promiseEntity(ezlo>housemode,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.227Z <Rule:CRIT> Rule#rule-ks210svp failed subscription to ezlo>housemode
                                  [latest-21281]2021-10-08T20:29:59.227Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.251Z <Structure:WARN> Structure#1 promiseEntity(ezlo>housemode,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.251Z <Rule:CRIT> Rule#rule-ks210svp failed subscription to ezlo>housemode
                                  [latest-21281]2021-10-08T20:29:59.252Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.252Z <Rule:5:Rule.js:704> Rule#rule-ks210svp start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.252Z <Rule:5:Rule.js:982> Rule#rule-ks210svp (v0 Function DayMode OverNight) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.252Z <Rule:5:Rule.js:986> Rule#rule-ks210svp._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.253Z <Rule:5:Rule.js:990> Rule#rule-ks210svp update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.253Z <Rule:5:Rule.js:914> Rule#rule-ks210svp evaluateExpressions() with 0 expressions
                                  [latest-21281]2021-10-08T20:29:59.254Z <Rule:5:Rule.js:1002> Rule#rule-ks210svp._evaluate() trigger state now false (was false)
                                  [latest-21281]2021-10-08T20:29:59.259Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>housemode
                                  ReferenceError: Can't find entity ezlo>housemode
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1294:27)
                                      at Rule._evaluateGroup (/opt/reactor/server/lib/Rule.js:1658:99)
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1283:47)
                                      at Rule._evaluateConstraints (/opt/reactor/server/lib/Rule.js:1689:42)
                                      at Rule._evaluate (/opt/reactor/server/lib/Rule.js:1003:55)
                                      at processTicksAndRejections (internal/process/task_queues.js:95:5)
                                      at async /opt/reactor/server/lib/Rule.js:969:17
                                  [latest-21281]2021-10-08T20:29:59.261Z <Structure:WARN> Structure#1 promiseEntity(ezlo>device_613e233f129e2912114c0941,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.262Z <Rule:CRIT> Rule#rule-ktmit785 failed subscription to ezlo>device_613e233f129e2912114c0941
                                  [latest-21281]2021-10-08T20:29:59.262Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.262Z <Rule:5:Rule.js:704> Rule#rule-ktmit785 start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.262Z <Rule:5:Rule.js:982> Rule#rule-ktmit785 (vT DLT 1 Bulb ID ) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.263Z <Rule:5:Rule.js:986> Rule#rule-ktmit785._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.263Z <Rule:5:Rule.js:990> Rule#rule-ktmit785 update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.263Z <Rule:5:Rule.js:914> Rule#rule-ktmit785 evaluateExpressions() with 0 expressions
                                  [latest-21281]2021-10-08T20:29:59.279Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>device_613e233f129e2912114c0941
                                  ReferenceError: Can't find entity ezlo>device_613e233f129e2912114c0941
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1294:27)
                                      at Rule._evaluateGroup (/opt/reactor/server/lib/Rule.js:1658:99)
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1283:47)
                                      at Rule._evaluateTriggers (/opt/reactor/server/lib/Rule.js:1675:38)
                                      at Rule._evaluate (/opt/reactor/server/lib/Rule.js:1001:55)
                                      at processTicksAndRejections (internal/process/task_queues.js:95:5)
                                      at async /opt/reactor/server/lib/Rule.js:969:17
                                  [latest-21281]2021-10-08T20:29:59.280Z <Structure:WARN> Structure#1 promiseEntity(ezlo>device_613e2b02129e2912114c0993,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.280Z <Rule:CRIT> Rule#rule-kthqmgb6 failed subscription to ezlo>device_613e2b02129e2912114c0993
                                  [latest-21281]2021-10-08T20:29:59.280Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.280Z <Rule:5:Rule.js:704> Rule#rule-kthqmgb6 start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.281Z <Rule:5:Rule.js:982> Rule#rule-kthqmgb6 (vR4 DLT 1 Bulb ID ) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.281Z <Rule:5:Rule.js:986> Rule#rule-kthqmgb6._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.281Z <Rule:5:Rule.js:990> Rule#rule-kthqmgb6 update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.282Z <Rule:5:Rule.js:914> Rule#rule-kthqmgb6 evaluateExpressions() with 0 expressions
                                  [latest-21281]2021-10-08T20:29:59.284Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>device_613e2b02129e2912114c0993
                                  ReferenceError: Can't find entity ezlo>device_613e2b02129e2912114c0993
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1294:27)
                                      at Rule._evaluateGroup (/opt/reactor/server/lib/Rule.js:1658:99)
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1283:47)
                                      at Rule._evaluateTriggers (/opt/reactor/server/lib/Rule.js:1675:38)
                                      at Rule._evaluate (/opt/reactor/server/lib/Rule.js:1001:55)
                                      at processTicksAndRejections (internal/process/task_queues.js:95:5)
                                      at runNextTicks (internal/process/task_queues.js:64:3)
                                      at listOnTimeout (internal/timers.js:526:9)
                                      at processTimers (internal/timers.js:500:7)
                                      at async /opt/reactor/server/lib/Rule.js:969:17
                                  [latest-21281]2021-10-08T20:29:59.285Z <Structure:WARN> Structure#1 promiseEntity(ezlo>device_613e2959129e2912114c098f,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.285Z <Rule:CRIT> Rule#rule-kthqpda8 failed subscription to ezlo>device_613e2959129e2912114c098f
                                  [latest-21281]2021-10-08T20:29:59.286Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.286Z <Rule:5:Rule.js:704> Rule#rule-kthqpda8 start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.286Z <Rule:5:Rule.js:982> Rule#rule-kthqpda8 (vR4 DLT 3 Lux ID  ) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.287Z <Rule:5:Rule.js:986> Rule#rule-kthqpda8._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.287Z <Rule:5:Rule.js:990> Rule#rule-kthqpda8 update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.287Z <Rule:5:Rule.js:914> Rule#rule-kthqpda8 evaluateExpressions() with 1 expressions
                                  [latest-21281]2021-10-08T20:29:59.290Z <Rule:ERR> Rule#rule-kthqpda8: error evaluating expression test: TypeError: Cannot read property 'log' of null
                                  [latest-21281]2021-10-08T20:29:59.290Z <Rule:ERR> Rule#rule-kthqpda8: expression: round((abs(int( getEntity( "ezlo>device_613e2959129e2912114c098f" ).attributes.light_sensor.value ) * (100/300) -100) - int((  getEntity( "ezlo>device_613e2959129e2912114c098f" ).attributes.light_sensor.value  * (100/300) ) - 100))/2)
                                  [latest-21281]2021-10-08T20:29:59.291Z <Rule:CRIT> TypeError: Cannot read property 'log' of null
                                  TypeError: Cannot read property 'log' of null
                                      at _0x2f8d77 (/opt/reactor/server/lib/Engine.js:984:21)
                                      at _run (/opt/reactor/common/lexp.js:1383:34)
                                      at _run (/opt/reactor/common/lexp.js:1338:33)
                                      at _run (/opt/reactor/common/lexp.js:1338:33)
                                      at _run (/opt/reactor/common/lexp.js:1338:33)
                                      at /opt/reactor/common/lexp.js:1381:33
                                      at Array.forEach (<anonymous>)
                                      at _run (/opt/reactor/common/lexp.js:1380:28)
                                      at _run (/opt/reactor/common/lexp.js:1208:34)
                                      at _run (/opt/reactor/common/lexp.js:1208:34)
                                  [latest-21281]2021-10-08T20:29:59.295Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>device_613e2959129e2912114c098f
                                  ReferenceError: Can't find entity ezlo>device_613e2959129e2912114c098f
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1294:27)
                                      at Rule._evaluateGroup (/opt/reactor/server/lib/Rule.js:1658:99)
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1283:47)
                                      at Rule._evaluateTriggers (/opt/reactor/server/lib/Rule.js:1675:38)
                                      at Rule._evaluate (/opt/reactor/server/lib/Rule.js:1001:55)
                                      at processTicksAndRejections (internal/process/task_queues.js:95:5)
                                      at runNextTicks (internal/process/task_queues.js:64:3)
                                      at listOnTimeout (internal/timers.js:526:9)
                                      at processTimers (internal/timers.js:500:7)
                                      at async /opt/reactor/server/lib/Rule.js:969:17
                                  [latest-21281]2021-10-08T20:29:59.296Z <Structure:WARN> Structure#1 promiseEntity(ezlo>device_613e2959129e2912114c0982,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.296Z <Rule:CRIT> Rule#rule-kthqljcu failed subscription to ezlo>device_613e2959129e2912114c0982
                                  [latest-21281]2021-10-08T20:29:59.296Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.296Z <Rule:5:Rule.js:704> Rule#rule-kthqljcu start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.297Z <Rule:5:Rule.js:982> Rule#rule-kthqljcu (vR4 DLT 2 Motion ID ) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.297Z <Rule:5:Rule.js:986> Rule#rule-kthqljcu._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.297Z <Rule:5:Rule.js:990> Rule#rule-kthqljcu update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.297Z <Rule:5:Rule.js:914> Rule#rule-kthqljcu evaluateExpressions() with 0 expressions
                                  [latest-21281]2021-10-08T20:29:59.299Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>device_613e2959129e2912114c0982
                                  ReferenceError: Can't find entity ezlo>device_613e2959129e2912114c0982
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1294:27)
                                      at Rule._evaluateGroup (/opt/reactor/server/lib/Rule.js:1658:99)
                                      at Rule._evaluateCondition (/opt/reactor/server/lib/Rule.js:1283:47)
                                      at Rule._evaluateTriggers (/opt/reactor/server/lib/Rule.js:1675:38)
                                      at Rule._evaluate (/opt/reactor/server/lib/Rule.js:1001:55)
                                      at processTicksAndRejections (internal/process/task_queues.js:95:5)
                                      at runNextTicks (internal/process/task_queues.js:64:3)
                                      at listOnTimeout (internal/timers.js:526:9)
                                      at processTimers (internal/timers.js:500:7)
                                      at async /opt/reactor/server/lib/Rule.js:969:17
                                  [latest-21281]2021-10-08T20:29:59.300Z <Structure:WARN> Structure#1 promiseEntity(ezlo>device_614e0c2f129e29124dfcd825,30000) timeout!
                                  [latest-21281]2021-10-08T20:29:59.300Z <Rule:CRIT> Rule#rule-ktpv9g18 failed subscription to ezlo>device_614e0c2f129e29124dfcd825
                                  [latest-21281]2021-10-08T20:29:59.300Z <Rule:CRIT> !timeout
                                  [latest-21281]2021-10-08T20:29:59.301Z <Rule:5:Rule.js:704> Rule#rule-ktpv9g18 start() dependencies resolved, performing initial evaluation
                                  [latest-21281]2021-10-08T20:29:59.301Z <Rule:5:Rule.js:982> Rule#rule-ktpv9g18 (vR3 DLT 1 Bulb ID) evaluate() acquiring mutex
                                  [latest-21281]2021-10-08T20:29:59.301Z <Rule:5:Rule.js:986> Rule#rule-ktpv9g18._evaluate() mutex acquired, evaluating
                                  [latest-21281]2021-10-08T20:29:59.301Z <Rule:5:Rule.js:990> Rule#rule-ktpv9g18 update rate is 0/min limit 60/min
                                  [latest-21281]2021-10-08T20:29:59.301Z <Rule:5:Rule.js:914> Rule#rule-ktpv9g18 evaluateExpressions() with 0 expressions
                                  [latest-21281]2021-10-08T20:29:59.304Z <Rule:CRIT> ReferenceError: Can't find entity ezlo>device_614e0c2f129e29124dfcd825
                                  

                                  `

                                  N 1 Reply Last reply Reply Quote 0
                                  • N
                                    noelab @noelab last edited by

                                    @noelab

                                    [latest-21281]2021-10-08T20:37:59.635Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:38:06.565Z <Rule:5:Rule.js:763> Rule#rule-ks56pa4y dependency notification timer-trigger Timer#rule-ks56pa4y from Timer#rule-ks56pa4y
                                    [latest-21281]2021-10-08T20:38:06.566Z <Rule:5:Rule.js:769> Rule#rule-ks56pa4y requesting eval; timer-trigger Timer#rule-ks56pa4y
                                    [latest-21281]2021-10-08T20:38:06.566Z <Rule:5:Rule.js:982> Rule#rule-ks56pa4y (vK DLT 8 Delay OFF ) evaluate() acquiring mutex
                                    [latest-21281]2021-10-08T20:38:06.569Z <Rule:5:Rule.js:986> Rule#rule-ks56pa4y._evaluate() mutex acquired, evaluating
                                    [latest-21281]2021-10-08T20:38:06.570Z <Rule:5:Rule.js:990> Rule#rule-ks56pa4y update rate is 0/min limit 60/min
                                    [latest-21281]2021-10-08T20:38:06.570Z <Rule:5:Rule.js:914> Rule#rule-ks56pa4y evaluateExpressions() with 0 expressions
                                    [latest-21281]2021-10-08T20:38:06.571Z <Rule:5:Rule.js:1650> cond condcxc7czr evaluation state false->true
                                    [latest-21281]2021-10-08T20:38:06.576Z <Rule:5:Rule.js:1002> Rule#rule-ks56pa4y._evaluate() trigger state now false (was false)
                                    [latest-21281]2021-10-08T20:38:06.576Z <Rule:5:Rule.js:1004> Rule#rule-ks56pa4y._evaluate() constraints state true
                                    [latest-21281]2021-10-08T20:38:06.576Z <Rule:5:Rule.js:1013> Rule#rule-ks56pa4y rule state now false, changed no
                                    [latest-21281]2021-10-08T20:38:07.815Z <Rule:5:Rule.js:763> Rule#rule-ktrefqfy dependency notification timer-trigger Timer#rule-ktrefqfy from Timer#rule-ktrefqfy
                                    [latest-21281]2021-10-08T20:38:07.815Z <Rule:5:Rule.js:769> Rule#rule-ktrefqfy requesting eval; timer-trigger Timer#rule-ktrefqfy
                                    [latest-21281]2021-10-08T20:38:07.816Z <Rule:5:Rule.js:982> Rule#rule-ktrefqfy (vH DLT 8 Delay OFF  ) evaluate() acquiring mutex
                                    [latest-21281]2021-10-08T20:38:07.816Z <Rule:5:Rule.js:986> Rule#rule-ktrefqfy._evaluate() mutex acquired, evaluating
                                    [latest-21281]2021-10-08T20:38:07.816Z <Rule:5:Rule.js:990> Rule#rule-ktrefqfy update rate is 0/min limit 60/min
                                    [latest-21281]2021-10-08T20:38:07.816Z <Rule:5:Rule.js:914> Rule#rule-ktrefqfy evaluateExpressions() with 0 expressions
                                    [latest-21281]2021-10-08T20:38:07.817Z <Rule:5:Rule.js:1650> cond condcxc7czr evaluation state false->true
                                    [latest-21281]2021-10-08T20:38:07.818Z <Rule:5:Rule.js:1002> Rule#rule-ktrefqfy._evaluate() trigger state now false (was false)
                                    [latest-21281]2021-10-08T20:38:07.818Z <Rule:5:Rule.js:1004> Rule#rule-ktrefqfy._evaluate() constraints state true
                                    [latest-21281]2021-10-08T20:38:07.818Z <Rule:5:Rule.js:1013> Rule#rule-ktrefqfy rule state now false, changed no
                                    [latest-21281]2021-10-08T20:38:19.635Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:38:19.636Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:38:19.636Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:38:28.614Z <wsapi:WARN> wsapi: timed out waiting for ping reply (pong) from client "172.17.0.1#4"
                                    [latest-21281]2021-10-08T20:38:28.615Z <wsapi:INFO> client "172.17.0.1#4" closed, code=1006, reason=
                                    [latest-21281]2021-10-08T20:38:49.688Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:38:49.688Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:38:49.688Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:38:54.226Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:39:14.695Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:39:14.695Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:39:14.696Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:39:44.747Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:39:44.747Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:39:44.748Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:40:14.758Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:40:14.758Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:40:14.759Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:40:44.809Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:40:44.810Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:40:44.810Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:41:19.824Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:41:19.824Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:41:19.825Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:41:39.101Z <wsapi:WARN> wsapi: timed out waiting for ping reply (pong) from client "172.17.0.1#5"
                                    [latest-21281]2021-10-08T20:41:39.102Z <wsapi:INFO> client "172.17.0.1#5" closed, code=1006, reason=
                                    [latest-21281]2021-10-08T20:41:49.876Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:41:49.876Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:41:49.876Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:42:29.878Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:42:29.879Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:42:29.879Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:42:59.931Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:42:59.931Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:42:59.931Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:43:44.942Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:43:44.942Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:43:44.943Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:44:14.994Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:44:14.994Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:44:14.994Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:44:33.693Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:44:35.025Z <wsapi:INFO> client "172.17.0.1#6" closed, code=1001, reason=
                                    [latest-21281]2021-10-08T20:44:54.281Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:45:04.999Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:45:04.999Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:45:05.000Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:45:35.050Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:45:35.051Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:45:35.051Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:46:30.052Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:46:30.052Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:46:30.053Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:46:34.315Z <wsapi:WARN> wsapi: timed out waiting for ping reply (pong) from client "172.17.0.1#7"
                                    [latest-21281]2021-10-08T20:46:34.316Z <wsapi:INFO> client "172.17.0.1#7" closed, code=1006, reason=
                                    [latest-21281]2021-10-08T20:46:46.206Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:47:00.103Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:47:00.103Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:47:00.104Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:47:11.581Z <wsapi:INFO> client "172.17.0.1#8" closed, code=1005, reason=
                                    [latest-21281]2021-10-08T20:47:14.206Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:48:00.114Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:48:00.115Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:48:00.115Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:48:30.167Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:48:30.167Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:48:30.168Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:49:30.169Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:49:30.169Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:49:30.170Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:50:00.221Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:50:00.221Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:50:00.221Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:50:24.385Z <wsapi:WARN> wsapi: timed out waiting for ping reply (pong) from client "172.17.0.1#9"
                                    [latest-21281]2021-10-08T20:50:24.386Z <wsapi:INFO> client "172.17.0.1#9" closed, code=1006, reason=
                                    [latest-21281]2021-10-08T20:50:27.211Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:51:00.225Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:51:00.225Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:51:00.226Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:51:22.359Z <wsapi:INFO> client "172.17.0.1#10" closed, code=1001, reason=
                                    [latest-21281]2021-10-08T20:51:22.848Z <wsapi:INFO> wsapi: connection from ::ffff:172.17.0.1
                                    [latest-21281]2021-10-08T20:51:30.276Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:51:30.277Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:51:30.277Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:52:30.279Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:52:30.279Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:52:30.280Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:53:00.331Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:53:00.331Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:53:00.331Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    [latest-21281]2021-10-08T20:54:00.338Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                    [latest-21281]2021-10-08T20:54:00.338Z <Controller:INFO> EzloController#ezlo opening hub connection to "90000464" at wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:54:00.339Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                    [latest-21281]2021-10-08T20:54:30.006Z <Rule:5:Rule.js:763> Rule#rule-ktggia4q dependency notification entity-changed Entity#vera>device_719 from Entity#vera>device_719
                                    [latest-21281]2021-10-08T20:54:30.007Z <Rule:5:Rule.js:769> Rule#rule-ktggia4q requesting eval; entity-changed Entity#vera>device_719
                                    [latest-21281]2021-10-08T20:54:30.007Z <Rule:5:Rule.js:982> Rule#rule-ktggia4q (vB2 DLT 2 Motion ID) evaluate() acquiring mutex
                                    [latest-21281]2021-10-08T20:54:30.008Z <Rule:5:Rule.js:986> Rule#rule-ktggia4q._evaluate() mutex acquired, evaluating
                                    [latest-21281]2021-10-08T20:54:30.008Z <Rule:5:Rule.js:990> Rule#rule-ktggia4q update rate is 0/min limit 60/min
                                    [latest-21281]2021-10-08T20:54:30.008Z <Rule:5:Rule.js:914> Rule#rule-ktggia4q evaluateExpressions() with 0 expressions
                                    [latest-21281]2021-10-08T20:54:30.009Z <Rule:5:Rule.js:1002> Rule#rule-ktggia4q._evaluate() trigger state now false (was false)
                                    [latest-21281]2021-10-08T20:54:30.009Z <Rule:5:Rule.js:1004> Rule#rule-ktggia4q._evaluate() constraints state true
                                    [latest-21281]2021-10-08T20:54:30.009Z <Rule:5:Rule.js:1013> Rule#rule-ktggia4q rule state now false, changed no
                                    [latest-21281]2021-10-08T20:54:30.389Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                    [latest-21281]2021-10-08T20:54:30.390Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                    [latest-21281]2021-10-08T20:54:30.390Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                    
                                    
                                    1 Reply Last reply Reply Quote 0
                                    • toggledbits
                                      toggledbits last edited by toggledbits

                                      No changes to EzloController for several builds now. Mine is working great.

                                      What's your install environment?

                                      Log snippets need several dozen lines before the error in order to be useful. For controller connection issues, it's also good to capture the entire startup until a bit past the first connection failure.

                                      Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                                      1 Reply Last reply Reply Quote 0
                                      • N
                                        noelab last edited by toggledbits

                                        It's Docker on Synology

                                        [latest-21281]2021-10-08T21:17:51.677Z <app:null> Reactor latest-21281-c4807c0 starting on v14.17.3
                                        [latest-21281]2021-10-08T21:17:51.678Z <app:INFO> Process ID 1; platform linux/x64 #41890 SMP Thu Jul 15 03:37:40 CST 2021; locale (undefined)
                                        [latest-21281]2021-10-08T21:17:51.678Z <app:INFO> Basedir /opt/reactor; data in /var/reactor/storage
                                        [latest-21281]2021-10-08T21:17:51.679Z <app:INFO> NODE_PATH /opt/reactor
                                        [latest-21281]2021-10-08T21:17:51.691Z <app:INFO> Configured locale (undefined); selected locale(s) en-US.UTF-8
                                        [latest-21281]2021-10-08T21:17:51.746Z <app:INFO> Loaded locale en-US
                                        [latest-21281]2021-10-08T21:17:51.880Z <Plugin:null> Module Plugin v21173
                                        [latest-21281]2021-10-08T21:17:51.888Z <default:INFO> Module Entity v21260
                                        [latest-21281]2021-10-08T21:17:51.891Z <Controller:null> Module Controller v21278
                                        [latest-21281]2021-10-08T21:17:51.891Z <default:null> Module Structure v21270
                                        [latest-21281]2021-10-08T21:17:51.900Z <default:null> Module Ruleset v21096
                                        [latest-21281]2021-10-08T21:17:51.900Z <default:null> Module Rulesets v21096
                                        [latest-21281]2021-10-08T21:17:51.922Z <default:null> Module Rule v21278
                                        [latest-21281]2021-10-08T21:17:51.978Z <default:null> Module Engine v21277
                                        [latest-21281]2021-10-08T21:17:51.978Z <default:null> Module httpapi v21278
                                        [latest-21281]2021-10-08T21:17:51.987Z <default:null> Module httpproxy v21054
                                        [latest-21281]2021-10-08T21:17:52.004Z <default:null> Module wsapi v21274
                                        [latest-21281]2021-10-08T21:17:52.075Z <app:NOTICE> Starting Structure...
                                        [latest-21281]2021-10-08T21:17:52.079Z <Structure:NOTICE> Structure#1 plugin ID influx disabled; skipping
                                        [latest-21281]2021-10-08T21:17:52.081Z <Structure:INFO> Structure#1 starting controller interface vera (VeraController)
                                        [latest-21281]2021-10-08T21:17:52.085Z <Structure:INFO> Structure#1 starting controller interface ezlo (EzloController)
                                        [latest-21281]2021-10-08T21:17:52.086Z <Structure:INFO> Structure#1 starting controller interface weather (OWMWeatherController)
                                        [latest-21281]2021-10-08T21:17:52.087Z <Structure:INFO> Structure#1 starting controller interface reactor_system (SystemController)
                                        [latest-21281]2021-10-08T21:17:52.173Z <default:null> Module VeraController v21271
                                        [latest-21281]2021-10-08T21:17:52.180Z <default:null> Module EzloController v21274
                                        [latest-21281]2021-10-08T21:17:52.183Z <default:null> Module OWMWeatherController v21278
                                        [latest-21281]2021-10-08T21:17:52.184Z <default:null> Module SystemController v21102
                                        [latest-21281]2021-10-08T21:17:52.192Z <VeraController:NOTICE> VeraController#vera starting
                                        [latest-21281]2021-10-08T21:17:52.246Z <VeraController:INFO> VeraController#vera loaded mapping ver 21274 rev 1 format 1 notice 
                                        [latest-21281]2021-10-08T21:17:52.247Z <VeraController:INFO> VeraController: deviceclass vera_system_object capability sys_system does not provide attribute state
                                        [latest-21281]2021-10-08T21:17:52.295Z <EzloController:null> EzloController#ezlo created, config { "source": "wss://10.0.4.119:17000", "serial": "XXXXXXXXXX" }
                                        [latest-21281]2021-10-08T21:17:52.295Z <EzloController:null> EzloController#ezlo instance log level (null) (4)
                                        [latest-21281]2021-10-08T21:17:52.314Z <Controller:INFO> EzloController#ezlo device mapping data loaded; checking...
                                        [latest-21281]2021-10-08T21:17:52.316Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                        [latest-21281]2021-10-08T21:17:52.346Z <Controller:NOTICE> Controller SystemController#reactor_system is now online.
                                        [latest-21281]2021-10-08T21:17:52.374Z <Controller:INFO> EzloController#ezlo opening hub connection to "XXXXXXXXXX" at wss://10.0.4.119:17000
                                        [latest-21281]2021-10-08T21:17:52.376Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                        [latest-21281]2021-10-08T21:17:52.381Z <app:INFO> Structure running; pausing for controllers' initial ready
                                        [latest-21281]2021-10-08T21:17:52.632Z <OWMWeatherController:INFO> OWMWeatherController#weather done; 1 locations, 0 failed
                                        [latest-21281]2021-10-08T21:17:52.634Z <OWMWeatherController:NOTICE> Controller OWMWeatherController#weather is now online.
                                        [latest-21281]2021-10-08T21:17:53.307Z <VeraController:NOTICE> Controller VeraController#vera is now online.
                                        [latest-21281]2021-10-08T21:18:22.427Z <Controller:WARN> EzloController#ezlo websocket error during open/negotation: Error: WebSocket was closed before the connection was established
                                        [latest-21281]2021-10-08T21:18:22.428Z <Controller:ERR> EzloController#ezlo failed to connect websocket to wss://10.0.4.119:17000: TimedPromise timeout
                                        [latest-21281]2021-10-08T21:18:22.429Z <Controller:NOTICE> EzloController#ezlo websocket to wss://10.0.4.119:17000 closed during open/negotiation
                                        [latest-21281]2021-10-08T21:18:27.433Z <Controller:INFO> EzloController#ezlo performing hub login without cloud authentication (hub.offline.anonymous_access must be enabled)
                                        [latest-21281]2021-10-08T21:18:27.433Z <Controller:INFO> EzloController#ezlo opening hub connection to "XXXXXXXXXX" at wss://10.0.4.119:17000
                                        [latest-21281]2021-10-08T21:18:27.434Z <Controller:NOTICE> EzloController#ezlo connecting via WS to wss://10.0.4.119:17000
                                        [latest-21281]2021-10-08T21:18:52.386Z <app:NOTICE> Starting HTTP server and API...
                                        [latest-21281]2021-10-08T21:18:52.392Z <app:NOTICE> Starting Reaction Engine...
                                        [latest-21281]2021-10-08T21:18:52.393Z <Engine:INFO> Reaction Engine starting
                                        [latest-21281]2021-10-08T21:18:52.393Z <Engine:INFO> Checking rule sets...
                                        [latest-21281]2021-10-08T21:18:52.445Z <Engine:INFO> Checking rules...
                                        [latest-21281]2021-10-08T21:18:52.446Z <Engine:INFO> Data check complete; no corrections.
                                        [latest-21281]2021-10-08T21:18:52.485Z <Engine:5:Engine.js:1350> _process_reaction_queue() entry 630
                                        [latest-21281]2021-10-08T21:18:52.500Z <Rule:5:Rule.js:623> Rule#rule-kuhickgs cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.501Z <Engine:5:Engine.js:886> Engine: new rule rule-kuhickgs ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.522Z <Rule:5:Rule.js:623> Rule#rule-ku1myjlz cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.522Z <Engine:5:Engine.js:886> Engine: new rule rule-ku1myjlz ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.534Z <Rule:5:Rule.js:623> Rule#rule-ks5pci0k cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.534Z <Engine:5:Engine.js:886> Engine: new rule rule-ks5pci0k ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.536Z <Rule:5:Rule.js:623> Rule#rule-ks5pdqcs cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.536Z <Engine:5:Engine.js:886> Engine: new rule rule-ks5pdqcs ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.537Z <Rule:5:Rule.js:623> Rule#rule-ks5pbeg9 cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.538Z <Engine:5:Engine.js:886> Engine: new rule rule-ks5pbeg9 ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.539Z <Rule:5:Rule.js:623> Rule#rule-ks5p8t6m cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.539Z <Engine:5:Engine.js:886> Engine: new rule rule-ks5p8t6m ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.540Z <Rule:5:Rule.js:623> Rule#rule-ks3j24qn cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.541Z <Engine:5:Engine.js:886> Engine: new rule rule-ks3j24qn ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.549Z <Rule:5:Rule.js:623> Rule#rule-ktrlog1t cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.549Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlog1t ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.550Z <Rule:5:Rule.js:623> Rule#rule-ktrlox2g cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.550Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlox2g ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.551Z <Rule:5:Rule.js:623> Rule#rule-ktrlp04x cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.552Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlp04x ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.553Z <Rule:5:Rule.js:623> Rule#rule-ktrlp2cn cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.553Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlp2cn ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.554Z <Rule:5:Rule.js:623> Rule#rule-ktrlp4il cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.555Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlp4il ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.556Z <Rule:5:Rule.js:623> Rule#rule-ktrlp6j9 cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.556Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlp6j9 ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.557Z <Rule:5:Rule.js:623> Rule#rule-ktrlp8v2 cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.557Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlp8v2 ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.558Z <Rule:5:Rule.js:623> Rule#rule-ktrlpbmt cleaning loaded condition states
                                        [latest-21281]2021-10-08T21:18:52.558Z <Engine:5:Engine.js:886> Engine: new rule rule-ktrlpbmt ((undefined)), creating!
                                        [latest-21281]2021-10-08T21:18:52.559Z <Rule:5:Rule.js:623> Rule#rule-ktrlpdzf cleaning loaded condition states
                                        
                                        1 Reply Last reply Reply Quote 0
                                        • toggledbits
                                          toggledbits last edited by

                                          Huh. Docker container also working just fine for me, with authenticated access, with anonymous access, and with anonymous insecure access. What version of firmware is your hub? Have you tried to reboot the hub?

                                          Author of Multi-system Reactor and Reactor, DelayLight, Switchboard, and about a dozen other plugins that run on Vera and openLuup.

                                          1 Reply Last reply Reply Quote 0
                                          • N
                                            noelab last edited by

                                            Now it's working again after I powered off/on ezlo controller and restarted Reactor. The log is too long, no privileges to upload it. It's not the first time it happens upgrating the container.
                                            ezloplus Firmware: 2.0.19.1714.2
                                            Thanks anyway.

                                            [latest-21281]2021-10-08T21:55:33.176Z <Controller:INFO> EzloController#ezlo hub inventory complete/successful; 837ms
                                            [latest-21281]2021-10-08T21:55:33.179Z <Controller:NOTICE> Controller EzloController#ezlo is now online.
                                            
                                            1 Reply Last reply Reply Quote 0
                                            • Locked by  toggledbits toggledbits 
                                            • First post
                                              Last post

                                            Welcome. If you’d like to participate in the discussion, rather than just read, then you can join the forum. As a member, you can interact with others here to share your experience and ask the questions you need answered.

                                            Powered by NodeBB | Contributors
                                            Hosted freely by PointPub Media Communications Inc. | Contact us