Delay problem in 2.2.4

Just updated to 2.2.4.147 and now I have a strange problem with one particular rule in RM. The rule looks like this:

When I open the laundry door, there is about a 4 second delay before the light comes on:

dev:5462020-11-25 17:44:12.069 infoGarage Lights is on [physical]
dev:5462020-11-25 17:44:12.027 infoGarage Lights was turned on [digital]
dev:3252020-11-25 17:44:11.857 infoLaundry door was closed
app:7692020-11-25 17:44:08.483 infoAction: END-IF
app:7692020-11-25 17:44:08.262 infoAction: On: Garage Lights
app:7692020-11-25 17:44:08.255 infoAction: IF (Garage Lights(off) is off(T) [TRUE]) THEN
app:7692020-11-25 17:44:08.047 infoGarage Lights via Laundry Door Triggered
app:7692020-11-25 17:44:08.031 infoGarage Lights via Laundry Door: Laundry door contact open
dev:3252020-11-25 17:44:07.834 infoLaundry door was opened

None of my other rules seem to have this delay, even one involving the Laundry door as a trigger. I'm not going to stand there with the door open for several seconds waiting for the light to come on -- with 2.2.3 it was very fast. I'm going to have to roll back both my hubs. I was looking forward to using the Hub Mesh but this is a problem. I tried rebooting, restoring the database -- it is very strange. And seems to be just this one rule, though of course I haven't tried them all. I even deleted this rule and re-entered it -- same exact behavior.

Why Rule Machine for this very simple rule? That is using a baseball bat to hit a mosquito.

Try Simple Automations, it is lighter and easier, and likely quicker.

We can see from the logs that RM acted fairly quickly, so the mystery is why the delay between RM turning on the light until it actually turns on. Could you pull up the Device Events (from the device page) for this same period of time and post a screenshot of those?

By chance, is the contact sensor involved here using security? Is it a different type of contact sensor than used elsewhere in your mesh? I'm trying to sort out a similar issue to what you're seeing...

same thing i was seeing after the f/w install.. seems to be better now but i posted an image showing the rule saying the light was turned on.. and it actually coming on 8 secs later.. Just before i manually turned on and off the light switch that the rule was controlling and it was instant...

none of my contact sensors have any security and anyway that would not explain the log showing that the rule has turned on the light.. that means it way passed sensing the contact sensor.

Summary

here is the log again

The delay is between app command on, and the light coming on, from what I can tell. Turning on/off a light switch has nothing to do with it. What we're trying to understand is where the lag is coming from for a digital 'on' command sent, but not acted on for some seconds.

About your logs, I have no context in which to make sense of that. What is app 327?

the switch was just to make sure that the light was working correctly ie not a zwave issue.

the app in question is app 97, lights on/of when deck doors opens becuase de v29 the slider was opened.. it is supposed to turn on the deck and backyard lights .. you can see them going on later at 4:39:08.. would you like me to post the rule.

Are these issues associated with Z-Wave contact sensors? There is another report of these causing Z-Wave network delays. That could explain what you guys are seeing.

yes mine are zwave contact sensors.. and zwave switches.. but now it is working fine.. i also saw delays at the same time with zwave motion sensors.. but again those rules are working fast at the moment.

This is a Z-Wave mesh issue. Your mesh, for some reason I don't know, was delaying commands getting to devices.

interesting because the example above the slider is 5 feet from the hub and the light switch is about 15 feet.. Doesn't seem to be distance related.. The basement door, light on, front door light on, motion in dining room light on.. all were delated 10-30 seconds before the lights came on.

And as you know i had logging on and i didn't see any kind of intense message storm, but without a sniffer maybe wouldn't see it.

It has nothing to do with distance. If the Z-Wave network doesn't send the command, the device doesn't get it.

1 Like

This is the same issue I'm running into... Is this a documented bug or just something others are reporting but no root cause?

I'm trying to figure out the pattern here, see if we can pinpoint where the slowdown is. From what I can tell, it appears to be Z-Wave related. But, I don't want to jump to that conclusion and miss something else. Logs showing a lag from stimulus (e.g. sensor firing a rule) and device turning on are very helpful (screenshots, not copy paste for logs). Generally speaking, a rule, be it RM or Simple Automation Lighting, or Scene, or Motion Lighting, sends the 'on' command at the same time it writes the log entry about turning something on. So from that log entry, to the device reporting being on is what I'm interested in.

1 Like

here is the same automation .. now working perfectly..

Summary

And nothing else changed since the time it was lagging until now, right?

nope nothing changed.. havent rebooted , haven't done anything.. i did go through and export every rule since then.. but it was already working ok at that point.

OK, good to know. Have you done a Z-Wave repair recently?

I still don't understand this comment. Was the switch the one controlling the light, a Z-Wave switch?

no, i did do a couple of node level repairs on nodes not related to those devices in that automation have always been no repeaters as they are so close to the hub.