Disable ZWave Polling 30 Minutes

[Ben (Ben A)]

I have a reasonably large (~100 node) ZWave network, mainly comprising dimmers, mains switches and USB-powered Aeotec MultiSensor 6 units:

On occasion the sensors fail to report a motion start or finish event. This creates a practical issue as these motion events control automatic lighting.

I have configured all devices to minimise unnecessary communications, such as only sending values as needed, setting unsolicited reporting intervals to low values (eg hourly) etc.

All ZWave things are configured for 86,400 second polling, as I do not need openHAB to poll them. Despite this, the debug log shows 84 unique devices over the past hour were polled a total of 227 times. While that’s only an average of one poll every 15 seconds, unfortunately the polling tends to concentrate. For example here we see 17 devices seemingly polled in the same second (these are window controllers):

2022-05-22 16:03:32.689 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 76: Polling...
2022-05-22 16:03:32.709 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 75: Polling...
2022-05-22 16:03:32.715 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 66: Polling...
2022-05-22 16:03:32.722 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 67: Polling...
2022-05-22 16:03:32.734 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 41: Polling...
2022-05-22 16:03:32.743 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling...
2022-05-22 16:03:32.748 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 72: Polling...
2022-05-22 16:03:32.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 122: Polling...
2022-05-22 16:03:32.761 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 71: Polling...
2022-05-22 16:03:32.766 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 77: Polling...
2022-05-22 16:03:32.790 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 74: Polling...
2022-05-22 16:03:32.791 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Polling...
2022-05-22 16:03:32.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 78: Polling...
2022-05-22 16:03:32.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 73: Polling...
2022-05-22 16:03:32.797 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 46: Polling...
2022-05-22 16:03:32.807 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 69: Polling...
2022-05-22 16:03:32.815 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 68: Polling...

More generally a 60 minute log when nothing is really happening in the house shows 2,065 ZWave receive events (grep "payload" openhab.log|grep Received|wc -l). That is one event every 1.74 seconds.

Any suggestions? It would appear preferable that polling happens as configured in the thing (ie 86,400 seconds, not 1,800), and polling has a network-wide rate limit (eg no more often than once every 5 - 10 seconds) so that devices wishing to send data have a reasonable chance to do so. Or is this really the responsibility of the MultiSensors to queue up their motion events and deliver it when they can, even if the network is flooded for a prolonged period? Or should I just split the ZWave network into 3 different zones (I had it configured this way in the past, but merged it into one to reduce failure modes)? Or don’t worry about it and solve it with software (eg make bigger lighting zones and require consensus of a few sensors to determine a zone’s likely presence state)?

[chris (Chris Jackson)]

It’s a bit hard to comment on what’s happening without seeing the logs so we can get the context of what is going on. Eg these 17 polls - when this this occur - did something trigger this? It seems strange they would be synchronised unless it was during startup or some other such event. Polling has some level of randomisation when it’s started so there shouldn’t be this sort of synchronisation unless something else in the system is sending a REFRESH command (since that will obviously poll the device to refresh the data).

@Ben

More generally a 60 minute log when nothing is really happening in the house shows 2,065 ZWave receive events

Again, it’s hard to comment on this without seeing the logs. Is this all due to polling, or device status reports, or what?

@Ben

Or is this really the responsibility of the MultiSensors to queue up their motion events and deliver it when they can

Yes, the devices will deliver data autonomously based on the configuration of the device. Often there’s a way to say “only report when the temperature changes by 1 degree” (etc) to reduce unnecessary reporting.

[Ben (Ben A)]

Thanks @chris. I have sent you an email with the log and ZWave device configuration settings.

[chris (Chris Jackson)]

Firstly, addressing the number of polls in the log -:

Polling is configured for 30 minutes in all devices I looked at. The log is 2hr 20min (140 min) long - if there’s 100 devices, you’d expect to see 140/30 polls - so 4.6 polls per device - or 460 polls. I see 465 polls in the log (searching for “polling…”). You need to remember that each device will normally have more than 1 channel, so there will be multiple polls per device - we see 1224 polls, which feels about right.

There’s some wierd stuff happening with node 84 -:

Likewise with node 37 -:

Node 32 looks mostly ok - it’s presumably a motion sensor and it’s triggering when people move around the house (I assume). I note though that it’s sending both the BASIC and ALARM reports - this might be something that can be reconfigured and the might halve the reports it sends.

I went through and looked at a bunch of other devices (just randomly) and most devices looked fine - a few reports, but otherwise just the standard 30 minute poll.

So, I guess there’s a couple of things to look at above, and you might want to use the log viewer to look through at a few other devices to see if there’s something strange. For the devices above that look like they are sending a lot of messages, you could try and reset them - however - it might not be their fault - it could be a network routing issue and this isn’t something you can easily see without a network sniffer.

@Ben

More generally a 60 minute log when nothing is really happening in the house shows 2,065 ZWave receive events (grep "payload" openhab.log|grep Received|wc -l). That is one event every 1.74 seconds.

This isn’t really a good thing to look at since this “Received” search will get all the low level communications between the binding and the controller. So you will also get all the ACK messages when a command is sent or received. If I instead search for “Application Command Request” which is logged when a command is received, then I see 2360 in this log which is about 8400 seconds long - so a frame every 3.5 seconds. 1224 of those come from polling (so broadly 1/2 of them), so if you reduce the polling from 30 minutes to a few hours, or a day, and it will really make a difference.

8233

I guess therefore we need to address this point -:

@Ben

All ZWave things are configured for 86,400 second polling

This is not what I see in the logs -:

NODE 112: Polling initialised at 1800 seconds

