2.3.9.147 - C7 - Virtual switches not responding to automations

I'm experiencing an issue where virtual switches cannot be turned off unless done so manually in device properties. I first noticed this when the "enable auto off" under "preferences" in device properties wasn't working when I set a value for that. As a workaround, I tried creating a rule to automatically turn off a virtual switch after 10 seconds, but the virtual switch ignored the rule as well. It seems like the issue is specific to the virtual switch being controlled by an automation.

1 Like

Working fine here with the auto-off enabled at 1s.

EDIT: Just realized I was still on .145 will re-test after updating.

Working fine on .147 as well for me.

Sorry .. 2.3.9.147 Mine seem fine ..
I have many v-switches just tested a few they work.
wonder if you need to do a reboot with rebuild data base ?

Thanks! Tried rebuilding the database on reboot. Same issue still.

Any errors in Logs? Especially something noting a hung scheduled job for an app or driver? This sounds a bit like it could be that, which there is a way to remove (but you need to know which).

1 Like

I tested with a virtual switch after enabling debug logging for it. The live logs show no errors, only "info" status level stuff related to the rules the virtual switch is involved in.

I should add I've recently discovered that this is affected all devices, both physical and virtual.

The issue started randomly at some point on 6/5. I did update to the 9.147 firmware that day. I can't be 100% sure the issue started after the firmware update. I rolled back to 9.141 anyway, but that didn't fix the issue.

Also, I tried another reboot with database rebuild with 9.141 installed, but no change.

How is it affecting physical devices? Auto off, or rules with delayed actions to turn off?

If it is basic rules, update back to .147 which fixes a bug in Basic Rules, and then open any impacted rules and click done to be sure all the subscriptions and timers are set correctly.

1 Like

Rules with delayed actions to turn off. Commands from Basic Rules, Rule Machine, & Simple Automation are all being ignored by the devices. No errors in the logs.

I went and updated to .148. I then created a Basic Rule for a delayed turn off with logging enabled. Still did not get the off command. Here's the logs (bottom is oldest):

 [dev:289] 2024-06-08 01:11:02.410 PM[info] Lava Lamp is on [digital]
 [dev:289] 2024-06-08 01:11:02.407 PM[info] BasicReport value: 99
 [dev:289] 2024-06-08 01:11:02.403 PM[debug] parse description: zw device: 1B, command: 2003, payload: 63 63 00 , isMulticast: false
 [dev:289] 2024-06-08 01:11:02.268 PM[debug] refresh()
 [dev:289] 2024-06-08 01:11:01.331 PM[info] Lava Lamp is on [digital]
 [dev:289] 2024-06-08 01:11:01.326 PM[info] BasicReport value: 99
 [dev:289] 2024-06-08 01:11:01.320 PM[debug] parse description: zw device: 1B, command: 2003, payload: 63 63 00 , isMulticast: false
 [dev:289] 2024-06-08 01:11:01.117 PM[debug] refresh()
 [app:710] 2024-06-08 01:10:01.038 PM[info] act: Wait Lava Lamp
 [app:710] 2024-06-08 01:10:01.021 PM[info] evt: Lava Lamp switch on
 [dev:289] 2024-06-08 01:10:00.950 PM[info] Lava Lamp was turned on [digital]
 [dev:289] 2024-06-08 01:10:00.947 PM[info] BasicReport value: 99

The goal is to look for any error, not one for this specific device and possibly not one that is even related to when you try to use it. If you go to Past Logs and filter for errors only, what do you see?

