KASA Integration: devices not responding or reporting properly

There are definitely issues with the dashboard picking up the current status of the lights.

For instance, if they're already on when I open the dashboard, it shows they're off. Or if someone manually turns them on or off, the status generally isn't reflected in the dashboard.

That seems to be true for my other devices as well so I'm not surprised.

What the dashboard says is one-step removed from the integration. From the Kasa Integration perspective, the stream ends with the EVENT interface. This is reflected by selecting events from the device's edit page.

As far as the dashboard is concerned, it is very interesting how they update (from my observations). They apparently queue state updates when they are not the focus window and plays them back until the dashboard is current. I have a table with a thermostat tile (among others). When I open the tablet in the morning, you can watch the thermostat cycling through the state changes encountered while the dashboard was not displayed.

If manually turned on or off, the state / display will reflect at the next poll interval for the device. If turned on/off through the app, the change will appear nearly immediately. The poll interval can be changed.

Several of the devices I have issues with do not have a poll interval setting. I'm guessing there are ways around that using a virtual device or switch or something perhaps but I'll have to play around with that more first.

All of the Kasa devices in Hubitat have a poll interval command. Very confused????????

Sorry, should've been more specific. The devices I'm having issues with are not Kasa devices.

They are Wyze bulbs and Govee plugs.

I just noticed that this is back to not working. Device is completely unresponsive to direct manipulation or rules.

Some confusion whether this is a Kasa device or not. If a Kasa device, check the device's IP address in Hubitat and compare to that in your router. If not the same:

  • In your router, set a static IP address for the device based on the current device.
  • In Hubitat
    • Uninstall the device then open.
    • Open the Kasa App and reinstall the device.

Yep, you're right. The IP changed. I should've looked into that first.

I'll make a static reservation.

Thanks

I'm now having the same issue with two Kasa KP115 plugs. I have rules used to turn a humidifier on and off, and it has been working fine for months. The following screenshot shows that the rule is correctly triggering an "OFF" command, but for some reason the plug is not actually switching the "value" from on to off.

Here's a screenshot showing a different Kasa KP115 where the "OFF" command is correctly switching the "value" of the switch to "off."

Any ideas? Sounds like perhaps the same problem others in this thread have dealt with. The Hubitat device page for the plug that is not working doesn't show any problems, but it will not update or refresh, and I cannot control the plug from Hubitat device page (no commands work). I can, however, still control it from the Kasa app on my phone, though.

There have been zero changes to the rules or devices at issue except that I pretty regularly update drivers and apps using Hubitat Package Manager. I use dedicated IPs for the devices. I'm using the latest version of Kasa Integration app. The only devices I've added to my Hubitat recently were some Levoit Air Purifiers, but I added those about a month ago and didn't start having problems with the Kasa plugs until 4 or 5 days ago.

The first time I had the problem with a KP115 plug 4 or 5 days ago, I was able to fix it by unplugging the plug for a few minutes, and then plugging it back in. Then 2 or 3 days later, the exact same problem started happening with a different KP115 plug.

Thanks in advance.

Need some real data to proceed. Since there have been zero changes, then why the sudden error? There are several possibilities.
The physical device
The device LAN IP address
We can also check if there are errors.

Needed information.

  • Any power surges or outing over the last several days?
  • What is the color of the light on the front of the plug?
  • Community or built-in integration?
  • What is the driver version from the device's page?
  • From the Hubitat Drivers code page, what is the date for the driver last modified?
    • Need to see if there is a correlation between the problem and a driver update.
  • Open the device's page and a separate logging window.
    • Is the Hubitat's device IP address the same as within your router?
      • If not the same, this is the issue.
    • Can you control the device from this page?
      • If you can, then there is something in the rule execution.
    • Are there any errors/warnings in the log. Please share as text rather than an image.
  • Open the rule for the device and test the rule.
    • Does it work?
    • Are there any errors/warnings in the log. Please share as text rather than an image.

Final. Sometimes the device goes "insane". Do not know why. So unplugging and plugging back in will reboot to a "sane" condition. (You can also try the Reboot Device preference - but this may not work.)

1 Like

@djgutheinz I have a somewhat similar (but very sporadic) issue I've been trying to get to the bottom of, and I wanted to brainstorm it for a bit. I'm 99.9% certain it's not your code, but that only makes troubleshooting even more fun :slight_smile:

