Hi @bravenel and all,
I have 3 simple rules setup to open/close my shades at a certain time of the day. 8am on weekdays, 9am on weekends, close everyday at 9pm. These worked flawlessly until the update to 2.2.3. I've removed all the rules and rebuilt them but it's still the same. The logs indicate that the shades were commanded to open/close but they don't. If I open the app and 'Run Actions' they work perfect and immediately. From the logs below... the at 9am is the RM action and the 10:30 is me pressing the 'Run Action' button. Only when I press the Run Action button did they actually open. All the rest of my automations are working fine and the ZW is quite responsive so I can't put my finger on why it won't work.
Look at the device events for the ones in the log. What do they show at 9:00 am? It appears that the app is giving the command.
The 9:00 event shows 'opening' and that's it. The 10:30 'Run Actions' event shows more... It's almost like the automation 'thinks' it's running the action but it doesn't actually send out the ZW command. Just wanted to add that the shades work almost immediately when using the dashboard, too so the ZW portion looks stable.
Something else a little frustrating. Since Thursday's update the shades have not worked once automatically. However, I've been changing the trigger time on that rule for the past 15min to have the rule trigger a few times, watching the ZW and hub logs, and all times (about 5 so far) the shades respond. I don't know why the original times don't want to work.
This has nothing to do with the automation, or the times involved. The rule clearly sent the command to the device. What happens with the device is a different matter. It's the driver that sends out Z-Wave commands, not the rule.
Please show the rule.
Sure...
Sorry to bug you with this, I appreciate your help. I know there are bigger fires you guys are dealing with.
Oh, side note, these are plugged in, there are no batteries even though it shows a battery level (the batteries were optional and I didn't use them). They're always awake.
Using the shade's device page, does it work when you put 40 into the setPosition box, and hit that command there? Perhaps before testing that, set the shades to the position they were at before the 9:00 rule ran.
Well 'unfortunately' it worked. I manually ran the close shades action to get them to 0 then ran the device using the set position and they all worked as expected.
If you didn't find anything in the code/driver that may be the issue then don't waste anymore of your time right now. I'll put all the rules back to the normal times and I'll open the logs (ZW and hub) and let you know what happens.
Thanks as always!
Whelp, @bravenel, sadly, they didn't close tonight at the trigger time. Here are the logs. The app triggered at 9pm on the nose, the shades indicated 'closing' but never did then I pressed the 'Run Action' button on the same app about 5 min later and they closed just fine.
App log...
Shade 214 ZW log
Shade 215 ZW log
Shade 214 Event log
Shade 215 Event log
Everything looks like it should have worked but it didn't, any ideas?
Not really. I suspect this is a device / mesh issue, but I don't know what that might be.
Turn on description logging in the device. I don't think the Z-Wave logs are useful for trouble shooting this. Capture the device logs isolated, like you are the app logs. Compare those two, see if there is any difference.
The visible difference in the events is the missing position event after the 9:00 event. If I were you, I'd test this with other times, not wait around all day until 9:00 or 8:00 in the morning. Try to catch it working or not working, look for log differences. It's not clear that the Z-Wave command ever gets to the device the first time. Are other things happening in your system at that same time -- other Z-Wave events for other devices?
That's the weird thing, when I edit the rules to trigger at times close to present the rules work as expected. I tried that this morning at least 5 times and it worked each time.
Nothing else is going on at these times and these rules have worked flawlessly since I integrated the hub about 2 weeks ago, it wasn't until I updated the latest FW on the hub and ZW that this issue occurred.
I'll keep digging and see if anything comes to light in the logs. If you come across anything then please let me know.
It smells from here to be a Z-Wave problem. Try rolling back to a prior version and see if it works as expected.
Just to check, there won't be an issue with the new ZW700 firmware interaction if I roll back the Hub FW?
I don't know. Just trying normal trouble shooting steps to isolate the problem.
Will do, thanks.
Hi @bravenel,
Just to give you an update. I was/am running .118 and .119, I did a ZW repair and it came up clean. I set the rules up to run the action, wait 1min, then run the action again. The first time the shades do not move (but HE indicates that they should, just like the logs you've seen before) but dead nuts 1min later they work as expected with the second call. I have it hooked to Alexa too and everytime I ask Alexa to move the shades they work, and I purposely did it sporadically throughout the day, it's really weird. It seems like it's only the first call of these automations after some ZW quiet time but it only affects the shades all my other timed automations worked perfect. This makes it hard to pinpoint where/when the issue is occurring since I can't 'make it happen' on demand. Knock on wood, everything else is working as expected so I'm going to leave it alone until next week. I'm off work next week and will try to downgrade and see what happens unless you or someone else uncovers something. Lemme know if you guys come across anything.
Thanks
Very odd.
It's baffling, I have been designing/programming/debugging industrial automation for close to 30yrs and I hate these scenarios. It usually ends up being something stupid, too; which is really irritating. I'll see if I can uncover anything... is there anyway to see what's actually being sent to/out of the ZW radio without buying extra hardware?
Hi @bravenel,
I've got more info for ya. Sorry for the long write-up but I wanted you to know that I did try many things to get to this conclusion. I've done some controlled tests and it's really strange but very repeatable. The shades do not appear to operate via automation when the rule is triggered on the hour (xx:00).
Because I like round numbers and the 1 minute delay I added in my routines worked, I set my automations to trigger at 8:59PM, 7:59am, and 8:59am, Figuring that the 1 minute delay would operate the shades on the hour like I wanted. But for 2 days the shades worked perfect at 8:59, and 7:59 (the 8:59am is for weekends) and the 1 minute delay didn't do anything as expected. So I put all my automations to trigger back on the hour (9:00pm, 8:00am, and 9:00am) for another day and they didn't work until the second command was issued after the 1 minute delay. When I got home today I set one to trigger at 6:00pm just to check other 'on the hour' time. The shades did not work, after the 1 minute delay they did. That meshes with my tests over last weekend, I was setting random times but none of them were on the hour (because I didn't feel like waiting). To prove out my theory this time I set the automation to the next hour and waited, and low and behold it didn't work. I set my night automation for 9:01pm tonight just for the heck of it to see what happens but I expect that they will work at 9:01 and not need the second command 1 minute later.
I hope this can point you to a place to look to see what's causing this.
Thanks, Mark