I did find some errors related to the Ecobee Suite Manager app. My ecobee thermostat is also not responding to commands from Rule Machine, so it's part of this as well. Below are the errors I see. It's also worth noting that I didn't get any errors from Ecobee Suite Manager before the issue started on 6/5:

 [app:682]2024-06-08 12:10:10.685 PM[error]getEcobeeSensors() - Missing or invalid thermostatList - no sensors
 
 [app:682]2024-06-08 12:10:08.336 PM[error]___exception getEcobeeThermostats(): groovyx.net.http.HttpResponseException: status code: 500, reason phrase: Internal Server Error
 
 [app:682]2024-06-07 05:41:49.805 PM[error]getEcobeeSensors() - Missing or invalid thermostatList - no sensors
 
 [app:682]2024-06-07 05:41:47.063 PM[error]___exception getEcobeeThermostats(): groovyx.net.http.HttpResponseException: status code: 500, reason phrase: Internal Server Error
 
 [app:682]2024-06-07 11:56:32.293 AM[error]java.lang.NullPointerException: Cannot get property 'heatTemp' on null object on line 4721 (method resumeProgram)
 
 [app:682]2024-06-05 10:04:51.390 PM[error]getEcobeeSensors() - Missing or invalid thermostatList - no sensors
 
 [app:682]2024-06-05 10:04:49.020 PM[error]___exception getEcobeeThermostats(): groovyx.net.http.HttpResponseException: status code: 500, reason phrase: Internal Server Error
 
 [app:682]2024-06-04 04:14:56.785 PM[error]checkThermostatSummary() - httpGet error: 500, status code: 500, reason phrase: Internal Server Error, [status:[code:3, message:Processing error. Error retrieving thermostat summary.]] - won't retry
 
 [app:682]2024-06-02 02:14:58.896 PM[error]refreshAuthToken() - HttpResponseException occurred. Exception info: groovyx.net.http.HttpResponseException: status code: 429, reason phrase: Too Many Requests StatusCode: 429
 
 [app:682]2024-06-02 02:14:48.348 PM[error]refreshAuthToken() - HttpResponseException occurred. Exception info: groovyx.net.http.HttpResponseException: status code: 429, reason phrase: Too Many Requests StatusCode: 429
 
 [app:682]2024-05-31 10:14:47.882 AM[error]checkThermostatSummary() - httpGet error: 500, status code: 500, reason phrase: Internal Server Error, [status:[code:3, message:Processing error. Error retrieving thermostat summary.]] - won't retry

Please post screenshots of the logs, the text is very hard to read the way it comes through in the forum.

The Ecobee stuff has been known before to cause issues I think depending on the setup it can be very active. If you cannot resolve those errors you should disable the app/driver for now to see if that helps.

Is App 710 above the new rule you created? Can we see a screenshot of the rule (if basic rules just the purple text at the top is good).

app:710 2024-06-08 01:10:01.038 PM info act: Wait Lava Lamp
app:710 2024-06-08 01:10:01.021 PM info evt: Lava Lamp switch on

I disabled the Ecobee app and rebooted the hub. No change in status.

Correct, app 710 is the new Basic Rule. Here's a screenshot of that:

I made a sample rule on my end
image

Set a slightly longer delay and then check in Logs > Scheduled Jobs you should see something like this while the delay is pending

Here is my resulting logs showing the delay then the rule completing
(I triggered the rule with the Run Actions button on the rule page)

image

I see your rule says "Wait Laval Lamp" while mine says "Wait 30 seconds", are those logs from a different version of this rule?

Do you have any other errors in your logs from anything?

Ok, I set a longer delay, and it did show up in scheduled jobs:

No change in behavior. But wow, do I have a rather long list of scheduled jobs. Could that indicative of the issue?

Resulting logs from the test:

The logs are from the same version of the rule, which is now updated to 60 seconds instead of 10. in my "apps" page, Basic rules are listed as "Basic Rule-1.0"

I went to "Past Logs" filtered on errors, and it's showing only errors from the Ecobee app, and one from the Ecobee device itself. No others I'm afraid:

Something is not right with your rule, the act should look like mine, "Wait XX seconds"
Maybe delete it and make a new one?

image

I deleted and created a new Basic rule. Used a different device. Logs look more like yours now. Still no auto-off. I guess the issue isn't that devices aren't responding to rules. The rules are turning them on successfully. They just won't turn them back off:

Yes, looks like the delayed action on the rule never even tries to fire, the schedule job is getting killed for some reason.

Go to Logs > Device stats
Click the display settings and enable all the columns.
Should be sorted by % of busy be default (highest at top).

Post a screenshot of the first page including the stats above the table.
Do the same for the App stats tab

Usually if delayed actions never fire it is from other apps/devices consuming the hub resources.

Device Stats:

App Stats:

Looks like you rebooted and then got the app stats? Will need to see another one after the hub has been running for a bit.