My understanding of Kasa driver's flow for turning the plug on:

  1. send command to the device: sendLanCmd: [ip: 192.168.1.999, cmd: {"system":{"set_relay_state":{"state":1}}}]
  2. wait for an acknowledgement from the device in a callback: parseUdp: [system:[set_relay_state:[err_code:0]]]
  3. once the acknowledgement is received, send a "refresh state" command to the device: sendLanCmd: [ip: 192.168.1.999, cmd: {"system":{"get_sysinfo":{}}}]
  4. wait for a response from the device in a callback: parseUdp: [system:[get_sysinfo:[sw_ver:1.0.8, model:HS103(US), rssi:-58, relay_state:1, ...]
  5. update the actual state in Hubitat based on relay_state in the response: setSysinfo: [switch:on]

The issue: occasionally one of the devices, a HS103 plug, doesn't report its status back after switching it. I.e. the command (1) is sent, the plug actually turns on instantaneously, but the acknowledgement (2) never makes it back.
I've only noticed it happening on this particular device, because it's the only Kasa device where I have a RM rule that triggers when the plug is turned on.
Subsequent retries are always successful, or at least I haven't seen it fail to respond twice in a row. I've tried to force the issue by operating the device a few hundred times, but, of course, it never happens when you want it to happen.
There is no significant load on the hub, and the device driver is only responsible for 0.002% of the load, which makes sense as it's completely async so it's not taking up any CPU cycles when it's waiting for the callback.

What I'm trying to understand is, hubitat.device.HubAction is called with a 9-second timeout, but when that timeout is clearly exceeded, absolutely nothing happens - no errors or warnings in the log, nothing. I would expect that with parseWarning flag set it should actually pass the error to the callback, but that doesn't seem to happen.
Also, is there any significance to the timeout being exactly 9 seconds?
I'm out of ideas what to try next... Thanks!

-B

If it hasn't responded in 2 or 3 seconds, it is not going to respond. Without a response, there is no way for me to determine what is going on.

That's what I thought as well, typical response time is under 200ms, but I saw over 6s today and that was puzzling:

dev:743 2023-07-26 06:51:00.224 debug Night Light V-2.3.5-1: parseUdp: [system:[get_sysinfo:[sw_ver:1.0.8 Build 221011 Rel.195515, hw_ver:5.0, model:HS103(US), rssi:-62, ...<skipped for brevity>]]]
dev:743 2023-07-26 06:51:00.097 debug Night Light V-2.3.5-1: sendLanCmd: [ip: 192.168.42.205, cmd: {"system":{"get_sysinfo":{}}}]
dev:743 2023-07-26 06:51:00.094 debug Night Light V-2.3.5-1: parseUdp: [system:[set_relay_state:[err_code:0]]]
dev:743 2023-07-26 06:50:54.052 debug Night Light V-2.3.5-1: sendLanCmd: [ip: 192.168.42.205, cmd: {"system":{"set_relay_state":{"state":1}}}]
dev:743 2023-07-26 06:50:54.050 debug Night Light V-2.3.5-1: setRelayState: [switch: 1]

If I understand things correctly, realistically, only 2 things could have caused a latency this high:
a) the plug itself took this long to send the response packet after it turned the relay on
b) the response packet was received by HE right away, but it took quite a bit to process it and finally invoke the callback method.

