Configuring zwave polling?

Configuration Z-Wave
1

Hello –

I’ve got zwave working (turning lights on and off) and I was looking at enabling polling to monitor energy use of an aeon power switch:

http://aeotec.com/z-wave-plug-in-switch/942-smart-energy-switch-manual-instructions.html

Based on the configuration (see below), I was expecting to poll the zwave device005 power every 2 minutes (polling frequency of 61 seconds, intensity of 2) and the other zwave elements every 5 minutes (polling frequency of 61 seconds intendity of 5). However, when looking at the OZW_log.txt file, it appears to be constantly polling.

Am I interpreting the logs properly? Assuming I want to poll once a minute, is there a recommended way to do that?

Thank you.

– charles

configuration/yaml:

zwave:
  usb_path: /dev/zwave
  config_path: /home/hass/src/home-assistant.upstream/build/python-openzwave/openzwave/config
  # polling is in milliseconds, so go with every 61 seconds.
  polling_interval: 61000
  customize:
    sensor.aeotec_smart_energy_switch_power_5:
      polling_intensity: 2
    sensor.aeotec_smart_energy_switch_energy_5:
      polling_intensity: 5
    sensor.aeotec_smart_energy_switch_power_6:
      polling_intensity: 5
    sensor.aeotec_smart_energy_switch_energy_6:
      polling_intensity: 5

OZW_log.txt:

