Unwanted polling loop traffic causes z-wave slowdown

zwave
Tags: #<Tag:0x00007f0147bf1798>

(Ian) #1

One of my sensors occasionally goes into a polling loop. I’ve so far disabled the poll after a command update in the device’s config, and have now moved polling from 1 day to 10 days, but once polling starts, it doesn’t stop. It’s a Steinel external motion sensor and relay, used to switch on an external light.

dbReference 630
defaultAssociations 0,1
manufacturerId 0271
manufacturerRef 0002:1A72,0002:6770
modelId IS140-2
vendor Steinel

It’s Node64 in the attached log file. When it goes into the loop, it brings my z-wave network to its knees and floods the logs very quickly. I’ve been through the log with the log viewer but as I don’t know z-wave to the depth required, I don’t know if it’s a config, device, setup or binding error. It does work absolutely fine until polling starts though.

If anyone has the time can you please cast your eyes over this and let me know your thoughts. I would disable polling completely but this doesn’t seem to be an option.

Log file attached with .xml appended to name to get around forum limit.

node64.log.gz.xml (306.9 KB)


WakeupTimerTask -- what is it?
(Ian) #2

Of course now I see this… “Application Busy, try again later”. Not sure if it’s meaningful or not but it sounds like it is, I’m off to bed so will have to look it up tomorrow.


(Ian) #3

May have fixed this myself this morning, have set polling to 10 minutes to test my “fix”, we’ll see how it goes.


(Ian) #4

Seems to be OK now, after tracking down what endpoint 2 was (the one that keeps saying “try again later”) and finding it was set to send changes to an association which included the controller, I removed the controller from the association for that endpoint and the looping seems to have stopped. Polling every 10 minutes hasn’t provoked it into going crazy again so I’ll park this for now and keep an eye on it.


(Ian) #5

This issue has returned. Node 64, the steinel, is poll looping, despite the associations being set to just lifeline and switch (so I can see if the light is on or off). Polling is set to one day as that seems to be the longest I can set it for. Command polling is disabled.

What I suspect is going on here is that openhab is polling the luminance sensor (endpoint 2) but when there’s no light falling on it (luminance 0), it returns “endpoint busy”, I suspect this is the situation as the timing seems to match this, the poll loop has now ended after the light sensor sent a reading to openhab. From looking at my logs, the polling starts at about the same time every day (consistent with the polling period) and ends at the point at which daylight starts hitting the sensor (around 7:20).

Log here: zwave.log.gz.xml (91.3 KB)

Configuration of item is as follows:

openhab> smarthome:things show zwave:device:214d29fb:node64
UID: zwave:device:214d29fb:node64
Type: zwave:steinel_is1402_00_000
Label: External Motion Sensor
Status: ONLINE
Bridge: zwave:serial_zstick:214d29fb

Properties:
        zwave_class_basic : BASIC_TYPE_ROUTING_SLAVE
        zwave_class_generic : GENERIC_TYPE_SENSOR_NOTIFICATION
        zwave_frequent : false
        zwave_neighbours : 1,2,3,4,7,8,10,16,17,22,23,24,25,40,44,58,62,63
        modelId : IS140-2
        zwave_version : 0.48
        zwave_listening : true
        zwave_plus_devicetype : NODE_TYPE_ZWAVEPLUS_NODE
        manufacturerId : 0271
        manufacturerRef : 0002:1A72,0002:6770
        dbReference : 630
        zwave_deviceid : 6770
        zwave_nodeid : 64
        zwave_lastheal : 2018-11-27T04:09:14Z
        vendor : Steinel
        defaultAssociations : 0,1
        zwave_routing : true
        zwave_plus_roletype : ROLE_TYPE_SLAVE_ALWAYS_ON
        zwave_beaming : true
        zwave_secure : false
        zwave_class_specific : SPECIFIC_TYPE_NOTIFICATION_SENSOR
        zwave_manufacturer : 625
        zwave_devicetype : 2

Configuration parameters:
        binding_cmdrepollperiod : 0
        config_10_2 : 255
        group_4 : []
        group_1 : controller
        group_3 : []
        group_2 : controller
        switchall_mode : 0
        action_reinit : false
        nodename_name : 
        config_16_2 : 0
        config_12_2 : 0
        config_11_2 : 255
        config_13_2 : 110
        config_14_2 : 110
        config_15_1 : 10
        action_failed : false
        action_remove : false
        binding_pollperiod : 86400
        action_heal : false
        config_9_1_00000002 : 0
        config_1_2 : 10
        config_9_1_00000001 : 1
        config_9_1_00000004 : 0
        config_8_1 : 1
        config_9_1 : 1
        nodename_location : 
        config_2_2 : 2000
        config_5_1 : 60
        node_id : 64

