Z-wave Devices Spamming the log

[Jonopo]

What actual devices are you using in your original post

This That would be the "Basement" is what is in the "Basement" Group 2.0:

5 GE/Honeywell (Jasco) Z-wave Plus Switch
Device ID 12342
Device Type 18770
Clusters: in: 0x5E, 0x56, 0x86, 0x72, 0x5A, 0x85, 0x59, 0x73, 0x25, 0x27, 0x70, 0x2C, 0x2B, 0x7A, out:
Driver: Generic z-wave Smart Switch

3 Enerwave Z-wave-Plus Relays ZWN-RSM1-PLUS
Device ID: 1541
Device Type: 273
Clusters: in: 0x5E, 0x86, 0x72, 0x5A, 0x73, 0x25, 0x85, 0x59, 0x27, out:
Driver: Generic z-wave Switch

1 Securifi Peanut Smart Plug
16 bit Address: D50A
64 bit Address: 000D6F000A792B59
Device Type Id: 8
Driver: Generic Zigbee outlet

and do they exhibit this behaviour when operated from the driver page?

The Enerwave ZWN-RSM1-PLUS do not put out any logging even when turned on.

When I toggle the "Basement" group directly from the device panel I get a similar log as whats above. And a large number of the Honeywells even ones without other rules or apps on them do the same in the log.

The GE/Honeywell (Jasco) Z-wave Plus Switch "Craft Room Light" When completely isolated does not misbehave its usually has a rule or app (does not matter what type, you will get original log) that when it changes it turns on another honeywell. If that was still there I still got the log like in the original post. But whats interesting is when I turn it on and off in isolation with the app gone and nothing subscribed to the switch I got logs looking like this:

dev:99](http://192.168.1.50/logs#dev99)2019-07-13 11:19:08.775 am infoIron is off [physical]

dev:962019-07-13 11:19:08.128 am infoCraft Room Light was turned off[digital]

dev:962019-07-13 11:19:07.337 am infoCraft Room Light was turned on[digital]

dev:992019-07-13 11:19:07.073 am infoIron is off [physical]

dev:962019-07-13 11:19:06.365 am infoCraft Room Light was turned off[digital]

dev:962019-07-13 11:19:05.541 am infoCraft Room Light was turned on[digital]

dev:992019-07-13 11:19:05.289 am infoIron is off [physical]

dev:962019-07-13 11:19:04.503 am infoCraft Room Light was turned off[digital]

dev:962019-07-13 11:19:03.655 am infoCraft Room Light was turned on[digital]

dev:992019-07-13 11:19:03.394 am infoIron is off [physical]

dev:962019-07-13 11:19:02.322 am infoCraft Room Light was turned off[digital]

dev:962019-07-13 11:19:01.564 am infoCraft Room Light is on [physical]

dev:962019-07-13 11:19:01.474 am infoCraft Room Light was turned on[digital]

dev:992019-07-13 11:19:01.337 am infoIron is off [physical]

dev:992019-07-13 11:19:01.127 am infoIron is off [physical]

"Iron" only has alexa, google, and scenes to turn it off and neither were called during this.

"Iron" is in the same room as "Craft Room Light" and only exhibits the behavior with "Craft Room Light" being toggled. "Craft Room Alcove" which is also in the same room and is also a Honeywell does not exhibit the same behavior as "Craft Room Light" with "Iron".

"Iron" is this:
GE Z-Wave Plus Wireless Plug-In Outdoor Smart Switch
Device ID: 12338
Device Type: 20304
Clusters: in: 0x5E, 0x56, 0x86, 0x72, 0x5A, 0x85, 0x59, 0x73, 0x25, 0x27, 0x2C, 0x2B, 0x7A, out:
Driver: Generic Z-wave Outlet

[Jonopo]

So have you look into my last reply?

Thanks.

[mike.maxwell]

The dup reporting on the ourdoor outlet is due to that device using the incorrect driver.
Have a look in the compatable devices wiki for the correct driver to use.

[Jonopo]

@mike.maxwell

on the ourdoor outlet is due to that device using the incorrect driver.
Have a look in the compatable devices wiki for the correct driver to use.

So I looked up the supported devices here:

https://docs.hubitat.com/index.php?title=List_of_Compatible_Devices

and this is what it says:

GE
Plug-In Outdoor Smart Switch
12720/ZW4201
Outlet
Z-Wave Generic Z-Wave Outlet

which is what it is set as already. Is there a different website I should be looking at?

Here is the back of the device:

[mike.maxwell]

Ok that's the correct driver. I have three if these none of which do this.

[waynespringer79]

@mike.maxwell

Virtually ever unresponsive lock issue had been repeater mesh/related.

Occasionally I also see that this is sometimes device related as if all other methods don't restore communication, simply unplugging the battery pack on the lock waiting a few seconds and plugging back in the communication is instantly restored, but that's only if you know your mesh is great to begin with.

[Jonopo]

I've also noticed 2 things:

1. having an device event subscription makes the spamming worse. Tried it with Simple Lighting, Rule Machine, and a custom app. When I remove/pause these this spamming is greatly reduced. Maybe there is a bug in the subscription method?

2. having Groups 2.0 nested inside each other makes this issue more noticeable as the delay between lights turning on/off is greatly increased. up to 20 seconds. I made a rule to turn on/off the basement devices individually instead of using groups 2.0 based on a virtual switch and the lights are almost instant. I wonder if the Groups 2.0 is slowed down enough by the nesting to prevent all the on/off commands to be issued before the z-wave queue is overwhelmed?

[mike.maxwell]

@Jonopo

having an device event subscription makes the spamming worse. Tried it with Simple Lighting, Rule Machine, and a custom app. When I remove/pause these this spamming is greatly reduced. Maybe there is a bug in the subscription method?

this doesn't make any sense...
A subscription is simply an event listener in an app, in and of itself it's passive and has no interaction with the device directly.
Apps (to be of any value) then take actions on these events, most typically by sending commands to other devices.

@Jonopo

having Groups 2.0 nested inside each other makes this issue more noticeable as the delay between lights turning on/off is greatly increased. up to 20 seconds. I made a rule to turn on/off the basement devices individually instead of using groups 2.0 based on a virtual switch and the lights are almost instant. I wonder if the Groups 2.0 is slowed down enough by the nesting to prevent all the on/off commands to be issued before the z-wave queue is overwhelmed?

There probably isn't much value in nesting groups, it certainly wasn't designed with that in mind.

[Jonopo]

this doesn't make any sense...

none the less that is the behavior I have observed. Hence why I said maybe there is a bug.

There probably isn't much value in nesting groups

I use it to give alternate names to a device/Group (Group with one item) IE Downstairs/Basement and "Master Bath"/"Master Bathroom".

I also nest them to make to make logical collections so I can be specific in what I turn off/on

Here is an example (not everything) of some nesting:
Everything
_Upstairs - many groups and devices
_Basement
__Downstairs
___CraftRoom - 2 lights
___PlayRoom - 4 lights
___BackRooms - 4 lights

[Jonopo]

Just a FYI this behavior persist after the recent update.
Same Basement group from last time.
here is the log from that:

dev:742019-08-03 12:53:49.063 am infoStairs is on [physical]

dev:742019-08-03 12:53:48.503 am infoStairs is on [physical]

dev:942019-08-03 12:53:48.491 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:48.478 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:48.425 am infoStairs is on [physical]

dev:942019-08-03 12:53:48.370 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:48.221 am infoStairs is on [physical]

dev:942019-08-03 12:53:48.214 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:48.100 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.973 am infoStairs is on [physical]

dev:942019-08-03 12:53:47.938 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.916 am infoStairs is on [physical]

dev:942019-08-03 12:53:47.890 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:47.853 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:47.841 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.830 am infoStairs is on [physical]

dev:942019-08-03 12:53:47.747 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:47.739 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.622 am infoStairs is on [physical]

dev:742019-08-03 12:53:47.553 am infoStairs is on [physical]

dev:942019-08-03 12:53:47.532 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:47.519 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.454 am infoStairs is on [physical]

dev:942019-08-03 12:53:47.346 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:47.104 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:47.076 am infoStairs is on [physical]

dev:742019-08-03 12:53:46.999 am infoStairs is on [physical]

dev:942019-08-03 12:53:46.406 am infoPlay Room Light is on [physical]

dev:972019-08-03 12:53:46.374 am infoCraft Room Alcove is on [physical]

dev:942019-08-03 12:53:46.322 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:46.295 am infoPlay Room Light is on [physical]

dev:972019-08-03 12:53:46.265 am infoCraft Room Alcove is on [physical]

dev:942019-08-03 12:53:45.509 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:45.417 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:45.362 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:45.283 am infoStairs is on [physical]

dev:972019-08-03 12:53:45.264 am infoCraft Room Alcove is on [physical]

dev:942019-08-03 12:53:44.977 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:44.952 am infoStairs is on [physical]

dev:942019-08-03 12:53:44.903 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:44.792 am infoStairs is on [physical]

dev:942019-08-03 12:53:44.052 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:43.728 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:43.439 am infoPlay Room Light is on [physical]

dev:742019-08-03 12:53:42.930 am infoStairs is on [physical]

dev:742019-08-03 12:53:42.819 am infoStairs is on [physical]

dev:942019-08-03 12:53:42.653 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:42.591 am infoCraft Room Light is on [physical]

dev:942019-08-03 12:53:42.563 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:42.532 am infoCraft Room Light is on [physical]

dev:742019-08-03 12:53:42.500 am infoStairs is on [physical]

dev:962019-08-03 12:53:42.096 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:42.084 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:42.061 am infoCraft Room Alcove is on [physical]

dev:962019-08-03 12:53:41.813 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:41.749 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:41.709 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:41.681 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:41.668 am infoCraft Room Alcove is on [physical]

dev:962019-08-03 12:53:41.657 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:41.607 am infoCraft Room Alcove is on [physical]

dev:962019-08-03 12:53:41.596 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:41.519 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:41.471 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:41.453 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:41.398 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:41.365 am infoCraft Room Alcove is on [physical]

dev:742019-08-03 12:53:41.265 am infoStairs is on [physical]

dev:962019-08-03 12:53:41.189 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:41.149 am infoCraft Room Light is on [physical]

dev:742019-08-03 12:53:41.012 am infoStairs is on [physical]

dev:962019-08-03 12:53:40.931 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:40.899 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:40.881 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:40.412 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:40.356 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:40.325 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:39.878 am infoCraft Room Light is on [physical]

dev:962019-08-03 12:53:39.807 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:39.724 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:39.686 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:39.649 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:38.981 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:38.817 am infoCraft Room Alcove is on [physical]

dev:942019-08-03 12:53:38.730 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:38.502 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:38.435 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:38.406 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:38.311 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:38.307 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:37.436 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:37.294 am infoCraft Room Alcove is on [physical]

dev:7722019-08-03 12:53:37.208 am infoFoot Massager power is 0W

dev:7712019-08-03 12:53:37.102 am infoOffice Heater power is 0W

dev:972019-08-03 12:53:37.035 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:36.621 am infoCraft Room Alcove is on [physical]

dev:972019-08-03 12:53:36.590 am infoCraft Room Alcove is on [physical]

dev:962019-08-03 12:53:36.575 am infoCraft Room Light is on [physical]

dev:972019-08-03 12:53:36.519 am infoCraft Room Alcove was turned on[digital]

dev:942019-08-03 12:53:36.386 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:36.334 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:36.058 am infoCraft Room Light is on [physical]

dev:942019-08-03 12:53:35.785 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:35.763 am infoCraft Room Light is on [physical]

dev:942019-08-03 12:53:35.720 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:35.647 am infoCraft Room Light is on [physical]

dev:942019-08-03 12:53:35.613 am infoPlay Room Light is on [physical]

dev:962019-08-03 12:53:35.560 am infoCraft Room Light was turned on[digital]

dev:742019-08-03 12:53:35.153 am infoStairs is on [physical]

dev:742019-08-03 12:53:34.834 am infoStairs is on [physical]

dev:942019-08-03 12:53:34.193 am infoPlay Room Light is on [digital]

dev:742019-08-03 12:53:33.542 am infoStairs is on [physical]

app:5472019-08-03 12:53:33.469 am debugcontactOpenHandler Ignored elapsed: 725, lastId: Play Room Hall , currentId: Stairs

dev:742019-08-03 12:53:33.289 am infoStairs was turned on[digital]

app:5472019-08-03 12:53:32.715 am debugcontactOpenHandler Ignored elapsed: 386, lastId: Play Room Hall , currentId: Play Room Light

dev:942019-08-03 12:53:32.632 am infoPlay Room Light is on [physical]

dev:942019-08-03 12:53:32.460 am infoPlay Room Light was turned on[digital]

app:5472019-08-03 12:53:32.425 am debugcontactOpenHandler Ignored lastState: on

app:5472019-08-03 12:53:32.416 am debugcontactOpenHandler Handled elapsed: 108088, currentId:Play Room Hall , evt.value: on

dev:1812019-08-03 12:53:30.646 am infoBasement switch was turned on

dev:1802019-08-03 12:53:30.601 am infoDownstairs switch was turned on

dev:1622019-08-03 12:53:30.442 am infoCraft Room switch was turned on

dev:1012019-08-03 12:53:30.386 am infoGuest Bathroom was turned on[digital]

dev:1702019-08-03 12:53:30.054 am infoPlay Room switch was turned on

dev:1772019-08-03 12:53:29.783 am infoBack Rooms switch was turned on

[Dhorlo]

I thought this was normal behavior until I read this post. I've been having this issue since I started looking at the logs practically at day one. My logs fill up so much with repeated entries that I have never been able to go back further than 12 hours.

I've been having issues with Mode Manager not changing modes as well as random unresponsiveness. I'm been giving some serious thought to doing a soft reset to see if that will help.

[codahq]

This one is very frustrating.

The only thing that fired was this simple rule:

Nothing else going on. All drivers OOB/recommended drivers. After this spam happens the subsequent events are delayed. There is potential for this to occur it seems ANY time more than one Z-Wave device is controlled at a time.

[rich.princeau]

I'm not much good on rules, but I think you have set up an endless loop between 8:pm and sunrise. The log is reflecting what you told it do do. Just for a test turn off the lights at 8PM only and check the logs.

[codahq]

I don't think that's how rules work. If I look at my event subscriptions I just have one for sunrise. If I were to restart the hub right now with those nightlights off that rule would not run again until sunrise even though it is still true. It's not repeating the action throughout the duration of the true condition. It evaluates it once and runs it when one of those conditions is met. The same is true of when it started. It schedules events based on when the conditions become true and false and run the appropriate actions at those times.

It doesn't matter even if what you were describing was true. I can put this same action in a button controller or use group actuator switch and recreate the same result a lot of the time. It happens outside of RM often so RM is not even a factor.

[storageanarchy]

You might want to try implementing this using Hubitat Simple Lighting instead of Rule Machine. Create 2 new instances:

• Turn on at 8pm
• Turn off at Sunrise

[mike.maxwell]

That's crazy, what devices are these?
I've never seen anything this bad before...

[cuboy29]

I just noticed this while doing a zwave repair. This normally does not happen for this device. It seems when the mesh is busy, you end up with these repeating message. I doubt that the device is sending this on its own.

[codahq]

I have a support ticket open for it. So far not a lot has been found out. Bobby hasn't given me any updates but it might be out of his hands. These particular devices are GE Z-Wave Plus outlets using the "Generic Z-Wave Outlet" OOB device driver. More often than not when spam is involved one of these devices is also in the log.

[ady.adrianu]

i have the same problem ,my aeotec 6 in 1 motion sensor reports motion active/inactive multiple times too in logs but on device history is correct.
seriously 2 years later nobody has fixed these problems?

[bcopeland]

if you ever looked at this device on zniffer, you would see it is very spammy.. I removed all of them from my network, as they just talk too much.