2016-03-22 15:33:02.472 Info, Node005, Sending (Poll) message (Callback ID=0x87, Expected Reply=0x04) - MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x10, 0x25, 0x87, 0x61
2016-03-22 15:33:02.477 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:02.477 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:02.489 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x87, 0x00, 0x6e
2016-03-22 15:33:02.490 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x87 received (expected 0x87)
2016-03-22 15:33:02.490 Info, Node005, Request RTT 17 Average Request RTT 21
2016-03-22 15:33:02.490 Detail,   Expected callbackId was received
2016-03-22 15:33:02.500 Detail, Node005,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x05, 0x0e, 0x32, 0x02, 0x21, 0x74, 0x00, 0x00, 0x00, 0x00, 0x00, 0x04, 0x00, 0x00, 0x3f, 0xb8, 0x02
2016-03-22 15:33:02.500 Detail, 
2016-03-22 15:33:02.500 Info, Node005, Response RTT 28 Average Response RTT 31
2016-03-22 15:33:02.500 Detail, Node005, Refreshed Value: old value=false, new value=false, type=bool
2016-03-22 15:33:02.500 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:02.500 Info, Node005, Received Meter report from node 5: Power=0.000W
2016-03-22 15:33:02.500 Detail, Node005, Refreshed Value: old value=0.000, new value=0.000, type=decimal
2016-03-22 15:33:02.500 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:02.500 Info, Node005,     Previous value was 16.312W, received 4 seconds ago.
2016-03-22 15:33:02.500 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:02.500 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:02.500 Detail, Node005, Refreshed Value: old value=9, new value=4, type=int
2016-03-22 15:33:02.500 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:02.500 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:02.500 Detail, Node005,   Message transaction complete
2016-03-22 15:33:02.500 Detail, 
2016-03-22 15:33:02.500 Detail, Node005, Removing current message
2016-03-22 15:33:02.500 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:02.501 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:02.501 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:02.502 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:04.170 Detail, Node005, Polling: COMMAND_CLASS_SENSOR_MULTILEVEL index = 4 instance = 1 (poll queue has 0 messages)
2016-03-22 15:33:04.170 Detail, Node005, Queuing (Poll) SensorMultilevelCmd_Get (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x31, 0x04, 0x25, 0x88, 0x7a
2016-03-22 15:33:04.170 Detail, 
2016-03-22 15:33:04.170 Info, Node005, Sending (Poll) message (Callback ID=0x88, Expected Reply=0x04) - SensorMultilevelCmd_Get (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x31, 0x04, 0x25, 0x88, 0x7a
2016-03-22 15:33:04.175 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:04.175 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:04.187 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x88, 0x00, 0x61
2016-03-22 15:33:04.187 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x88 received (expected 0x88)
2016-03-22 15:33:04.187 Info, Node005, Request RTT 16 Average Request RTT 18
2016-03-22 15:33:04.187 Detail,   Expected callbackId was received
2016-03-22 15:33:04.195 Detail, Node005,   Received: 0x01, 0x0e, 0x00, 0x04, 0x00, 0x05, 0x08, 0x31, 0x05, 0x04, 0x64, 0x00, 0x00, 0x00, 0x00, 0xac
2016-03-22 15:33:04.195 Detail, 
2016-03-22 15:33:04.195 Info, Node005, Response RTT 25 Average Response RTT 28
2016-03-22 15:33:04.195 Info, Node005, Received SensorMultiLevel report from node 5, instance 1, Power: value=0.000W
2016-03-22 15:33:04.195 Detail, Node005, Refreshed Value: old value=0.000, new value=0.000, type=decimal
2016-03-22 15:33:04.195 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:04.195 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:04.195 Detail, Node005,   Message transaction complete
2016-03-22 15:33:04.195 Detail, 
2016-03-22 15:33:04.195 Detail, Node005, Removing current message
2016-03-22 15:33:04.195 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.866 Detail, Node005, Polling: COMMAND_CLASS_METER index = 0 instance = 1 (poll queue has 0 messages)
2016-03-22 15:33:05.866 Detail, Node005, Queuing (Poll) MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x00, 0x25, 0x89, 0x7f
2016-03-22 15:33:05.866 Detail, Node005, Queuing (Poll) MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x10, 0x25, 0x8a, 0x6c
2016-03-22 15:33:05.866 Detail, 
2016-03-22 15:33:05.866 Info, Node005, Sending (Poll) message (Callback ID=0x89, Expected Reply=0x04) - MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x00, 0x25, 0x89, 0x7f
2016-03-22 15:33:05.871 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:05.871 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:05.883 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x89, 0x00, 0x60
2016-03-22 15:33:05.883 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x89 received (expected 0x89)
2016-03-22 15:33:05.883 Info, Node005, Request RTT 17 Average Request RTT 17
2016-03-22 15:33:05.883 Detail,   Expected callbackId was received
2016-03-22 15:33:05.894 Detail, Node005,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x05, 0x0e, 0x32, 0x02, 0x21, 0x64, 0x00, 0x00, 0x3f, 0xb8, 0x00, 0x03, 0x00, 0x00, 0x3f, 0xb8, 0x92
2016-03-22 15:33:05.894 Detail, 
2016-03-22 15:33:05.894 Info, Node005, Response RTT 28 Average Response RTT 28
2016-03-22 15:33:05.894 Detail, Node005, Refreshed Value: old value=false, new value=false, type=bool
2016-03-22 15:33:05.894 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.894 Info, Node005, Received Meter report from node 5: Energy=16.312kWh
2016-03-22 15:33:05.894 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:05.894 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.894 Info, Node005,     Previous value was 16.312kWh, received 3 seconds ago.
2016-03-22 15:33:05.894 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:05.894 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.894 Detail, Node005, Refreshed Value: old value=4, new value=3, type=int
2016-03-22 15:33:05.894 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.894 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:05.894 Detail, Node005,   Message transaction complete
2016-03-22 15:33:05.894 Detail, 
2016-03-22 15:33:05.894 Detail, Node005, Removing current message
2016-03-22 15:33:05.894 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.895 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.895 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.895 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.895 Detail, 
2016-03-22 15:33:05.895 Info, Node005, Sending (Poll) message (Callback ID=0x8a, Expected Reply=0x04) - MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x10, 0x25, 0x8a, 0x6c
2016-03-22 15:33:05.901 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:05.901 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:05.913 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x8a, 0x00, 0x63
2016-03-22 15:33:05.913 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x8a received (expected 0x8a)
2016-03-22 15:33:05.913 Info, Node005, Request RTT 17 Average Request RTT 17
2016-03-22 15:33:05.913 Detail,   Expected callbackId was received
2016-03-22 15:33:05.923 Detail, Node005,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x05, 0x0e, 0x32, 0x02, 0x21, 0x74, 0x00, 0x00, 0x00, 0x00, 0x00, 0x03, 0x00, 0x00, 0x3f, 0xb8, 0x05
2016-03-22 15:33:05.923 Detail, 
2016-03-22 15:33:05.923 Info, Node005, Response RTT 27 Average Response RTT 27
2016-03-22 15:33:05.923 Detail, Node005, Refreshed Value: old value=false, new value=false, type=bool
2016-03-22 15:33:05.923 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.923 Info, Node005, Received Meter report from node 5: Power=0.000W
2016-03-22 15:33:05.923 Detail, Node005, Refreshed Value: old value=0.000, new value=0.000, type=decimal
2016-03-22 15:33:05.923 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.923 Info, Node005,     Previous value was 16.312W, received 3 seconds ago.
2016-03-22 15:33:05.923 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:05.923 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.923 Detail, Node005, Refreshed Value: old value=4, new value=3, type=int
2016-03-22 15:33:05.923 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:05.923 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:05.923 Detail, Node005,   Message transaction complete
2016-03-22 15:33:05.923 Detail, 
2016-03-22 15:33:05.923 Detail, Node005, Removing current message
2016-03-22 15:33:05.923 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.924 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.924 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:05.924 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.592 Detail, Node005, Polling: COMMAND_CLASS_METER index = 8 instance = 1 (poll queue has 0 messages)
2016-03-22 15:33:07.592 Detail, Node005, Queuing (Poll) MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x00, 0x25, 0x8b, 0x7d
2016-03-22 15:33:07.592 Detail, Node005, Queuing (Poll) MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x10, 0x25, 0x8c, 0x6a
2016-03-22 15:33:07.593 Detail, 
2016-03-22 15:33:07.593 Info, Node005, Sending (Poll) message (Callback ID=0x8b, Expected Reply=0x04) - MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x00, 0x25, 0x8b, 0x7d
2016-03-22 15:33:07.598 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:07.598 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:07.610 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x8b, 0x00, 0x62
2016-03-22 15:33:07.610 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x8b received (expected 0x8b)
2016-03-22 15:33:07.610 Info, Node005, Request RTT 17 Average Request RTT 17
2016-03-22 15:33:07.610 Detail,   Expected callbackId was received
2016-03-22 15:33:07.621 Detail, Node005,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x05, 0x0e, 0x32, 0x02, 0x21, 0x64, 0x00, 0x00, 0x3f, 0xb8, 0x00, 0x02, 0x00, 0x00, 0x3f, 0xb8, 0x93
2016-03-22 15:33:07.621 Detail, 
2016-03-22 15:33:07.621 Info, Node005, Response RTT 27 Average Response RTT 27
2016-03-22 15:33:07.621 Detail, Node005, Refreshed Value: old value=false, new value=false, type=bool
2016-03-22 15:33:07.621 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.621 Info, Node005, Received Meter report from node 5: Energy=16.312kWh
2016-03-22 15:33:07.621 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:07.621 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.621 Info, Node005,     Previous value was 16.312kWh, received 2 seconds ago.
2016-03-22 15:33:07.621 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:07.621 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.621 Detail, Node005, Refreshed Value: old value=3, new value=2, type=int
2016-03-22 15:33:07.621 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.621 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:07.621 Detail, Node005,   Message transaction complete
2016-03-22 15:33:07.621 Detail, 
2016-03-22 15:33:07.621 Detail, Node005, Removing current message
2016-03-22 15:33:07.621 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.621 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.621 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.621 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.621 Detail, 
2016-03-22 15:33:07.621 Info, Node005, Sending (Poll) message (Callback ID=0x8c, Expected Reply=0x04) - MeterCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x32, 0x01, 0x10, 0x25, 0x8c, 0x6a
2016-03-22 15:33:07.627 Detail, Node005,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2016-03-22 15:33:07.627 Detail, Node005,   ZW_SEND_DATA delivered to Z-Wave stack
2016-03-22 15:33:07.639 Detail, Node005,   Received: 0x01, 0x05, 0x00, 0x13, 0x8c, 0x00, 0x65
2016-03-22 15:33:07.639 Detail, Node005,   ZW_SEND_DATA Request with callback ID 0x8c received (expected 0x8c)
2016-03-22 15:33:07.639 Info, Node005, Request RTT 17 Average Request RTT 17
2016-03-22 15:33:07.639 Detail,   Expected callbackId was received
2016-03-22 15:33:07.650 Detail, Node005,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x05, 0x0e, 0x32, 0x02, 0x21, 0x74, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0x00, 0x00, 0x3f, 0xb8, 0x04
2016-03-22 15:33:07.650 Detail, 
2016-03-22 15:33:07.650 Info, Node005, Response RTT 28 Average Response RTT 27
2016-03-22 15:33:07.650 Detail, Node005, Refreshed Value: old value=false, new value=false, type=bool
2016-03-22 15:33:07.650 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.650 Info, Node005, Received Meter report from node 5: Power=0.000W
2016-03-22 15:33:07.650 Detail, Node005, Refreshed Value: old value=0.000, new value=0.000, type=decimal
2016-03-22 15:33:07.650 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.650 Info, Node005,     Previous value was 16.312W, received 2 seconds ago.
2016-03-22 15:33:07.650 Detail, Node005, Refreshed Value: old value=16.312, new value=16.312, type=decimal
2016-03-22 15:33:07.650 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.650 Detail, Node005, Refreshed Value: old value=3, new value=2, type=int
2016-03-22 15:33:07.650 Detail, Node005, Changes to this value are not verified
2016-03-22 15:33:07.650 Detail, Node005,   Expected reply and command class was received
2016-03-22 15:33:07.650 Detail, Node005,   Message transaction complete
2016-03-22 15:33:07.650 Detail, 
2016-03-22 15:33:07.650 Detail, Node005, Removing current message
2016-03-22 15:33:07.650 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.650 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.650 Detail, Node005, Notification: ValueChanged
2016-03-22 15:33:07.651 Detail, Node005, Notification: ValueChanged
2

Follow up for future reference…

Semi-resolved summary: It may be an issue with my zwave network. Some new zwave service commands are available in home-assistant versions 0.16 and 0.17 to help make zwave networks more reliable.

Details: Some zwave commands were added to version 0.16 which helped (zwave.soft_reset and zwave.heal_network - see the zwave component documentation for details). However, in my case even after I got the network to reliably poll every 2 minutes, eventually some nodes would timeout and be put in the “presumed dead” state. The upcoming version 0.17 has a zwave command (zwave.test_network) which may bring nodes back out of “presumed dead”, but the various google searches I did imply either I need more zwave nodes to increase the redundancy in the mesh network or my controller is having a bad day.

For now, going to give up on polling and try the “hail” feature so the nodes can inform the controller that data has changed and see what happens…

– charles

1 Like