Good morning,
I'm trying to figure out if there is a way to evaluate if a command was completed and retry if it did not complete.
I have 14 iBlinds 3.1 z-wave controllers in my home. 95% of the time, they work just fine. Occasionally, I'll get a blind that does not open on the first attempt. When I go into Home Assistant, and manually open or close the blind, it works.
I have 3 reactions set up for each room. One to open, one to close, and one partial open for sun glare. Each of them is set up as below.
5afc9924-4300-4718-9e23-8855c4a3a9fd-image.png
The reactions are set up to wait for 5 seconds before going onto the next blind, so the z-wave network doesn't get overwhelmed.
In addition, the set command to run the reactions has "Wait for completion" checked.
3919fc06-c1f1-4c49-bf95-716028d18a27-image.png
I also have a routine set up whenever a z-wave device reports as non-functional (dead), it'll get pinged to wake it up. This usually works to wake them up.
16df4bff-c733-4ec2-a55c-c964238ada3b-image.png
Appreciate any ideas to make this more reliable.
I'm running:
Reactor latest-24190-bd310acc, Bare-metal on Fedora WaveJSController [0.1.23326] Home Assistant: 2024.7.0I think this feature request could be accomplished with the use of two or more rules, but it would be great if there was a way to wait for an event or trigger to occur before continuing on in the reactions.
For example, I have a rule that will turn on some exterior lights if you arrive home after the porch lights have been turned off. Right now this rule randomly will turn off between 5-10 minutes after the person has entered the geofence. On some occasions this 5-10 minutes isn't long enough, say if you are unloading the car or something. I would like to kick off the reaction, but pause it part way through and wait for the door to close and lock, then continue it on. Hubitat Rule Machine has a "Wait for event" option, but I really want to keep all my logic within MSR.
Good morning,
I'm going through my ruleset this morning, trying to get away from haas>blahblablah entries and completely migrate them all to zwavejs>xx-0 entries where possible.
I have 3 Aeon MultiSensor 6 devices in my home, all USB powered.
When using Haas entries, I see an entry for hass>binary_sensor_guest_bedroom_multisensor_home_security_motion_detection, and motion_sensor.state (primary)
Screenshot 2024-07-25 at 8.25.53 AM.png
Under ZwaveJS, this entry appears to be missing.
Screenshot 2024-07-25 at 8.26.51 AM.png
From the Entities page:
battery_power.level=1
battery_power.since=1721910337433
binary_sensor.state=false
humidity_sensor.units="%"
humidity_sensor.value=46
light_sensor.units="Lux"
light_sensor.value=5
tamper.state=false
temperature_sensor.units="°F"
temperature_sensor.value=73.8
x_debug.dt={}
x_zwave_values.Basic_currentValue=0
x_zwave_values.Battery_isLow=false
x_zwave_values.Battery_level=100
x_zwave_values.Binary_Sensor_Any=false
x_zwave_values.Configuration_Automatic_Report_Group_1_Battery_1=1
x_zwave_values.Configuration_Automatic_Report_Group_1_Humidity_64=1
x_zwave_values.Configuration_Automatic_Report_Group_1_Luminance_128=1
x_zwave_values.Configuration_Automatic_Report_Group_1_Temperature_32=1
x_zwave_values.Configuration_Automatic_Report_Group_1_Ultraviolet_16=1
x_zwave_values.Configuration_Automatic_Report_Group_2_Battery_1=0
x_zwave_values.Configuration_Automatic_Report_Group_2_Humidity_64=0
x_zwave_values.Configuration_Automatic_Report_Group_2_Luminance_128=0
x_zwave_values.Configuration_Automatic_Report_Group_2_Temperature_32=0
x_zwave_values.Configuration_Automatic_Report_Group_2_Ultraviolet_16=0
x_zwave_values.Configuration_Automatic_Report_Group_3_Battery_1=0
x_zwave_values.Configuration_Automatic_Report_Group_3_Humidity_64=0
x_zwave_values.Configuration_Automatic_Report_Group_3_Luminance_128=0
x_zwave_values.Configuration_Automatic_Report_Group_3_Temperature_32=0
x_zwave_values.Configuration_Automatic_Report_Group_3_Ultraviolet_16=0
x_zwave_values.Configuration_Automatic_Reporting_Interval_Group_1=3600
x_zwave_values.Configuration_Automatic_Reporting_Interval_Group_2=3600
x_zwave_values.Configuration_Automatic_Reporting_Interval_Group_3=3600
x_zwave_values.Configuration_Automatic_Temperature_Reporting_Unit=2
x_zwave_values.Configuration_Battery_Level_Threshold=10
x_zwave_values.Configuration_Current_Power_Mode_65280=0
x_zwave_values.Configuration_Humidity_Above_Lower_Limit_32=0
x_zwave_values.Configuration_Humidity_Below_Lower_Limit_2=0
x_zwave_values.Configuration_Humidity_Change_Threshold=10
x_zwave_values.Configuration_Humidity_Recover_Limit=5
x_zwave_values.Configuration_Humidity_Sensor_Calibration=0
x_zwave_values.Configuration_LED_Blinking=0
x_zwave_values.Configuration_Lighting_Recover_Limit=10
x_zwave_values.Configuration_Lock_Configuration=0
x_zwave_values.Configuration_Low_Battery_Threshold=20
x_zwave_values.Configuration_Low_Temperature_Alarm_15_C=0
x_zwave_values.Configuration_Lower_Humidity_Limit=50
x_zwave_values.Configuration_Lower_Lighting_Limit=100
x_zwave_values.Configuration_Lower_Temperature_Limit_4294901760=320
x_zwave_values.Configuration_Lower_Temperature_Limit_Unit_3840=2
x_zwave_values.Configuration_Lower_Ultraviolet_Limit=4
x_zwave_values.Configuration_Luminance_Above_Lower_Limit_64=0
x_zwave_values.Configuration_Luminance_Below_Lower_Limit_4=0
x_zwave_values.Configuration_Luminance_Change_Threshold=100
x_zwave_values.Configuration_Luminance_Sensor_Calibration=0
x_zwave_values.Configuration_Motion_Sensor_Report_Type_to_Send=2
x_zwave_values.Configuration_PIR_Sensitivity=3
x_zwave_values.Configuration_PIR_Sensor_Timeout=20
x_zwave_values.Configuration_Recover_Limit_Temperature_Unit_255=2
x_zwave_values.Configuration_Report_Above_Humidity_Threshold_32=0
x_zwave_values.Configuration_Report_Above_Luminance_Threshold_64=0
x_zwave_values.Configuration_Report_Above_Temperature_Threshold_16=0
x_zwave_values.Configuration_Report_Above_Ultraviolet_Threshold_128=0
x_zwave_values.Configuration_Report_Below_Humidity_Threshold_2=0
x_zwave_values.Configuration_Report_Below_Luminance_Threshold_4=0
x_zwave_values.Configuration_Report_Below_Temperature_Threshold_1=0
x_zwave_values.Configuration_Report_Below_Ultraviolet_Threshold_8=0
x_zwave_values.Configuration_Reset_Parameters_101_103_to_Default_Values=null
x_zwave_values.Configuration_Reset_Parameters_111_113_to_Default_Values=null
x_zwave_values.Configuration_Reset_to_Factory_Default_Setting=null
x_zwave_values.Configuration_Selective_Reporting=0
x_zwave_values.Configuration_Sleep_State_255=2
x_zwave_values.Configuration_Temperature_Above_Lower_Limit_16=0
x_zwave_values.Configuration_Temperature_Below_Lower_Limit_1=0
x_zwave_values.Configuration_Temperature_Calibration_Offset_65280=0
x_zwave_values.Configuration_Temperature_Calibration_Unit_255=2
x_zwave_values.Configuration_Temperature_Change_Threshold_4294901760=20
x_zwave_values.Configuration_Temperature_Recover_Limit_65280=20
x_zwave_values.Configuration_Temperature_Threshold_Unit_3840=2
x_zwave_values.Configuration_Ultraviolet_Above_Lower_Limit_128=0
x_zwave_values.Configuration_Ultraviolet_Below_Lower_Limit_8=0
x_zwave_values.Configuration_Ultraviolet_Change_Threshold=2
x_zwave_values.Configuration_Ultraviolet_Recover_Limit=2
x_zwave_values.Configuration_Ultraviolet_Sensor_Calibration=0
x_zwave_values.Configuration_Upper_Humidity_Limit=60
x_zwave_values.Configuration_Upper_Lighting_Limit=1000
x_zwave_values.Configuration_Upper_Temperature_Limit_4294901760=824
x_zwave_values.Configuration_Upper_Temperature_Limit_Unit_3840=2
x_zwave_values.Configuration_Upper_Ultraviolet_Limit=8
x_zwave_values.Configuration_Wake_Device_for_10_minutes_After_Power_On=1
x_zwave_values.Configuration_Wake_Up_Timeout=15
x_zwave_values.Manufacturer_Specific_manufacturerId=134
x_zwave_values.Manufacturer_Specific_productId=100
x_zwave_values.Manufacturer_Specific_productType=258
x_zwave_values.Multilevel_Sensor_Air_temperature=73.8
x_zwave_values.Multilevel_Sensor_Humidity=46
x_zwave_values.Multilevel_Sensor_Illuminance=5
x_zwave_values.Multilevel_Sensor_Ultraviolet=0
x_zwave_values.Notification_Home_Security_Cover_status=0
x_zwave_values.Notification_Home_Security_Motion_sensor_status=0
x_zwave_values.Notification_alarmLevel=0
x_zwave_values.Notification_alarmType=0
x_zwave_values.Version_firmwareVersions=["1.17"]
x_zwave_values.Version_hardwareVersion=100
x_zwave_values.Version_libraryType=3
x_zwave_values.Version_protocolVersion="4.54"
x_zwave_values.Wake_Up_controllerNodeId=1
x_zwave_values.Wake_Up_wakeUpInterval=3600
zwave_device.capabilities=[32,48,49,112,113,114,128,132,134]
zwave_device.endpoint=0
zwave_device.failed=false
zwave_device.generic_class="Multilevel Sensor"
zwave_device.impl_sig="23326:1:22315:1"
zwave_device.is_beaming=false
zwave_device.is_listening=true
zwave_device.is_routing=true
zwave_device.is_secure=false
zwave_device.manufacturer_info=[134,258,100]
zwave_device.max_data_rate=null
zwave_device.node_id=53
zwave_device.specific_class="Routing Multilevel Sensor"
zwave_device.status=4
zwave_device.status_text="alive"
zwave_device.version_info=[null,"1.17"]
zwave_device.wakeup_interval=3600
I'm running:
Reactor latest-24190-bd310acc, Bare-metal on Fedora
WaveJSController [0.1.23326]
Home Assistant: 2024.7.0
I'm fetching certain data five past every hour, but I would like to do it closer to the hour, e.g. 1 or 2 past (but not at the hour).
I experimented with the following rule that almost works (triggers also at the hour which is not the intention). Any advice for a solution?
It would be nice to have an ability to bookmark a direct link to a dashboard item. In my case I would use this feature to access a virtual switch directly.
Hi @toggledbits
Would you please consider adding an extra sublevel in the rulesets?
I have grouped my rules in rooms/ areas. This works great for me, but I would also like to group rules for the same functionality (in a room). This would make the rules easier to find and name.
Please let me know if this is an option. Thanks!
@togglebits I am curious as to why the tilt_sensor.state (primary) = NULL. I believe it should show true or false. I have to use binary_sensor.state instead in my rules.
Again, not sure if this is related to Reactor/ZwaveJSController implementation or the actual Z-Wave JS UI docker version. I have copied, below, the attributes of the tilt sensor in hopes it can help.
Thanks in advance.
Reactor version 23302
ZWaveJSController version 23254
Z-Wave JS UI version 9.3.0.724519f
zwave-js version 12.2.3
@toggledbits,
I have this device attached to my system, but use a DSC panel. If you need testers to move forward, I'm happy to help.
I'm curious what your thinking the use case is for this. I currently have it integrated into HomeAssistant, and it works fine for the most part. The one thing I can't do is bypass zones, which I would like to have the ability to do.
Are you looking at more direct control for the panel, as opposed to having to jump through HA (or another system) first?
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.I have the following ruleset which I though had been working well until this morning when I noticed it's not.
I've put four weather conditions in an in array and one of them is the current weather condition - but the rule is not true. Now the cloud cover percentage is not yet met but this is an or rule so as long as the "Current Conditions" are met then it should go true.
What's the obvious thing I'm missing here? (I've tried spaces/no spaces in the in and no difference.)
Hi,
Running the latest MSR latest-24152-3455578a with the latest HA 2024.6.1. When trying to call a service I get the following in the MSR logs. Is this a version mismatch? I am not seeing anything in the HA logs.
[latest-24152]2024-06-11T10:29:56.162Z <Rule:INFO> rule-Monitor-DHW (rule-lsvq5k3x in Central Heating) started [latest-24152]2024-06-11T10:29:58.625Z <HassController:WARN> HassController#hass unknown service opentherm_gw.set_hot_water_setpoint in x_hass.call_service action on Thermostat#hass>climate_living_room_otgw [latest-24152]2024-06-11T10:29:58.626Z <HassController:INFO> HassController#hass: sending payload for x_hass.call_service on Thermostat#hass>climate_living_room_otgw action: [Object]{ "type": "call_service", "service_data": { "gateway_id": "living_room_otgw", "temperature": 65 }, "domain": "opentherm_gw", "service": "set_hot_water_setpoint", "target": { "entity_id": "climate.living_room_otgw" } } [latest-24152]2024-06-11T10:29:58.627Z <HassController:ERR> HassController#hass request 1718101798626<6/11/2024, 12:29:58 PM> (call_service) failed: [Object]{ "id": 1718101798626, "type": "result", "success": false, "error": { "code": "invalid_format", "message": "extra keys not allowed @ data['entity_id']" } } [latest-24152]2024-06-11T10:29:58.627Z <HassController:WARN> HassController#hass action x_hass.call_service([Object]{ "service": "opentherm_gw.set_hot_water_setpoint", "data": "{ \"gateway_id\": \"living_room_otgw\", \"temperature\": 65 }" }) on Thermostat#hass>climate_living_room_otgw failed!Cheers Rene
Some background
I'm trying to integrate a Zigbee device into the MSR using zigbee2mqtt bridge and MQTTController. The device in question is a cheap mood light that has following properties that I'd like to control:
I'v already managed to get the switch part working and can toggle the light on/off. Also the brightness value is mapped back to MSR. In zigbee2mqtt it has a value range from 0 to 254, so this the reason for the expression:
expr: 'payload.brightness / 254'Here's the entity definition (don't know whether the type should be something else than the Switch)
zigbee-lidl-mood-light: name: 'Lidl Mood Light' friendly_name: 'Mood Light' type: Switch uses_template: lidl-moodlightAnd the corresponding template (NOTE: rgb_color has not been defined in this example):
lidl-moodlight: init: "zigbee2mqtt/%friendly_name%/get/state" query: "zigbee2mqtt/%friendly_name%/get/state" capabilities: - power_switch - toggle - dimming primary_attribute: power_switch.state events: "zigbee2mqtt/%friendly_name%": "power_switch.state": json_payload: true expr: 'upper(payload.state) == "ON"' "dimming.level": json_payload: true expr: 'payload.brightness / 254' actions: power_switch: "on": topic: "zigbee2mqtt/%friendly_name%/set/state" payload: 'ON' "off": topic: "zigbee2mqtt/%friendly_name%/set/state" payload: 'OFF' set: topic: "zigbee2mqtt/%friendly_name%/set/state" payload: expr: "parameters.state ? 'ON' : 'OFF'" type: raw toggle: topic: "zigbee2mqtt/%friendly_name%/set/state" payload: 'TOGGLE'The problem
In order to control the brightness or the RGB color values, I would have send a JSON payload in corresponding actions. But I have no idea how to define it in the template. The reason why the switch part is working is that the zigbee2mqtt accepts also plain ON / OFF / TOGGLE string payloads in that case.
But the brightness should be controlled with the following payload:
{"brightness": 196}And the RGB color like:
{"color":{"rgb":"46,102,150"}}Here's the link for the documentation (the Exposes part defines the messages).
So how should I define the JSON payload for example for the dimming action? It definitely should be some sort of expressions since I have to map the MSR real value (0...1) to (0...254) for the zigbee2mqtt.
actions: dimming: set: topic: "zigbee2mqtt/%friendly_name%/set" payload: expr: ????? type: jsonAnother problem is the RGB value. I could use the rgb_color capability for the setting but the problem is that the zigbee2mqtt only reports the current color in hue/saturation or xy coordinates.
Here's an example of published message after setting the color:
Topic: zigbee2mqtt/Mood Light QoS: 0 { "brightness":254, "color":{ "hue":240, "saturation":100, "x":0.1355, "y":0.0399 }, "color_mode":"xy", "color_temp":574, "linkquality":96, "state":"ON" }I would have to map those values back to RGB, but is it even possible with existing constructs in MQTTController's templates?
Help would be appreciated @toggledbits
br,
mgvra
That's probably more appropriate to post on Mantis for @toggledbits, but since I know there's at least @Crille publishing templates, my intent with this post is to open a broader discussion.
Long story short: I'm starting to slowly add new template for Shelly Plus and I noticed I'll end up with a dozen more templates, all similar but simply different in trivial details, all sharing a large amount of code and all needing special cares when fixing bugs/adding features (as the latest wifi_status addition).
So, I'm wondering if it's time to start thinking of some sort of inheritance in templates, where I could just create a generic shelly_gen1 and use it as a base for shelly_relay, and this be used as the base for shelly_relay_power and so on.
I could probably achieve this with some sort of scripting on my side to generate templates via code, but maybe there's a better way of doing this, or it's already on the radar.
I need a handful of victims volunteers to help test previews of the next build of Reactor. A long-standing request was for "a simple login mechanism," but in practice, adding user authentication and competent access control turned out to be a pretty big project with a lot of big changes on both server and client sides. It's a bit more than I'm comfortable testing myself and springing out to everyone at once, so I'd like to work with a small group to put it through "sea trials."
Major changes/features include:
User authentication with hashed password storage; User group configuration with application restriction (admin, dashboard, API); Detailed control over API access, with user- and token-based authentication/authorization; Improvements to the HTTPS service; Improvements to UI coordination with the core for Rules and Reactions.If this sounds like something you'd like to help with, drop me a reply here in this thread or privately.
[Solution: Reactor 24115 is not compatible with MQTTController > 24120]
Reactor latest-24115 bare metal.
All MQTT entities stop working after updating MQTTController to 24142, downgrade to 24120 and they are back. Templates and configured entities has not been changed between versions.
I'm not sure if uses_template should be replaced by ìnclude in entity configuration in reactor.yaml but I guess not, I've tried it and it did not do any difference.
I have not tried to update Reactor to userauth version.
Example entity in reactor.yaml that uses MQTTController included template:
entities: "takflakt_kallare": name: "Takfläkt källare" topic: "Källartemp" unit: "" uses_template: tasmota_generic_relay init: "cmnd/%topic%/POWER%unit%"Any hints? Do you need more info, please let me know.
Log from startup:
I'm slowly migrating all my stuff to MQTT under MSR, so I have a central place to integrate everything (and, in a not-so-distant future, to remove virtual devices from my Vera and leave it running zwave only).
Anyway, here's my reactor-mqtt-contrib package:
![](https://github.com/fluidicon.png)
Contrib MQTT templates for Reactor. Contribute to dbochicchio/reactor-mqtt-contrib development by creating an account on GitHub.
Simply download yaml files (everything or just the ones you need) and you're good to go.
I have mapped my most useful devices, but I'll add others soon. Feel free to ask for specific templates, since I've worked a lot in the last weeks to understand and operate them.
The templates are supporting both init and query, so you have always up-to-date devices at startup, and the ability to poll them. Online status is supported as well, so you can get disconnected devices with a simple expression.
Many-many thanks to @toggledbits for its dedication, support, and patience with me and my requests 🙂
Is the following config correct?
- id: time_series name: "Out temp" capabilities: temperature_sensor: attributes: value: model: time series entity: "hass>sensor_outdoor_temperature" attribute: "temperature_sensor.value" interval: 5 # minutes retention: 20 # minutes aggregate: wma primary_attribute: temperature_sensor.value type: ValueSensorSpecifically, is "depth" directive needed/mandatory here? Reason I'm asking is that I'm not getting a "final" value in MSR, only debug values are shown:
temperature_sensor.units=null temperature_sensor.value=null x_virtualentity.last_request_time=null x_virtualentity.request_failures=null x_virtualentity.template=null x_virtualentity.timeseries_debug=[{"time":1716537360000,"value":22.1},{"time":1716537660000,"value":22},{"time":1716537960000,"value":22},{"time":1716538260000,"value":21.9},{"time":1716538560000,"value":22}]Good morning,
I apologize if this subject has been covered. I did try the search, but I'm not coming up with any topics on my issue.
I'm running userauth-24137-57b41335, bare metal installation on Fedora 39 Server.
I have a rule set up to turn the Eco mode off on my Nest Thermostat when the thermostat is set to Away (Rule State: Away Mode), the user (Driver) presence in my car changes to true, and the destination is set to home.
93804f7c-62d6-42c0-ae04-ff602011a6fd-image.png
This works fine for most days, where I'm headed home from work (commute is about 45 minutes). What I don't want it to do is set change it to Eco mode if my ETA is more than an hour.
There is a sensor/entity for Time to Arrival when the Destination is set. What it appears to provide is the Time OF arrival/ETA, not time until arrival. If it was Time until Arrival, and it was a numeric value, I could simply test if the value is less than 60 and be done with it.
I pulled up the history through Home Assistant for my morning commute and this appears to be what it is providing.
c2a32739-c84f-4a05-95d9-73793ed818f5-image.png
So what I need to do is to do a calculation of the the ETA from the sensor value and subtract the current time, and get a value in minutes that I can determine if it's less than 60.
I believe I can do this with the local expression, but I don't see anything for the system time, or local time. Also, do the local expressions update themselves if the sensors do?
Good morning,
I'm running userauth-24137-57b41335 on Fedora 39, bare metal installation.
ZWaveJSController 0.1.23254
Home Assistant:
Core, 2024.5.3 Supervisor, 2024.05.1 Operating System, 12.3 Frontend, 20240501.1I'm trying to troubleshoot a Dynamic Group Controller and notification alert that I've set up for low battery level.
In my Reactor.config, I have the following lines:
name: "Dynamic Group Controller" implementation: DynamicGroupController config: groups: "zwavejs_dead": select: - include_group: "zwavejs" filter_expression: "entity?.attributes?.zwave_device?.status == 3" group_actions: true "low_battery": select: - include_capability: battery_power filter_expression: > entity.attributes.battery_power.level < 0.35The idea here is that I should only have members of this group that have a battery level below 35%. When I go into Entities, I show a whole slew of devices, none of which have a battery level below the threshold.
a77e445b-ab78-4752-a624-3c4117f34f90-image.png
I also tried setting up a rule to generate a push notification once a day, but with all of the group members, I've had to disable the rule. I believe I have it set up correctly, but I'm not 100% sure. I want the notification to tell me the battery level for that device as well.
289b4f68-03ba-49c0-8275-f0f197d13a3a-image.png
ce24a76e-6865-40bd-bd85-632e54d315a8-image.png dc837424-deb5-4ef7-8f0d-3676f1769535-image.png
Can anyone point to me what I may have misconfigured to get these results?
I should also note I'm only interested in ZWaveJS devices. It's showing me battery status for my iPad and car as well, which I don't need it to send me.
EzloController error
-
@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.
-
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.
-
@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...
-
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? -
@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? -
Variables
hm
andHouseMode
both are referenced somewhere, but appear to not be global. If you don't seehm
in the list of global variables, it's probably buried in a rule somewhere. What aboutHouseMode
? Global or rule? -
@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 namedhousemode
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. -
OK. Great detail. That helps, thank you. Let me see what I can do here...
-
@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!
I've now put a sustianed for 3 secs on the first variable trigger to ignore flapping.
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...
-
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
-
Is this on 21275?
-
@toggledbits Sorry, yes. latest-21275-df3d784
-
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 singleeach
loop, and store thegetEntity()
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 variablee
. 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 thereachable
test, and to returnname
as the loop body result foreach
. Also note that since thereachable
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 whenreachable
is true,null
is returned, and when not reachable, the entity name is returned). -
@toggledbits Ok, great explanation!
I do like cleaner expressions and will absolutely switch todo...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.
-
Hi, updated MSR latest-21281-c4807c0
I have connection with ezloplus in set_anonymous_access: trueMSR 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
`
-
[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
-
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.
-
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
-
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?
-
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.
-
T toggledbits locked this topic on