Help with RM Rule performance

🛎️ Get Help
1

Hi not sure what I am doing wrong here but I have rule that responds to a button click, however it takes over 2 seconds after the button press even is fired and the lights are turned on/off. This is pretty bad for a local control device. As fas as I can tell its RM that is slow If turn on the lights by sending a direct message its pretty quick.

08:38:02.232 am button push is logged from the app looking at mqtt
08:38:02.236 AM event is fired - pretty quick
08:38:03.475 am first log entry from RM rules indicating trigger 1.2 secs thats a lot of time
08:38:04.592 am light is turned on 1117ms to evaluate and execute a simple rule -

2356ms between the time event is fired to when the light turns on, this is very bad, there is nothing in the logs between this events, so what is making HE run so slow? Is there something wrong in my rules? too many conditions? I pretty much copied examples from @Ryan780 from various posts.

BTW other method of turn on the same lights (alexa, UI) etc are all within acceptable times

The rule -

08%20AM
Screen Shot 2020-01-02 at 9.00.08 AM.png1696×1464 303 KB

Event log from the remote
pushed 1 Bedroom Remote 1 button 1 was pushed DEVICE 2020-01-02 08:38:02.236 AM EST

Relevant portion of the main log - I have not removed any entries

dev:6762020-01-02 08:38:04.616 am infoBedroom Main was turned on

dev:6752020-01-02 08:38:04.592 am infoDesk was turned on

app:6662020-01-02 08:38:04.556 am infoAction: END-IF

app:6662020-01-02 08:38:04.549 am infoAction: Off: Desk, Bedroom Main (skipped)

app:6662020-01-02 08:38:04.472 am infoAction: ELSE-IF (Desk, Bedroom Main(off, off) any is on(F) [FALSE]) THEN (skipping)

dev:6762020-01-02 08:38:04.450 am infoBedroom Main is 75%

dev:6762020-01-02 08:38:04.323 am infoBedroom Main was turned on

dev:6752020-01-02 08:38:04.124 am infoDesk was turned on

dev:6752020-01-02 08:38:04.109 am infoDesk is 75%

app:6662020-01-02 08:38:03.869 am infoAction: On: Desk, Bedroom Main

app:6662020-01-02 08:38:03.845 am infoAction: IF (Desk, Bedroom Main(off, off) any is off(T) [TRUE]) THEN

app:6662020-01-02 08:38:03.475 am infoBedroom Buttons : Bedroom Remote 1 pushed 1

dev:7652020-01-02 08:38:02.232 am debugBedroom Remote 1 button 1 was pushed

2

Hi there, sorry for the troubles. Have you tried using a virtual button instead of the current driver you are using for the Bedroom Remote 1? If your latency disappears, then you know that the driver for the remote is the problem.

1 Like
3

Please review the logs - its not the driver. It RM - if I use other mechanisms including simple lightning its fast. however I can't use that because there are are few other conditions that my rules require.

On a side note I am seeing delays in other RM rules I have with motion detectors, haven't had time to pull together logs and do analysis. I would be happy to share anything from my system that may help you locate the root cause.

4

Well, first of all, you do not need to turn on the light and set it to 19% in separate commands. Simply setting the light to 19% will turn it on. That should speed up the first press.

Also, you are setting it to 19% on the first press and then 20% on the second. That isn't very different, not different enough to require 2 button presses. I would modify that.

Also, I don't understand the logs that I'm seeing. The light is off, so it should be turned on to 19% but I believe another rule is firing setting it to 75%. Do you have another rule setting the default dimmer level of this light? Can you show the In Use By section of the edit device page?

5

Based on your logs and my preliminary research, the latency could be caused by the remote driver. If you could please recreate the rule using a virtual button and you still get the same results, that may help us identify the root cause of your problem. Please post the same logs for a rule that doesn't use the "zigbee2mqtt EcoSmart Remote ZBT-CCTSwitch-D0001" driver.

1 Like
6

@anisk Are some of your bulbs the Ecosmart bulbs? I noticed that if you send them a dim command under about 30 then they take a long time to turn on. They actually report being on but it takes them a couple of seconds to light up. If you send an on command and the dim level is low they light up brighter then dim. Your problems in this thread may be different but worth watching out for. I had some Ecosmart bulbs being triggered by a motion sensor to dim to 15 at night. They take a couple seconds to turn on even though they report being on. From what I can tell it's an issue with the bulb not Hubitat.

7

some are - I have a similar issue with Sengled bulbs as well. As you can see from the logs above the command to turn on the lights isnt even fired by RM for 2356ms. I could blame the bulbs after the command is fired. Turning the lights on manually or even simple lighting are quick enough. The issue is RM

I think something is gumming up and slowing down RM. Hopefully someone from Hubitat support will actually read my messages and try to diagnose the issue. doesnt make sense why 2.5 secs would be spent evaluating a simple rule,