From what I can see, all nodes are set to 1800 seconds (so 30 minutes). The default in the binding is 86400 seconds, so I assume therefore that your devices must explicitly be set to 30 minutes. I would check this to see if the thing configuration really is 1 day, or 30 minutes.

Hopefully that was helpful - it was a bit of a random search of a couple of dozen devices, so there could be more issues, but in general I think it looks mostly ok, and the polling should be able to be reduced from the currently 30 minutes.

[Ben (Ben A)]

@chris

There’s some wierd stuff happening with node 84

This is a USB-powered MultiSensor. It reports its configuration as follows:

Parameter 9 per the engineering specs states “Value1 (MSB): 0x00=USB power mode”. The thing properties:

Why would a wake up notification even be sent to it?

@chris

Likewise with node 37

This sensor is some distance from the controller. I assume it’s re-sending frames that the controller doesn’t acknowledge.

@chris

I note though that it’s sending both the BASIC and ALARM reports - this might be something that can be reconfigured and the might halve the reports it sends.

I have changed this setting for all sensors to only send alarm reports (MultiSensor parameter 5 set to 2).

@chris

From what I can see, all nodes are set to 1800 seconds (so 30 minutes). The default in the binding is 86400 seconds, so I assume therefore that your devices must explicitly be set to 30 minutes. I would check this to see if the thing configuration really is 1 day, or 30 minutes.

I have never modified the polling interval from the default, and they are always 86400 in the admin UI. Let’s take node 77:

Here’s the log viewer for it, which shows 30 minute polls despite 86400 being the setting:

Anything else to try?

[chris (Chris Jackson)]

@Ben

Why would a wake up notification even be sent to it?

The notification is not being sent to the device - the device is sending it to the binding. Probably you have included this device when it was battery powered - it must be excluded, and then included with the power configured as you will use it. Currently the device is configured as a battery device - the device remembers the settings it had when it was included.

@Ben

Here’s the log viewer for it, which shows 30 minute polls despite 86400 being the setting:

As above, the configuration is set to 30 minutes - I’d suggest to check that it’s not set like this in the devices (ie each device - not the default in the controller).

[mhilbush (Mark)]

@chris

From what I can see, all nodes are set to 1800 seconds (so 30 minutes). The default in the binding is 86400 seconds, so I assume therefore that your devices must explicitly be set to 30 minutes. I would check this to see if the thing configuration really is 1 day, or 30 minutes.

@chris Depending on what version he’s running, do you think he might be the victim of what you fixed with this PR?

Set polling default to same as config description

Edit: The above PR was merged on March 12. So, if you are on a version of openHAB that doesn’t include that change, the polling interval will default to 1800 sec unless you set a new value by explicitly editing the polling interval in thing configuration.

[chris (Chris Jackson)]

@mhilbush

@chris Depending on what version he’s running, do you think he might be the victim of what you fixed with this PR?

Set polling default to same as config description by cdjackson · Pull Request #1747 · openhab/org.openhab.binding.zwave · GitHub

Yes, quite likely, but the only way out I think is to change each device explicitly to a different value (or edit the json files directly, but that’s the same thing, implemented in a different way)

[mhilbush (Mark)]

@chris

but the only way out

Or update to the most recent milestone (M5), which includes the fix.

[Ben (Ben A)]

I set all the devices to 86,399 seconds and restarted openHAB. This appears to have resolved the earlier issue.

I am still seeing a lot of traffic though. For example grep 13: openhab.log|grep "Application Command Request"|wc -l to narrow it to a full hour I see 1417 events, or one every 2.54 seconds.

I will email Chris the log again, just in case he has a moment and can comment if it looks normal. If it is normal, I would be interested to know whether this kind of traffic volume is “reasonable” or I should think about splitting the network.

[chris (Chris Jackson)]

I’d probably suggest to use the log viewer and try and understand what is happening. From my quick look, things do look (mostly!) ok. You seem to have quite a few sensors that are triggering a lot (often many times a minute, and each time these send two reports) -:

There are a few strange things I’ve spotted -:

This might be indicative of a problem with this device, or possibly an issue in the network.

Likewise with node 84 -:

So there are a few strange things here, but in general I don’t see any issues with the binding. I think it would be good for you to work through this - looking at the different devices to understand if traffic can be reduced (eg see if it’s possible to configure these sensors to only report one type of alarm). Maybe this isn’t possible, and it’s just a “feature” of your household (eg quite a few motion sensors that are triggering quite often).

@Ben

should think about splitting the network.

I’m not sure that splitting the network will help a lot - it may make things worse since you reduce your routing options. You will still have the same amount of traffic being sent though - the same reports etc. Splitting the traffic across two networks won’t reduce this, and as ZWave typically only uses a single channel (in practical terms anyway) the channel congestion at least will be the same. I think you’re better to try and use the viewer to understand what is happening with each device, and see if you can improve it. Devices that are misbehaving might require a reset to stop them flooding the network (this is something we do see occasionally) and reducing reporting where it’s not needed may also help.

[Ben (Ben A)]

Thanks @chris and @mhilbush. Having given it a few days, I have not observed any incorrect presence reporting since configuring all devices to 86,399 second polling and the MultiSensor change (parameter 5 set to 2).

The logs showing an alarm on then alarm off event very regularly is due to the configuration of the MultiSensors. They send a motion off event a configurable period after the last motion. For the MultiSensors I have this set to 60 seconds. A larger value is problematic as at night time I want the lights to quickly go off after motion ends. If I was designing this from scratch I’d pull in the data from alarm system PIRs instead. I have dozens of MultiSensors so it’s not really worth the effort at this point.

I will look more closely at the devices Chris identified and re-associate them. I will then take a deeper look at the traffic, but overall it seems to be working fairly well now.

[mhilbush (Mark)]

Glad you got it sorted out.