Need help troubleshooting a rule/behavior

[waterboysh]

I'm going to try and explain as much as I can. I sorta know the problem, but am unsure how to go about troubleshooting the exact cause and fixing it.

Summary: I have an HS300 in my living room. It's an energy monitoring power strip. I have my TV and an air purifier plugged into it. I have a rule that when the TV powers on, will turn off the air purifier outlet. Since the air purifier has to be physically interacted with to turn on, I have a second rule that turns the outlet back on after a few seconds delay.

Problem: Sometimes, the outlet for the air purifier turns off and stays off.

---

I am using the community app/driver for the TP-Link devices. It works great. After some initial troubleshooting, I am pretty sure the issue is not there, but is somewhere in HE. Whether it's in the way an event was handled or an issue with Basic Rules, I am not sure.

We can treat the rule that turns off the outlet as a black box with an output that turns off the outlet. No need to troubleshoot that aspect. It works 100% of the time actually. Here is the rule that should turn it back on.

Super simple rule. What happens in my testing is that for the TP-Link device, using a command from the device or in a rule will immediately update the status of the device. It is a wifi device, so polling is needed to know the state. If for some reason, the states do not match when it's next polled, the device in HE is updated to reflect reality. I have mine configured to poll once a minute.

Because of this, I expected my rule to work to always make sure the outlet is on. It would go something like

1. TV turns on. Sometime in less than 1 minute HE should realize this.
2. Sends an off command to the Air Purifier. The device in HE should report off at this time. (this part never fails)
3. The rule triggers and waits 5 seconds; sends an on command. The device in HE should now say on.
4. For whatever reason, the plug didn't get the on command. When it's polled for its energy usage again, the switch in HE should revert back to off.
5. This should trigger step 3 and 4 to repeat until the switch is actually on.

But this breaks down at some point. Sometimes the outlet turns off and stays off until I manually turn it back on and I'm not sure where the breakdown is occurring. When it's like this and I check in HE, it will show correctly as off.

Due to the nature of this being polled once a minute, plus I don't know when it happens until the next time I go to turn the air purifier on, which could even be the next day or two. I don't always remember to turn it back on. It makes it hard to track down the when it started.

I've got logging turned on both the device and the basic rule. but not sure where to go from there.

[waterboysh]

Here's what it looks like when it works. In this instance, I used the Kasa app to turn the outlet off so that there would be a mismatch between reality and what HE thinks.

[Sebastien]

I’m curious as to what would happen if you added a wait for 5 seconds and then a command to turn on the outlet in the rule that turns it off instead (or on top) of the separate rule that does this?

[sburke781]

A couple of random things that spring to mind..... apart from being baffled by what you are seeing...

What do the logs look like when it doesn't work?
Does it only do this occasionally, or most of the time the rule runs?
What happens if you turn on debug logging on the device?
What happens if you add a virtual switch to the list of switches being turned on after 5 seconds?
Does the delay need to be so short? Not a solution as such, but a longer timeframe may help...
The rule looks simple enough, have you tried re-creating it?

If it comes to the point of involving the support / dev's, it may be useful to know the platform and app version you are running.
You may also want to double-check what is using the device just to make sure there's not something else interfering with the rule running.

Best I can come up with....

[waterboysh]

That's how I used to have it, but occasionally the turn back on command gets missed by the plug. That's why I moved it into a separate rule because every minute when the plug is polled, it should update it's status and if it moves from on to off, should trigger this rule and turn it back on.... in theory. Most of the time it works great.

[waterboysh]

@sburke781

What do the logs look like when it doesn't work?

I'm not sure. That's part of the problem is I typically don't know when it doesn't work until much later. I suppose for troubleshooting, I could set something up to notify me on my phone if the outlet is still off. I think the way I'd set it up is in the rule that turns the outlet off initially, at the end add a several minute long wait (to give the other rule several chances to run) and then have a conditional check and if the outlet is still off, notify me and then I can go check the logs right then.

Does it only do this occasionally, or most of the time the rule runs?

Only occasionally... I'd say once every couple of weeks or so.

What happens if you turn on debug logging on the device?

The debug logging turns off after 30 minutes. I assume you mean to have debug logging on when it fails? Would need the app developer to change the way logging works.

What happens if you add a virtual switch to the list of switches being turned on after 5 seconds?

I suppose it would turn on.... Is there something I could do with that?

The rule looks simple enough, have you tried re-creating it?