Actually, looking at the past logs of twice-an-hour polls, I see a lot of delays there too (that's between sendLanCmd and parseUdp), and all of the delayed ones are suspiciously very close to 1 second granularity:

128ms, 6043ms, 128ms, 119ms, 6043ms, 129ms, 130ms, timeout, 130ms, 130ms, 129ms, 130ms, 6044ms, 129ms, 130ms, 8048ms, 126ms, 2033ms, 128ms, 4045ms, timeout, 134ms, 4038ms, 130ms, 2120ms, 129ms, 1029ms, 2040ms, 4133ms, 118ms, 121ms, 130ms, 5036ms, 132ms, 5148ms, 130ms, 6051ms, 1942ms, 129ms, timeout, 125ms, 126ms, 5012ms, 127ms, 4041ms, 122ms, 223ms, 6024ms, 8070ms, 116ms, 113ms, 114ms

It's the device itself, isn't it?..

Tested on my HS200 switch, bought in 2018. The delay for the entire on - update status (all log lines in your message above) were 0.277 sec and 0.260 sec. So, could not duplicate. Same version, C-8 Hub. So we have a curiosity that will require more data/research.

First, what is the device? Also, Private Message me more of the logs (several on/off command cycles with 10 seconds between). I want to determine if certain commands are slower.

Second, look at the Logs - Device Stats.

What is the total% utilization for all your devices:
image

What is the % of total for your problematic device?

Current remedy (attempt): Try a reboot (using the device preference). Also, make sure the device has only one master - Hubitat. These could also interfere.

  • Alexa: Make sure the Kasa Skill is not installed. Use the Alexa App instead.
  • SmartThings/Google: Same thing.
  • Other home integration sites - same thing.
  • Non-Hubitat rules / routines - no.
  • The Kasa Phone App (I do a forcestop - just in case.
  • The Kasa Phone App - make sure there are no rules/routines.

Issue: The issue is that the devices appear to ignore "collisions", the case where it is working on command A and receives command B. Simply ignores.

I know it's been a while, but I was finally able to carve out some time to embark on a deep dive research project, and the results were quite surprising.
In my current setup I have 20 Kasa devices, mostly plugs (a mix of HS103, KP125 and EP10) and 3 ES20M motion dimmers. 2 of the KP125s are used for energy use monitoring.
Hub (C-7) load is very reasonable:

Local apps: 1h 31m 47s / 4d 12h 53m 4s total (1.4%)
Devices: 2h 2m 1s / 4d 12h 53m 17s total (1.9%)

As a first step, I tweaked your driver code to log callback latency of getSysinfo(), getRealtime() and setRelayState(), and keep track of the number of "slow" responses (>1s) vs "normal" responses (typically 120-140ms). I also increased the callback timeout from 9s to 30s, just to see if it does anything.
All the devices are configured with a 10-minute refresh interval, except for KP125s, that are on a 1-minute cycle.

  • Surprise #1: every single device was showing those latency issues, with anywhere between 15% and 30% of responses taking longer than 1s.
  • Surprise #2: While most slow responses were about 4-6s, occasionally latencies would jump to absurd levels:
dev:1028 2023-12-19 16:10:30.511 warn Curio Cabinet (left)-2.3.6: High Sysinfo latency: 22949ms
  • Surprise #3: KP125 devices that were getting 20x the requests, showed a much lower percentage of slow responses (1.2%-1.8%), but in absolute numbers, they were comparable to the rest of the devices. Logs also confirm that the absolute majority of those slow responses were observed during those once-every-10-minutes refresh cycles. Also in many cases the "backlog" would clear in batches:
dev:865 2023-12-19 07:01:00.154 warn Guest Bathroom-2.3.6: High Sysinfo latency: 2133ms
dev:1027 2023-12-19 07:01:00.082 warn Curio Cabinet (right)-2.3.6: High Sysinfo latency: 2027ms
dev:835 2023-12-19 07:01:00.076 warn Reading Light A-2.3.6: High Sysinfo latency: 4053ms
dev:837 2023-12-19 07:00:51.285 info Living Room Receiver-2.3.6: Emeter latency: 123ms
dev:837 2023-12-19 07:00:51.158 info Living Room Receiver-2.3.6: Sysinfo latency: 137ms

Which leads me to believe that the root of the issue is the way Hubitat is handling callbacks. Without knowing the actual implementation details it's pure conjecture, but it feels like once the response packet arrives, and HE decides that it can't process it right this moment, for whatever reason, it kicks the proverbial can further down the road, i.e. reschedules the processing to 1 second later or something like that.

To completely rule out the devices themselves, I set up HomeAssistant with nothing besides a Kasa integration, which polls devices very aggressively (every 5 seconds), and didn't get a single hiccup over the 24 hours period I had it running, confirming that it's not the devices.
As it was running, I was fully expecting the symptoms to get worse on the Hubitat side, but, interestingly enough, it didn't make any difference in the overall rate of slow responses.

Nothing in the apps/drivers stats stands out as particularly slow or a resource hog, so I'm still curious, what could possibly cause these "stop the world"-like events. It's hard to pinpoint whether it started after one of the hub firmware updates a few months back, or if it's simply the number of devices managed by a single hub has reached a critical mass? I have quite a few, about 50 Z-Wave and 60 Zigbee devices in addition to 20 Kasa devices.

In the end, it's not very difficult to work around this issue using a virtual device, but it would be a lot cooler if I didn't have to :slight_smile:

I think you have reached a critical mass, but I am definitely not an expert there. I do not see the extreme delays you see and it could be how the Hubitat SW handles interrupts from the Z-wave and Zigbee devices (do they have a higher priority than ASYNC responses from sendHubAction)? If that is the case, I can surely see delays.

I would check and assure I am not seeing app, zigbee, and z-wave errors and warning (handling errors get a priority in most software). Finally check the various log pages (device stats, app stats, etc); including hub events. You may have something else taking priority. But you have a lot on your Hub's plate.

My setup is a LOT less loaded. I have a single hub with about 55 devices (mixed types), and 13 apps. I also do not see the delays you are.

Out of curiosity, did you try testing with 2.3.7.x ?

I personally have never experienced anything like that with Hubitat in general. I was having similar problems with this Kasa integration quite awhile ago (that's why I started this thread originally) but ultimately, I was able to solve all my issues and it turned out that Hubitat was not the problem. In my case, it was a poorly set up wifi network combined with some problems that seemed to be caused by the now defunct Wemo Connect integration.

Open up a terminal on your computer, find the IP address of one of your Kasa devices which is giving you issues, and ping it 100 times. If any are dropped, there's probably an issue with your wifi that is causing this problem with your Kasa devices. It could be something as simple as a TV broadcasting a casting SSID on the same channel as your access point.

Does your router have wifi 6? See the article below. I set up a separate SSID for 2.4 GHz devices and disabled wifi 6 on that SSID.