Channels:
        ID: switch_binary
        Label: Switch
        Type: zwave:switch_binary
        Description: Switch the power on and off

        ID: scene_number
        Label: Scene Number
        Type: zwave:scene_number
        Description: Triggers when a scene button is pressed

        ID: sensor_binary
        Label: Binary Sensor
        Type: zwave:sensor_binary
        Description: Indicates if a sensor has triggered

        ID: sensor_luminance
        Label: Sensor (luminance)
        Type: zwave:sensor_luminance
        Description: Indicates the current light reading

        ID: alarm_burglar
        Label: Alarm (burglar)
        Type: zwave:alarm_burglar
        Description: Indicates if the burglar alarm is triggered

        ID: alarm_system
        Label: Alarm (system)
        Type: zwave:alarm_system
        Description: Indicates if a system alarm is triggered

        ID: alarm_burglar1
        Label: Alarm (burglar) motion
        Type: zwave:alarm_burglar
        Description: Indicates if the burglar alarm is triggered

        ID: sensor_luminance2
        Label: Sensor (luminance)
        Type: zwave:sensor_luminance
        Description: Indicates the current light reading

        ID: switch_binary3
        Label: Relay Switch
        Type: zwave:switch_binary
        Description: Switch the power on and off<a class="attachment"

(Ian) #6

Does anyone know how to stop polling on this device? It’s polling again and taking down my network, is there no way to stop polling for a device? Can I modify any XML anywhere?


(Mark) #7

I’m not aware of a way to disable polling.

@chris IIRC, isn’t there a way to set a channel as read-only. If so, would that be a possible solution in this case?


(Chris Jackson) #8

I suggest to make sure that the database is correct and that channels haven’t been added to endpoints that don’t really exist. This is the likely cause of this sort of thing - although it shouldn’t report “try again later” in this instance! :wink:


(Ian) #9

It works fine once the device has been powered off, including polling, it’s when the device returns “APPLICATION_BUSY” that it just hits it with another poll message. Right now for example I can hit the “refresh” button in habmin and it polls the device without problems, but this only lasts for a while before I wind up having to yank the power out of the device again. Are the polls triggered by the binding or is it something the device is doing to create the polling messages?


(Ian) #10

This is the device in the database, I’m not sure how to check if the database is correct though, I don’t remember the documentation being exactly wonderful!

https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/630


(Ian) #11

Just going through the manual, it looks OK for endpoint 2:

2 = AMBIENT LIGHT SENSOR
To endpoint 2 is mapped ambient light sensor functionality.
Device type = Sensor - Multilevel
Supported Command Classes:
COMMAND_CLASS_ZWAVEPLUS_INFO ( v2 )
COMMAND_CLASS_SENSOR_MULTILEVEL ( v4 )
COMMAND_CLASS_ASSOCIATION (v2)
COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION ( v3 )
COMMAND_CLASS_ASSOCIATION_GRP_INFO ( v1 )
Controlled Command Classes: No

(Mark) #12

I can’t remember. @chris Does the binding not poll channels that aren’t linked to items?

If that’s the case, maybe you can delete the item that’s linked to that channel. I realize you won’t be able to use the luminance feature of the device. But, as they say, pick your poison…


(Ian) #13

I’ve got three channels mapped, one to the burglar alarm (endpoint 1), another to the ambient light sensor (endpoint 2) and a third to the relay (endpoint 3). I’ve got two association groups set, one to “group 1 lifeline” (although Habmin and PaperUI keep losing this) and another to “group 2 Control key” (to send back motion events).

The ambient light sensor is something I’m quite keen on keeping and the device works fine until this weird loop starts, why would the binding be polling a device every 5 seconds?


(Mark) #14

Simple. It’s getting an APPLICATION_BUSY response from the device that says try again later.

To me, the real question is why the device is constantly returning busy, try later. Have you asked the manufacturer what’s wrong with their device?


(Ian) #15

I’ll try asking the manufacturer (which never seems to go anywhere) but as I’m running snapshots to deal with other problems with openhab I’m trying to exhaust this first.

I’ve noticed that other devices in the past have been problematic with polling and have had this turned off in the database, maybe this is another one of them? There’s no real need to poll this one as it returns all its results to associations.

These polling loops go on for hours, a poll every 5 seconds for 4 or 5 hours seems like a bit of a standoff, if there’s a way to end it on one side quickly that would be helpful.


(Ian) #16

I’ve sent steinel an email with the device config, a snapshot of the log viewer and an explanation of the issue and am hoping they send me something other than a recommendation that I run their controller software or something like that!


(Rossko57) #17

It does seem that it should not behave oddly just because there is no light. One could imagine a device bug where the firmware is waiting for a reading from light sensor (and so rejecting polls).

I guess you could put a hood over it and get it failing, as an exercise?


(Ian) #18

I shone a torch on it last night to get a light reading but it didn’t stop the polling loop so that may have been a red herring. It’s quiet at the moment so I’m just trying to get various other problems sorted until this one re-occurs, or the manufacturer replies to my email, or someone comes up with something I can do. As you pointed out in another thread, there are other devices that have polling problems and were worked around by MiCasaVerde to take that into account.


(Chris Jackson) #19

I will take a look to see if I can limit this (somehow). We probably could set some sort of counter on the number of retries following the “Try Again Later” message and if we hit that count, we don’t send further requests for some period of time.


(Ian) #20

Thanks, I’m running on a virtual machine so can test things and rewind if needed so if you want to try a dirty proof-of-concept then let me know, although I’m away from mid-Sunday on work so might be slow to respond after that until I get back.