I used to have this setup in RM instead of Basic Rules and it happened then too. I moved it to Basic Rules probably about a month or two ago to see if having it in a more simple app would prevent the issue and it doesn't seem to have made a difference.

it may be useful to know the platform and app version you are running.

Not sure how much that would help actually... I've had this problem for a pretty long time; at least a year I think. I'm honestly not sure when it started. I've just never bothered to troubleshoot it because there were always bigger issues to worry about. It's not a significant problem by any means, just a minor annoyance. But at the moment, I'm on the latest release.

[sburke781]

Hmmm.... I am stumped. Where I was heading with some of my suggestions was, apart from the obvious benefits from seeing additional logs, could there be an occasional timing issue where the state is changed (the plug is turned off) midway through the polling process, where the polling process reads the plug as being on, but does not update the HE device until after the off command has been issued in your "black-box" rule. With a bit of testing I suspect RM and Simple Rules both still call the on command regardless of the device state, and the Kasa driver does not appear to conditionally send the command to the physical device based on the device state, so I am at a loss. Perhaps @djgutheinz can "check my working"....

My suggestion for including a virtual device in the rule was purely for debugging purposes, to see if that part of the rule was called at all when things did not work as expected, trying to see if it was the way the app was determining whether to run the actions, or whether it was more likely to be logic in the device driver. My testing I did with a virtual switch to arrive at my conclusion above proves that is not likely to be the case, but there may still be some usefulness in including one to see what happens. I wasn't thinking it could be used for anything beyond debugging your issue.

[djgutheinz]

@waterboysh

Summary: I have an HS300 in my living room. It's an energy monitoring power strip. I have my TV and an air purifier plugged into it. I have a rule that when the TV powers on, will turn off the air purifier outlet. Since the air purifier has to be physically interacted with to turn on, I have a second rule that turns the outlet back on after a few seconds delay.

My assumption: you are turning off via the Hubitat interface and not the Kasa App.

Your misconception: When changing setting (on/off) via the Hubitat Interface, the state is immediately updated to the detected final state. Essentially, I send a refresh command.

What should happen in your rule: When the rule detects "off" for the switch, it will initialize and run the delay followed by the on command.

Troubleshooting: I created the below rule and enabled logging for events, triggers, and actions. I then turned Couch Right ON. Next, I opened a logging window to see the actions performed. I then turned Couch Right OFF. The logs below show the actions and SUCCESS.

Logs of Test Rule.

app:48702022-07-26 11:46:19.839 am infoAction: On: Couch Right

app:48702022-07-26 11:46:19.822 am infoDelay Over: Delay 0:00:05

app:48702022-07-26 11:46:14.784 am infoAction: Delay 0:00:05

app:48702022-07-26 11:46:14.707 am infoTriggered

app:48702022-07-26 11:46:14.690 am infoEvent: Couch Right switch off

Logs of Couch Right. (note the change in on_off)

dev:65732022-07-26 11:46:20.021 am infoCouch Right 6.6.1: setSysinfo: [status: [on_off:1, mode:normal, brightness:100, hue:0, saturation:0, color_temp:5500, err_code:0]]

dev:65732022-07-26 11:46:14.649 am infoCouch Right 6.6.1: setSysinfo: [status: [on_off:0, dft_on_state:[hue:0, saturation:0, color_temp:5500, brightness:100, mode:normal], err_code:0]]

Next: I will do the same on my HS300 Plug (using a spare port).

[djgutheinz]

@djgutheinz

Next: I will do the same on my HS300 Plug (using a spare port).

Same results for an outlet on my HS300.

The other error if there is an error in sending the on command. My driver tries three times before giving up and it will set an event "CommsError" if an error has occurred.

The only issue I saw was the use of "wait" by you and "delay" by me. THE ONLY WAY to test is to turn on the logging in the rule and then go and get the logs (past Logs) from the logging page.

[waterboysh]

@djgutheinz I basically fixed this by making my rule that turns the air purifier back on send the on command more than once. But I wanted to show you the logs that show the rule turning the switch on but nothing being reported by the switch.

The TV turned on, which triggered the rule to turn off the air purifier switch. That triggered this rule to run, wait 5 seconds, and then turn the switch back on. Then 5 minutes later it sent another command to turn the switch on. Here is even event info for the air purifier device.

It never saw the first command to turn on.

[djgutheinz]

All my driver/device does is respond to rule machine. You could turn on debug logging to see if the command is actually received by the device from RULE MACHINE. If it is not received, that is an issue with your rule or somewhere else. (in other words, the logs you provide are still ambiguous as to the cause of the anomaly.)