I have a few RM rules that have slowed down in execution time. They used to be rather quick, but now it takes them about 10 seconds from start to finish.
In a nutshell, the rules will trigger on a button press, wait for 1.5 seconds to see if the button is pressed again (detecting a double click) and then turn on lights.
The rule looks like this:
I enabled logging to see what was causing the lights to turn on 10 seconds after the button was pressed. This was what was logged:
dev:73 2020-01-29 20:38:19.688 infoGroup Lights Group - Kitchen Island was turned on
app:273 2020-01-29 20:38:18.990 infoAction: END-IF
app:273 2020-01-29 20:38:18.377 infoAction: On: Lights Group - Kitchen Island
app:273 2020-01-29 20:38:16.480 infoAction: Set Double click to false
app:273 2020-01-29 20:38:16.044 infoDelay Over: Delay 0:00:01.5 (cancelable)
app:273 2020-01-29 20:38:13.518 infoAction: Delay 0:00:01.5 (cancelable)
app:273 2020-01-29 20:38:11.632 infoAction: Set Double click to true
app:273 2020-01-29 20:38:11.619 infoAction: ELSE (do actions)
app:273 2020-01-29 20:38:11.611 infoAction: On: Lights Group - Kitchen (skipped)
app:273 2020-01-29 20:38:11.596 infoAction: Set Double click to false (skipped)
app:273 2020-01-29 20:38:11.583 infoAction: Cancel Delayed Actions (skipped)
app:273 2020-01-29 20:38:11.575 infoAction: IF (Variable Double click(false) = true(F) [FALSE]) THEN (skipping)
app:273 2020-01-29 20:38:10.261 infoButton - Kitchen: Button - Kitchen pushed 1
dev:11 2020-01-29 20:38:08.929 infoButton - Kitchen button 1 was pushed [physical]
The delays I could identify were the following:
It took RM over 1 second to trigger on the physical button push
It then took more than 1 second to start processing the rule
There are then 2 other noticeable delays and that's when setting the local variable "Double click" to a different value takes about 2 seconds each
Before I restart the hub (which very well might solve these delays) I just wanted to ask if these delays look normal and if there would be any merit to have my system looked at before I reboot if this could help with the bigger issue of the "HE slowdown issue"
If you open 'logs' and keep it running for a while, are you noticing any devices that might be spamming your hub and causing it to both work really hard constantly and perhaps making it memory consumption not fun?
I had this happen to me and the culprit was a z-wave multi-sensor that was pinging me constantly. Luckily using a customer driver i was able to instruct the device to only self-report every 5 minutes instead which is all I need and honestly probably too frequent as it does report whenever there is a change or activity automatically.
Another common question is if a safe-reboot of your hub fixes your issue, there are some good threads [1] [2] about that including some work-around people have created if they can't get to the crux of what is causing the issue (which I'd highly recommend you do v.s. working around the issue).
This particular delay in RM is consistent throughout the day. It happens during busy periods when sensors are reporting all sorts of data when there is a whole lot of people moving around the house, but it also happens during slow periods of time when I'm the only one at home and not setting off any sensors. During those slow periods it's like watching paint dry when monitoring the live log as there are hardly any entries in there at all.
I have also tried disabling all custom apps and drivers but that didn't make any difference.
Like you, I'd rather fix the root cause than suppressing the symptoms (by restarting the hub). (My doctor is actually all about treating symptoms rather than finding out the root cause which I think is very odd. I might change doctors...)
That doesn't sound good nor normal.
I've never done this, but I think you could backup your device, then hard-reset it and see if the problem persists to rule out a hardware issue, then either re-build or re-load your backup. I saw this with "find root issue" in mind as you seem to have ruled out any specific devices or custom apps running causing this.
I also wonder if disabling one of your mesh networks (e.g. zigbee only, z-wave only) could help rule-out anything.
If you want to perform a Soft Reset, that is safe and simple to do following Hubitat's documentation. A Full Reset is much more difficult to recover from.
Well, it seems only RM is affected. Other apps are working normally. And also within RM, it looks to be especially anything to do with local or global variables that slows things down. As you can tell from the log above, whenever a variable was changing it caused a delay of about 2 seconds. I have just created a new global variable in RM and between each step of the process (click "new variable", set the name, set the type, set the inital value) I had to wait at least 10 seconds for the next step to come up.
However, using RM to create a new rule works normally, with no abnormal delays
I have still not rebooted the hub. I may be stirring up a storm in a tea cup here, because this may very well resolve itself after a reboot, but as I've stated before, I'd just like to see if this is something that someone wants to have a look at before I do the reboot to see if it can shed a light on maybe a bigger issue - such as the over-arching "slow hub" issue. This might be one piece of that puzzle. @bravenel, what do you think? Is it worth looking in to what's causing the delays with variables or just restart the hub and be done with it?
Bruce,
I am seeing the same thing, but for me it is not only rules that use variables. It seems almost all rules are taking nearly 10 seconds to perform their action. Now, it isn't just RM, but it appears to be apps / rules that subscribe to device events. I have an Inovelli Red Series Dimmer. When I double-click down, it issues Button 2 Held, and if I double-click up, it issues Button 1 Pressed. I created a button controller rule that when I double-press up or down, it will increase, or decrease the fan speed by one speed level. You can see in the logs, that there is a significant delay from the moment the hub picks up the event to the time that the rules react to them.
The event is detected by the device handler at 05:42:23.8 then .2 seconds later the app picks up the event, and it takes 3 seconds for the app to decide what to do with three simple conditional actions, then once the action is executed (Set Fan Speed: Guest Room Ceiling Fan to low) it takes another 4 seconds for the Bond Integration app's handleFanSpeed function to be called. Once called, the state changes quite fast.
If I go to the fan device, and issue the set speed event, the change is near instant.
This rules out the Bond Integration App as the culprit for the delay.
Additionally, this is not unique to Bond, as I use the Mirror app to link the dimmer level of my Office Light Dimmer (an Inovelli Red Series Dimmer) with the Hue Light "Office". And here too, there is a significant delay in the rules handler, as compared to direct control in the the device page of HE.
As you can see, the HE picked up the even for light on, and the Mirror Me app command the light to turn on, but it took 4 seconds to get there. These long delays are why I left SmartThings to local control.