8

Actually, it was very helpful. It just wasn't what you wanted to hear. I have zigbee bulbs triggered by a button (Pico remote) and RM, and there's no 2 second delay. I also have zigbee RGBW bulbs controlled by one of these, and there's no delay using either the Mirror app or RM.

3 Likes
9

You do realize that you have a transition time on the bulbs, correct? You have to look at what you have set in the bulb for the transition time in order to know how long it will take to turn on. If that is set long and the level you have commanded is low, it will appear that the bulb is off for a long period of time since they have a minimum level to turn on. Also, with the ecosmart bulb, when turned on to a low level, they first jump to a higher level, then back down. So, a long on-transition time with a low level might be screwing up the bulbs performance. I would remove those and see how the bulb reacts.

10

And you are an expert on my system? Do you know how its setup?
How do you know my Hubitat unit is not broken or there is some other misconfiguration in my system?
How is your system configuration or its results relevant to mine? You may not even have the same HE device.

What part of what he said is helpful?
He didn't address the core issue and sent me on an irrelevant chase. which BTW I have done and here are the results.

12:53:15.188 pm virtual button button 1 was pushed
12:53:17.483 pm desk is turned off

2295 ms between RM receiving the event and firing off the message to turn off the desk

Removed the "zigbee2mqtt EcoSmart Remote ZBT-CCTSwitch-D0001" device from triggers - only used a virtual smart button

dev:6762020-01-02 12:53:18.082 pm infoBedroom Main was turned off

dev:6752020-01-02 12:53:18.018 pm infoDesk is off

dev:6762020-01-02 12:53:17.944 pm infoBedroom Main is 75%

dev:6762020-01-02 12:53:17.769 pm infoBedroom Main was turned off

dev:6752020-01-02 12:53:17.536 pm infoDesk is 75%

dev:6752020-01-02 12:53:17.483 pm infoDesk was turned off

app:6662020-01-02 12:53:17.254 pm infoAction: END-IF

app:6662020-01-02 12:53:17.114 pm infoAction: Off: Desk, Bedroom Main

app:6662020-01-02 12:53:17.090 pm infoAction: ELSE-IF (Desk, Bedroom Main(on, on) any is on(T) [TRUE]) THEN

app:6662020-01-02 12:53:16.938 pm infoAction: On: Desk, Bedroom Main (skipped)

app:6662020-01-02 12:53:16.915 pm infoAction: IF (Desk, Bedroom Main(on, on) any is off(F) [FALSE]) THEN (skipping)

app:6662020-01-02 12:53:16.517 pm infoBedroom Buttons : virtual button pushed 1

dev:7682020-01-02 12:53:15.188 pm infovirtual button button 1 was pushed

11

What is the transition time you have set for the light on the edit device page? The light will not report being turned off until it is actually off. If you have a transition time of 4 seconds, this is exactly what I would expect.

12

I get that - however look at the logs, the command to turn on the bulbs takes 2.3 seconds to pass through the RM. And I replicated that with virtual switch, i can further test with my Sengled lights, my concern is that either my HE device is bad or something is slowing it down.

Or are you saying that the transition time will affect RM processing? Hadn't thought of that. It was set to 1s,

13

No, it doesn't. The event occurs as 16.157.
app:6662020-01-02 12:53:16.517 pm infoBedroom Buttons : virtual button pushed 1

That is the event.

This is not the event:
dev:7682020-01-02 12:53:15.188 pm infovirtual button button 1 was pushed

The driver is taking recognizing the press. Then 1.4 seconds later the event is published. It is probably waiting to see if your are getting a HELD event instead of a pushed event. That is the driver, not the rule. You can see that because next to the first event is "dev " and next to the second it "app". The app line is the app picking up that the button was pressed.

Then the command to turn the light off happens at 17.114. That is less than 1 second.

2 Likes
14

@Ryan780 Thank you this was very helpful, along with the tip to check transition time. I will try to tweak the driver then.

1 Like
15

So, I guess @bobbyD suggested was accurate after all.

3 Likes
16

I would say partially....the driver he is referring to is the driver controlling the bulb and it's transition time. Not the remote's driver.

1 Like
17

Seems to me like he did.

That's been dealt with earlier by @Ryan780, so there's no point in discussing it again.

18

The point is that the long delay is a combination of things. So looking at any one thing by itself was never going to find the root cause. You have to take a broader look at everything that is going on to try to sum up why the delay is occurring.

I also contend, that it support it doesn't matter if you have the write answer. If you can't convince the customer that you are write then you're still wrong. The customer's perception is the only barometer of success.

4 Likes
19

Very true. I did customer support as an undergrad (35 years ago), and you've written is 100% accurate.

20

And given that it's a pretty technical audience - providing hard facts and clarifying information just like you did instead of generalized responses.