Nodes sending data multiple times

mnl1121 · November 10, 2020, 8:13pm

Hi everyone, I recently noticed my zwave network has been very slow, possibly with the update to .117.5 (I upgrade from .117.4. Before .116, I was on .116.4, so I’m keeping up with updates). The network is also taking a very long time to start up as well, close to 45 minutes. I have about 50+ nodes so it’s a fairly large network, but I believe in the past it used to take maybe 5-10 minutes or so.

Anyway, I noticed in the logs that nodes are sending data multiple times. For example I have an Aeotec Nano Switch 6 connected to my washing machine’s outlet that is reporting power consumption. Below is from my Zwave logs showing the node reporting the same Amp rating 8 times in the span of about half a second (reporting is configured to once a minute). Anyone have any ideas why? I haven’t tried downgrading to .116 yet as I’ve added the Xbox Integration and that would be broken, but I can if need be.

2020-11-10 15:06:12.697 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:12.697 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.697 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:12.697 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:12.697 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.697 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.702 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.791 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:12.791 Detail,
2020-11-10 15:06:12.791 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:12.791 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.791 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:12.791 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:12.791 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.791 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.794 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.870 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:12.870 Detail,
2020-11-10 15:06:12.870 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:12.870 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.870 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:12.870 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:12.870 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.870 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.877 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.932 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:12.932 Detail,
2020-11-10 15:06:12.932 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:12.932 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.932 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:12.932 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:12.932 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.932 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.935 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.962 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:12.962 Detail,
2020-11-10 15:06:12.962 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:12.962 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.962 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:12.962 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:12.962 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:12.962 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:12.967 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.025 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:13.025 Detail,
2020-11-10 15:06:13.025 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:13.025 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.025 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:13.025 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:13.025 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.025 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.028 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.129 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:13.129 Detail,
2020-11-10 15:06:13.129 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:13.129 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.129 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:13.129 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:13.129 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.129 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.135 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.180 Detail, Node066,   Received: 0x01, 0x10, 0x00, 0x04, 0x10, 0x42, 0x0a, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x00, 0x26, 0x00, 0x00, 0x68
2020-11-10 15:06:13.180 Detail,
2020-11-10 15:06:13.180 Detail, Node066, Refreshed Value: old value=false, new value=false, type=bool
2020-11-10 15:06:13.180 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.180 Info, Node066, Received Meter report from node 66: Current=0.038A
2020-11-10 15:06:13.180 Detail, Node066, Refreshed Value: old value=0.038, new value=0.038, type=decimal
2020-11-10 15:06:13.180 Detail, Node066, Changes to this value are not verified
2020-11-10 15:06:13.180 Detail, Node066, Notification: ValueChanged
2020-11-10 15:06:13.185 Detail, Node066, Notification: ValueChanged

M0E-lnx · November 10, 2020, 8:46pm

This looks awfully similar to a problem I had.

See here: OZW stuck on "Starting Z-Wave Network... This may take a while depending on the size of your network."

I resolved the issue by replacing the node that kept sending out the data. You may try removing that Node066 from your network and see if the problem goes away, i’m almost certain it will.

mnl1121 · November 10, 2020, 9:09pm

Node66 isn’t the only node that is sending out multiple data. I should have mentioned most of my nodes are. However you gave me an idea. I recently had a node that started acting up. It routinely dies (no idea why) every couple of months. I normally have to use remove or replace failed node and reconfigure it. However this time I used replace failed node and I didn’t have to reconfigure it. It miraculously came back to life, but it’s still acting strange, like turning on when I didn’t ask it to or generally being unresponsive.

I’m going to try removing it and see how it goes.

M0E-lnx · November 10, 2020, 9:23pm

In my case it took a little bit of a quest to figure out which one it was, but essentially it’s a failing node. I would start by sifting through the logs and seeing the most active ones and remove them one by one until you see the problem go away. Then start adding them back in and see how the network reacts.

mnl1121 · November 10, 2020, 9:25pm

You were exactly right, thanks so much. It was the node that I mentioned in my last comment that was failing. I wasn’t able to gracefully remove it, however once I reset the device HA noticed immediately it was dead. Once I did that all my other nodes started working normally again! My theory is that my other nodes were trying to route through the failing node and it was taking too long and thus were sending multiple requests.

M0E-lnx · November 10, 2020, 9:32pm

You were probably seeing the traffic passing through other nodes.

I ended up having to replace that node. You may try adding it again and see if it does the same thing again. If it does, you may have no choice but to get rid of it.

Glad it worked out for ya

mnl1121 · November 10, 2020, 9:43pm

Ah that could have been what I was seeing. Would be nice if the zwave logs indicated that.