Z-Wave Device no Ack issue

Hi Matt

Was wondering whether could offer comment and help about the below Z-wave issue?

Basically have been running Z-Wave Gen5 stick without trouble for sometime - about 100 or so Z-wave devices.

Recently three AeonLabs ZW096 Smart Switches have been 'no ack' and failing to respond.
If I manually turned on/off, would seem to respond again for a while.

I have updated MaC Mini and restarted
I have tried factory resetting the device
I have excluded and reincluded the device.
I have replaced (yep! the Z-wave stick with a Backup and Restore via Aeonlabs windows app - which was very straight-forward and everything except these devices back going; including locks)
Once I turn on/turn off multiple times manually I can usually define and sync again.

Problem persists...

This is one of the switches

Code: Select all

   Indigo Z-Wave Version: 2.0.119
Node ID: [b]113[/b]
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: 2, 5, 7, 8, 9, 10, 11, 12, 14, 15, 16, 29, 31, 35, 36, 37, 38, 39, 42, 43, 44, 46, 47, 48, 51, 56, 59, 60, 72, 73, 74, 93, 95, 102, 107, 108, 111
Associations: 1:[1] 2:[]
Config Values: 112:600 3:1 101:12 102:0 113:600 252:0 103:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5

& this from Z-wave debug is the what I receive when attempt to turn-on/turn-off:

Node 113 - is Xbox Room -Power

Code: Select all

   Z-Wave Debug                    SENT setRelayValue: 01 0A 00 13 71 03 25 01 00 25 24 B1
   Z-Wave Debug                    RCVD setRelayValue: 01 07 00 13 24 01 03 3D F0 (node NAK)
   Z-Wave Debug                    . .  setRelayValue: requeuing 3 unsolicited packets
   Z-Wave Error                    send "Xbox Room - Power" off failed
   Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 2D 06 31 05 03 0A 02 10 F3
   Z-Wave Debug                    . .  requestVarSensorStatus: node 045, endpoint None, type 3, raw value 0A02...
   Z-Wave Debug                    . .  requestVarSensorStatus: 528 lux (float: 528.000000)


Code: Select all

   Z-Wave Debug                    SENT setRelayValue: 01 0A 00 13 71 03 25 01 00 25 32 A7
   Z-Wave Debug                    RCVD setRelayValue: 01 07 00 13 32 01 03 56 8D (node NAK)
   Z-Wave Error                    send "Xbox Room - Power" off failed

Code: Select all

   Z-Wave Debug                    SENT setRelayValue: 01 0A 00 13 71 03 25 01 00 25 3B AE
   Z-Wave Debug                    RCVD setRelayValue: 01 07 00 13 3B 01 03 1C CE (node NAK)
   Z-Wave Error                    send "Xbox Room - Power" off failed

Code: Select all

   Z-Wave Debug                    SENT setRelayValue: 01 0A 00 13 71 03 25 01 FF 25 3E 54
   Z-Wave Debug                    RCVD setRelayValue: 01 07 00 13 3E 01 03 1F C8 (node NAK)
   Z-Wave Error                    send "Xbox Room - Power" on failed

Code: Select all

   Z-Wave Debug                    RCVD requestRelayStatus: 01 07 00 13 40 01 03 48 E1 (node NAK)
   Z-Wave Debug                    . .  requestRelayStatus: requeuing 4 unsolicited packets
   Z-Wave Error                    send "Xbox Room - Power" status request failed

Code: Select all

   Z-Wave Debug                    SENT requestRelayStatus: 01 09 00 13 71 02 25 02 25 43 D7
   Z-Wave Debug                    RCVD requestRelayStatus: 01 07 00 13 43 01 03 15 BF (node NAK)
   Z-Wave Debug                    . .  requestRelayStatus: requeuing 1 unsolicited packets
   Z-Wave Error                    send "Xbox Room - Power" status request failed

Code: Select all

   Z-Wave Debug                    SENT sendRawZwaveCommand: 01 0A 00 13 71 03 25 01 FF 25 4B 21
   Z-Wave Debug                    RCVD sendRawZwaveCommand: 01 07 00 13 4B 01 03 26 84 (node NAK)
   Z-Wave Debug                    . .  sendRawZwaveCommand: requeuing 1 unsolicited packets
   Z-Wave Error                    send "Xbox Room - Power" raw command failed [25 01 FF]

Code: Select all

   Z-Wave Debug                    SENT sendRawZwaveCommand: 01 0A 00 13 71 03 20 01 FF 25 4E 21
   Z-Wave Debug                    RCVD sendRawZwaveCommand: 01 07 00 13 4E 01 03 30 97 (node NAK)
   Z-Wave Error                    send "Xbox Room - Power" raw command failed [20 01 FF]

& then this one randomly worked!

Code: Select all

   Z-Wave Debug                    RCVD relaySetLevel: 01 09 00 04 00 71 03 20 03 FF 5C
   Z-Wave Debug                    . .  relaySetLevel: node 113, endpoint None, value 255
   Z-Wave                          received "Xbox Room - Power" status update is on

This bit here seems important to me??
RCVD setRelayValue: 01 07 00 13 24 01 03 3D F0 (node NAK)

Seems strange to me that same issue randomly starts with x3 AeonLabs devices at the same time?


Thanks!

Glenn

[matt (support)]

Open the Event Log file (button at the top of the Event Log window will show it in the Finder) and find in the file a few examples where it fails, then copy/paste those lines along with about 10 seconds before and after the actual failure into a reply for me. The actual Event Log file will have timestamps on every line and I'd like to get a better idea of what all is going on with your Z-Wave network around the time of the failure(s).

Thanks Matt for reply

This is a different device example - the earlier AeonLabs Switch ZW096 I have excluded, factory reset and then firmware updated with AeonLabs Windows tool (to same version).
Same issue - currently it is installed right next to Indigo and Z-Stick and there it works.... (only reports one neighbour - when should report about 20!)
(Currently using the new Z-Wave stick, but yesterday was using old and same issue with both)

Odd to me that the 3-4 Switches all would have the same issue at the same time... but very much leaning towards this being a Aeon issue, but certainly interested in your take.

After a lot of looking at Network and optimising it seems that these problematic devices NEVER show up as others neighbours after optimisation.

I have optimised devices very close to them and essentially they appear never to be added to these close devices neighbour lists.
Obviously that could be the because of issues they are having or cause of issues if mesh topology buggered for them.

I have opened a ticket with Aeonlabs to see at least if they can send me new firmware (apparently there is firmware 1.6)

Copied below, just attempted turn on which failed, reasonable period of traffic - but isn't always and have dropped energy reporting times for them (took a while because of communication issues) to 1800 or greater.

You see in this example that it does fail to response to on/off, but then fails with energy reports - even though seems to receive reports?

Code: Select all

Indigo Z-Wave Version: 2.0.120
Node ID: 110
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: 3, 5, 7, 16, 31, 37, 40, 48, 51, 54, 56, 57, 59, 60, 72, 95, 107
Associations: 1:[1] 2:[]
Config Values: 3:0 20:0 80:2 81:0 83:1774619 84:3289650 90:0 91:25 92:5 101:12 102:0 103:0 111:600 112:600 113:600 252:0


Code: Select all

2019-03-31 08:37:06.214   DEBUG   . . . . . . . : skipping battery check (next check in 596 mins)
2019-03-31 08:37:06.214   DEBUG   SENT goToSleep: 01 09 00 13 63 02 84 08 24 E0 CC
2019-03-31 08:37:06.233   DEBUG   RCVD packet: 01 07 00 13 E0 00 00 01 0A (hex)
2019-03-31 08:37:11.976   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 29 0E 32 02 21 64 00 15 73 90 02 58 00 15 73 90 E7
2019-03-31 08:37:11.976   DEBUG   . .  requestMeterLevel: node 041, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:11.976   DEBUG   . .  requestMeterLevel: 1405.840 kWh (float: 1405.840000)
2019-03-31 08:37:24.677   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 E1 94
2019-03-31 08:37:24.972   DEBUG   . .  setRelayValue: requeuing 1 unsolicited packets
2019-03-31 08:37:24.972   INFO   sent "Projector Room - Power - Smart Switch 6 (ZW096)" on
2019-03-31 08:37:24.972   DEBUG   queueing energy request of "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (activity detected)
2019-03-31 08:37:24.972   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 08:37:24.973   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 08:37:30.710   DEBUG   polling status of node "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (post-activity energy request)
2019-03-31 08:37:30.733   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 00 25 E2 7F
2019-03-31 08:37:31.172   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 6E 00 54 00 00 30 6E 00 00 00 00 BE
2019-03-31 08:37:31.172   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:31.172   DEBUG   . .  requestMeterLevel: 12.398 kWh (float: 12.398000)
2019-03-31 08:37:31.173   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 10 25 E3 6E
2019-03-31 08:37:31.748   DEBUG   RCVD requestMeterLevel: 01 07 00 13 E3 01 00 37 3E (node NAK)
2019-03-31 08:37:31.749   DEBUG   . .  requestMeterLevel: requeuing 1 unsolicited packets
2019-03-31 08:37:31.749   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" requestMeterLevel command failed (module might be asleep, or is unreachable)
2019-03-31 08:37:31.749   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 6E 00 54 00 00 30 6E 00 00 00 00 BE
2019-03-31 08:37:31.749   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:31.749   DEBUG   . .  requestMeterLevel: 12.398 kWh (float: 12.398000)
2019-03-31 08:37:32.028   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 6E 00 00 00 00 30 6E 00 00 00 00 EA
2019-03-31 08:37:32.028   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:32.028   DEBUG   . .  requestMeterLevel: 12.398 kWh (float: 12.398000)
2019-03-31 08:37:32.656   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 6E 00 00 00 00 30 6E 00 00 00 00 EA
2019-03-31 08:37:32.657   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:32.657   DEBUG   . .  requestMeterLevel: 12.398 kWh (float: 12.398000)
2019-03-31 08:37:35.938   DEBUG   SENT setRelayValue: 01 0A 00 13 82 03 25 01 00 25 E4 82
2019-03-31 08:37:36.116   INFO   sent "Kitchen - Water Cooler Power" off
2019-03-31 08:37:36.116   DEBUG   queueing energy request of "130 - Kitchen - Water Cooler Power" (activity detected)
2019-03-31 08:37:36.236   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 82 03 20 03 00 50
2019-03-31 08:37:36.236   DEBUG   . .  relaySetLevel: node 130, endpoint None, value 0
2019-03-31 08:37:41.728   DEBUG   polling status of node "130 - Kitchen - Water Cooler Power" (post-activity energy request)
2019-03-31 08:37:41.779   DEBUG   SENT requestMeterLevel: 01 0A 00 13 82 03 32 01 00 25 E5 94
2019-03-31 08:37:42.206   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 82 12 32 02 21 64 00 01 D2 69 00 91 00 01 D2 69 00 00 00 00 97
2019-03-31 08:37:42.206   DEBUG   . .  requestMeterLevel: node 130, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:42.206   DEBUG   . .  requestMeterLevel: 119.401 kWh (float: 119.401000)
2019-03-31 08:37:42.207   DEBUG   SENT requestMeterLevel: 01 0A 00 13 82 03 32 01 10 25 E6 87
2019-03-31 08:37:42.642   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 82 12 32 02 21 74 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16
2019-03-31 08:37:42.642   DEBUG   . .  requestMeterLevel: node 130, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:37:42.642   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 08:37:54.626   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 66 0E 32 02 21 64 00 03 37 53 02 58 00 03 37 53 A8
2019-03-31 08:37:54.627   DEBUG   . .  requestMeterLevel: node 102, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:37:54.627   DEBUG   . .  requestMeterLevel: 210.771 kWh (float: 210.771000)
2019-03-31 08:39:00.340   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 08:39:00.340   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 08:39:00.341   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 08:39:00.341   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 08:39:00.341   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 08:39:00.341   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0006 secs)
2019-03-31 08:39:27.992   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1E 03 20 01 FF 31
2019-03-31 08:39:27.992   DEBUG   . .  sensorSetLevel: node 030, endpoint None, cmdClass 20, value 255
2019-03-31 08:39:27.992   INFO   received "Bathroom - Downstairs - Motion Sensor" status update is on
2019-03-31 08:39:47.451   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1E 03 20 01 00 CE
2019-03-31 08:39:47.451   DEBUG   . .  sensorSetLevel: node 030, endpoint None, cmdClass 20, value 0
2019-03-31 08:39:47.452   INFO   received "Bathroom - Downstairs - Motion Sensor" status update is off
2019-03-31 08:39:50.686   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1E 03 20 01 FF 31
2019-03-31 08:39:50.687   DEBUG   . .  sensorSetLevel: node 030, endpoint None, cmdClass 20, value 255
2019-03-31 08:39:50.687   INFO   received "Bathroom - Downstairs - Motion Sensor" status update is on
2019-03-31 08:40:06.043   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 08:40:06.044   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 08:40:06.044   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 08:40:06.044   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 08:40:06.044   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 08:40:06.044   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0005 secs)
2019-03-31 08:40:17.499   DEBUG   RCVD requestDimmerStatus: 01 09 00 04 00 1D 03 26 03 00 C9
2019-03-31 08:40:17.499   DEBUG   . .  requestDimmerStatus: node 029, endpoint None, value 0
2019-03-31 08:40:17.499   INFO   received "Bathroom Downstairs - Light" status update is off
2019-03-31 08:40:24.542   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 08:40:24.542   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 08:40:24.542   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 08:40:24.560   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 08:40:24.560   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 08:40:24.560   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0181 secs)
2019-03-31 08:40:27.449   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1E 03 20 01 00 CE
2019-03-31 08:40:27.449   DEBUG   . .  sensorSetLevel: node 030, endpoint None, cmdClass 20, value 0
2019-03-31 08:40:27.449   INFO   received "Bathroom - Downstairs - Motion Sensor" status update is off
2019-03-31 08:40:50.666   DEBUG   SENT setRelayValue: 01 0A 00 13 82 03 25 01 FF 25 E7 7E
2019-03-31 08:40:50.847   INFO   sent "Kitchen - Water Cooler Power" on
2019-03-31 08:40:50.847   DEBUG   queueing energy request of "130 - Kitchen - Water Cooler Power" (activity detected)
2019-03-31 08:40:50.964   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 82 03 20 03 FF AF
2019-03-31 08:40:50.964   DEBUG   . .  relaySetLevel: node 130, endpoint None, value 255
2019-03-31 08:40:55.304   DEBUG   SENT setRelayValue: 01 0A 00 13 82 03 25 01 00 25 E8 8E
2019-03-31 08:40:55.440   INFO   sent "Kitchen - Water Cooler Power" off
2019-03-31 08:40:55.441   DEBUG   ignoring duplicate energy request of "130 - Kitchen - Water Cooler Power" (activity detected)
2019-03-31 08:40:55.566   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 82 03 20 03 00 50
2019-03-31 08:40:55.566   DEBUG   . .  relaySetLevel: node 130, endpoint None, value 0
2019-03-31 08:40:59.946   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 00 25 E9 63
2019-03-31 08:41:00.338   INFO   sent "Projector Room - Power - Smart Switch 6 (ZW096)" off
2019-03-31 08:41:00.338   DEBUG   queueing energy request of "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (activity detected)
2019-03-31 08:41:00.518   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 00 BC
2019-03-31 08:41:00.518   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 0
2019-03-31 08:41:00.802   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 00 BC
2019-03-31 08:41:00.802   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 0
2019-03-31 08:41:04.541   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 EA 9F
2019-03-31 08:41:08.899   DEBUG   RCVD setRelayValue: 01 07 00 13 EA 01 01 B0 B1 (node NAK)
2019-03-31 08:41:08.899   DEBUG   . .  setRelayValue: requeuing 3 unsolicited packets
2019-03-31 08:41:08.900   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" on failed
2019-03-31 08:41:08.900   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 08:41:08.900   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 08:41:08.901   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" status update is on
2019-03-31 08:41:08.901   DEBUG   ignoring duplicate energy request of "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (activity detected)
2019-03-31 08:41:08.901   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 08:41:08.901   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 08:41:08.902   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 08:41:08.902   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 08:41:08.902   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 08:41:08.902   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0008 secs)
2019-03-31 08:41:14.165   DEBUG   polling status of node "130 - Kitchen - Water Cooler Power" (post-activity energy request)
2019-03-31 08:41:14.200   DEBUG   SENT requestMeterLevel: 01 0A 00 13 82 03 32 01 00 25 EB 9A
2019-03-31 08:41:14.634   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 82 12 32 02 21 64 00 01 D2 69 00 D5 00 01 D2 69 00 00 00 00 D3
2019-03-31 08:41:14.635   DEBUG   . .  requestMeterLevel: node 130, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:41:14.635   DEBUG   . .  requestMeterLevel: 119.401 kWh (float: 119.401000)
2019-03-31 08:41:14.635   DEBUG   SENT requestMeterLevel: 01 0A 00 13 82 03 32 01 10 25 EC 8D
2019-03-31 08:41:15.070   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 82 12 32 02 21 74 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16
2019-03-31 08:41:15.070   DEBUG   . .  requestMeterLevel: node 130, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:41:15.071   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 08:41:17.166   DEBUG   polling status of node "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (post-activity energy request)
2019-03-31 08:41:17.199   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 00 25 ED 70
2019-03-31 08:41:21.662   DEBUG   RCVD requestMeterLevel: 01 07 00 13 ED 01 01 BC BA (node NAK)
2019-03-31 08:41:21.662   DEBUG   . .  requestMeterLevel: requeuing 1 unsolicited packets
2019-03-31 08:41:21.662   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" requestMeterLevel command failed (module might be asleep, or is unreachable)
2019-03-31 08:41:21.662   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 6E 00 E3 00 00 30 6E 00 00 00 00 09
2019-03-31 08:41:21.662   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:41:21.663   DEBUG   . .  requestMeterLevel: 12.398 kWh (float: 12.398000)
2019-03-31 08:41:21.663   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 10 25 EE 63
2019-03-31 08:41:23.081   DEBUG   RCVD requestMeterLevel: 01 07 00 13 EE 01 00 89 8D (node NAK)
2019-03-31 08:41:23.082   DEBUG   . .  requestMeterLevel: requeuing 2 unsolicited packets
2019-03-31 08:41:23.082   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" requestMeterLevel command failed (module might be asleep, or is unreachable)
2019-03-31 08:41:23.082   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 36 95 00 00 00 00 00 00 00 00 00 00 59
2019-03-31 08:41:23.082   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:41:23.082   DEBUG   . .  requestMeterLevel: 13.973 W (float: 13.973000)
2019-03-31 08:41:23.083   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" power load to 13.973 W
2019-03-31 08:41:23.083   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 36 95 00 00 00 00 00 00 00 00 00 00 59
2019-03-31 08:41:23.083   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:41:23.083   DEBUG   . .  requestMeterLevel: 13.973 W (float: 13.973000)
2019-03-31 08:41:23.414   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 36 95 00 00 00 00 00 00 00 00 00 00 59
2019-03-31 08:41:23.415   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:41:23.415   DEBUG   . .  requestMeterLevel: 13.973 W (float: 13.973000)
2019-03-31 08:41:23.798   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 36 95 00 00 00 00 00 00 00 00 00 00 59
2019-03-31 08:41:23.798   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:41:23.798   DEBUG   . .  requestMeterLevel: 13.973 W (float: 13.973000)
2019-03-31 08:41:29.880   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 02 0E 32 02 21 64 00 04 03 92 0E 10 00 04 03 7D 67
2019-03-31 08:41:29.880   DEBUG   . .  requestMeterLevel: node 002, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:41:29.881   DEBUG   . .  requestMeterLevel: 263.058 kWh (float: 263.058000)
2019-03-31 08:41:29.881   INFO   received "Kitchen - AeonPlug - Photoframe" energy total to 263.058 kWh
2019-03-31 08:41:30.160   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 16 0E 32 02 21 64 00 00 05 BE 02 58 00 00 05 BE D8
2019-03-31 08:41:30.161   DEBUG   . .  requestMeterLevel: node 022, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:41:30.161   DEBUG   . .  requestMeterLevel: 1.470 kWh (float: 1.470000)

Code: Select all

2019-03-31 08:56:51.319   INFO   received "Laundry - Humidity" sensor update to 55%
2019-03-31 08:57:02.377   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3D 06 31 05 03 0A 01 A8 58
2019-03-31 08:57:02.377   DEBUG   . .  requestVarSensorStatus: node 061, endpoint None, type 3, raw value 0A01...
2019-03-31 08:57:02.378   DEBUG   . .  requestVarSensorStatus: 424 lux (float: 424.000000)
2019-03-31 08:57:02.378   INFO   received "(U) Ensuite Bathroom - Luminance" sensor update to 424 lux
2019-03-31 08:57:06.152   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3D 06 31 05 03 0A 00 2D DC
2019-03-31 08:57:06.152   DEBUG   . .  requestVarSensorStatus: node 061, endpoint None, type 3, raw value 0A00...
2019-03-31 08:57:06.153   DEBUG   . .  requestVarSensorStatus: 45 lux (float: 45.000000)
2019-03-31 08:57:06.153   INFO   received "(U) Ensuite Bathroom - Luminance" sensor update to 45 lux
2019-03-31 08:57:12.128   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 08:57:12.129   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 08:57:12.129   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 08:57:12.129   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 08:57:12.129   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 08:57:12.130   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0008 secs)
2019-03-31 08:57:12.251   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 29 0E 32 02 21 64 00 15 73 90 02 58 00 15 73 90 E7
2019-03-31 08:57:12.251   DEBUG   . .  requestMeterLevel: node 041, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:57:12.251   DEBUG   . .  requestMeterLevel: 1405.840 kWh (float: 1405.840000)
2019-03-31 08:57:31.320   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 08:57:31.321   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 08:57:31.321   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 08:57:31.323   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 08:57:31.323   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 08:57:31.323   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0023 secs)
2019-03-31 08:57:48.836   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 03 0A 00 C3 4A
2019-03-31 08:57:48.836   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 3, raw value 0A00...
2019-03-31 08:57:48.836   DEBUG   . .  requestVarSensorStatus: 195 lux (float: 195.000000)
2019-03-31 08:57:48.836   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:48.836   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 03 0A 00 C3 42
2019-03-31 08:57:48.836   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 3, raw value 0A00...
2019-03-31 08:57:48.837   DEBUG   . .  requestVarSensorStatus: 195 lux (float: 195.000000)
2019-03-31 08:57:48.837   INFO   received "(U) Wardrobe - Luminance" sensor update to 195 lux
2019-03-31 08:57:48.958   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 05 01 49 00 CD
2019-03-31 08:57:48.958   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 5, raw value 0149...
2019-03-31 08:57:48.958   DEBUG   . .  requestVarSensorStatus: 73% (float: 73.000000)
2019-03-31 08:57:48.958   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:48.959   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 05 01 49 00 C5
2019-03-31 08:57:48.959   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 5, raw value 0149...
2019-03-31 08:57:48.959   DEBUG   . .  requestVarSensorStatus: 73% (float: 73.000000)
2019-03-31 08:57:48.959   INFO   received "(U) Wardrobe - Humidity" sensor update to 73%
2019-03-31 08:57:49.023   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 01 22 00 B8 1B
2019-03-31 08:57:49.023   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 1, raw value 2200...
2019-03-31 08:57:49.024   DEBUG   . .  requestVarSensorStatus: 18.4 °C (float: 18.400000)
2019-03-31 08:57:49.024   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:49.024   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 01 22 00 B8 13
2019-03-31 08:57:49.024   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 1, raw value 2200...
2019-03-31 08:57:49.025   DEBUG   . .  requestVarSensorStatus: 18.4 °C (float: 18.400000)
2019-03-31 08:57:49.025   INFO   received "(U) Wardrobe - Temperature" sensor update to 18.4 °C
2019-03-31 08:57:49.801   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 3E 06 31 05 03 0A 03 8E 77
2019-03-31 08:57:49.801   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 3, raw value 0A03...
2019-03-31 08:57:49.801   DEBUG   . .  requestVarSensorStatus: 910 lux (float: 910.000000)
2019-03-31 08:57:49.801   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:49.802   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 03 0A 03 8E 7F
2019-03-31 08:57:49.802   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 3, raw value 0A03...
2019-03-31 08:57:49.802   DEBUG   . .  requestVarSensorStatus: 910 lux (float: 910.000000)
2019-03-31 08:57:49.802   INFO   received "(U) GameRoom-  Luminance" sensor update to 910 lux
2019-03-31 08:57:49.921   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 3E 06 31 05 05 01 3C 00 CB
2019-03-31 08:57:49.921   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 5, raw value 013C...
2019-03-31 08:57:49.921   DEBUG   . .  requestVarSensorStatus: 60% (float: 60.000000)
2019-03-31 08:57:49.921   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:49.921   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 05 01 3C 00 C3
2019-03-31 08:57:49.922   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 5, raw value 013C...
2019-03-31 08:57:49.922   DEBUG   . .  requestVarSensorStatus: 60% (float: 60.000000)
2019-03-31 08:57:49.922   INFO   received "(U) GameRoom- Humidity" sensor update to 60%
2019-03-31 08:57:49.993   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 3E 06 31 05 01 22 00 B6 66
2019-03-31 08:57:49.993   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 1, raw value 2200...
2019-03-31 08:57:49.993   DEBUG   . .  requestVarSensorStatus: 18.2 °C (float: 18.200000)
2019-03-31 08:57:49.993   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 08:57:49.993   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 01 22 00 B6 6E
2019-03-31 08:57:49.993   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 1, raw value 2200...
2019-03-31 08:57:49.994   DEBUG   . .  requestVarSensorStatus: 18.2 °C (float: 18.200000)
2019-03-31 08:57:49.994   INFO   received "(U) GameRoom- Temperature" sensor update to 18.2 °C
2019-03-31 08:57:54.761   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 66 0E 32 02 21 64 00 03 37 53 02 58 00 03 37 53 A8
2019-03-31 08:57:54.761   DEBUG   . .  requestMeterLevel: node 102, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:57:54.761   DEBUG   . .  requestMeterLevel: 210.771 kWh (float: 210.771000)
2019-03-31 08:58:20.303   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 03 0A 00 00 D2
2019-03-31 08:58:20.303   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 3, raw value 0A00...
2019-03-31 08:58:20.304   DEBUG   . .  requestVarSensorStatus: 0 lux (float: 0.000000)
2019-03-31 08:58:20.304   INFO   received "Bathroom - Downstairs - Luminance" sensor update to 0 lux
2019-03-31 08:58:20.304   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 05 01 2E 00 F1
2019-03-31 08:58:20.304   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 5, raw value 012E...
2019-03-31 08:58:20.304   DEBUG   . .  requestVarSensorStatus: 46% (float: 46.000000)
2019-03-31 08:58:20.304   INFO   received "Bathroom - downstairs - Humidity" sensor update to 46%
2019-03-31 08:58:20.340   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 01 22 00 AD 55
2019-03-31 08:58:20.340   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 1, raw value 2200...
2019-03-31 08:58:20.340   DEBUG   . .  requestVarSensorStatus: 17.3 °C (float: 17.300000)
2019-03-31 08:58:20.341   INFO   received "Bathroom - downstairs - Temperature" sensor update to 17.3 °C
2019-03-31 08:58:31.158   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 08:58:31.159   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 08:58:31.159   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 08:58:31.163   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 08:58:31.163   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 08:58:31.163   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0043 secs)
2019-03-31 08:58:35.348   INFO   Indigo Device "Projector Room - Power - Smart Switch 6 (ZW096)" Z-Wave Properties:
Indigo Z-Wave Version: 2.0.120
Node ID: 110
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: 3, 5, 7, 16, 31, 37, 40, 48, 51, 54, 56, 57, 59, 60, 72, 95, 107
Associations: 1:[1] 2:[]
Config Values: 3:0 20:0 80:2 81:0 83:1774619 84:3289650 90:0 91:25 92:5 101:12 102:0 103:0 111:600 112:600 113:600 252:0
2019-03-31 08:58:52.855   DEBUG   validating parm 020, userVal 0, curVal 0, stateless False, writeonly False
2019-03-31 08:58:52.855   DEBUG   validating parm 081, userVal 0, curVal 0, stateless False, writeonly False
2019-03-31 08:58:52.855   DEBUG   validating parm 003, userVal 0, curVal 0, stateless False, writeonly False
2019-03-31 08:58:52.855   DEBUG   validating parm 090, userVal 0, curVal 0, stateless False, writeonly False
2019-03-31 08:58:52.856   DEBUG   validating parm 091, userVal 25, curVal 25, stateless False, writeonly False
2019-03-31 08:58:52.856   DEBUG   validating parm 092, userVal 5, curVal 5, stateless False, writeonly False
2019-03-31 08:58:52.856   DEBUG   validating parm 111, userVal 4600, curVal 600, stateless False, writeonly False
2019-03-31 08:58:52.856   DEBUG   validating parm 255, userVal 0, curVal None, stateless True, writeonly False
2019-03-31 08:58:52.901   DEBUG   SENT setConfigVal: 01 0F 00 13 6E 08 70 04 6F 04 00 00 11 F8 25 0E 58
2019-03-31 08:58:57.063   DEBUG   RCVD setConfigVal: 01 07 00 13 0E 01 01 9E 7B (node NAK)
2019-03-31 08:58:57.063   DEBUG   . .  setConfigVal: requeuing 1 unsolicited packets
2019-03-31 08:58:57.064   ERROR   device "Projector Room - Power - Smart Switch 6 (ZW096)" parameter 111 "Reporting interval" change failed
2019-03-31 08:58:57.064   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 65 03 20 01 00 B5
2019-03-31 08:58:57.064   DEBUG   . .  sensorSetLevel: node 101, endpoint None, cmdClass 20, value 0
2019-03-31 08:58:57.064   INFO   received "TV Room New 101 - Motion Sensor" status update is off
2019-03-31 08:58:57.068   DEBUG   SENT setRelayValue: 01 0A 00 13 0E 03 25 01 00 25 0F E5
2019-03-31 08:58:57.096   INFO   sent "TV Room Xmas Lights Switch" off
2019-03-31 08:58:57.096   DEBUG   queueing energy request of "014 - TV Room Xmas Lights Switch" (activity detected)
2019-03-31 08:58:57.115   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 0E 03 20 03 00 DC
2019-03-31 08:58:57.115   DEBUG   . .  relaySetLevel: node 014, endpoint None, value 0
2019-03-31 08:58:57.234   DEBUG   RCVD requestAlarmSensorStatus: 01 10 00 04 00 65 0A 71 05 00 00 00 FF 07 00 00 00 08
2019-03-31 08:58:57.235   DEBUG   . .  requestAlarmSensorStatus: node 101, endpoint None, cmdClass 71, type 0, value 0, classSubKey 710000
2019-03-31 08:58:57.235   DEBUG   . .  requestAlarmSensorStatus: typeExt 7, valueExt 0, classSubKeyExt 7100000700
2019-03-31 08:58:57.235   DEBUG   . .  requestAlarmSensorStatus: defnStatusByte 0
2019-03-31 08:58:57.235   INFO   received "TV Room New 101 - Tamper" status update is off
2019-03-31 08:58:57.252   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 0E 03 20 03 00 DC
2019-03-31 08:58:57.252   DEBUG   . .  relaySetLevel: node 014, endpoint None, value 0
2019-03-31 08:59:02.367   DEBUG   polling status of node "014 - TV Room Xmas Lights Switch" (post-activity energy request)
2019-03-31 08:59:02.392   DEBUG   SENT requestMeterLevel: 01 0A 00 13 0E 03 32 01 00 25 10 ED
2019-03-31 08:59:02.670   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 0E 0E 32 02 21 64 00 00 10 F8 01 03 00 00 10 F8 98
2019-03-31 08:59:02.670   DEBUG   . .  requestMeterLevel: node 014, endpoint None, meterType 01, raw value 6400...
2019-03-31 08:59:02.670   DEBUG   . .  requestMeterLevel: 4.344 kWh (float: 4.344000)
2019-03-31 08:59:02.671   DEBUG   SENT requestMeterLevel: 01 0A 00 13 0E 03 32 01 10 25 11 FC
2019-03-31 08:59:02.964   DEBUG   RCVD requestMeterLevel: 01 0E 00 04 00 0E 08 32 02 21 74 00 00 00 00 96
2019-03-31 08:59:02.964   DEBUG   . .  requestMeterLevel: node 014, endpoint None, meterType 01, raw value 7400...
2019-03-31 08:59:02.965   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 08:59:10.140   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 03 0A 00 B6 66
2019-03-31 08:59:10.141   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 3, raw value 0A00...
2019-03-31 08:59:10.141   DEBUG   . .  requestVarSensorStatus: 182 lux (float: 182.000000)
2019-03-31 08:59:10.141   INFO   received "TV Room - Luminance" sensor update to 182 lux
2019-03-31 08:59:10.142   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 05 01 2E 00 F3
2019-03-31 08:59:10.142   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 5, raw value 012E...
2019-03-31 08:59:10.142   DEBUG   . .  requestVarSensorStatus: 46% (float: 46.000000)
2019-03-31 08:59:10.142   INFO   received "Tv room - Humidity" sensor update to 46%
2019-03-31 08:59:10.177   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 01 22 00 A9 53
2019-03-31 08:59:10.177   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 1, raw value 2200...
2019-03-31 08:59:10.177   DEBUG   . .  requestVarSensorStatus: 16.9 °C (float: 16.900000)
2019-03-31 08:59:10.177   INFO   received "Tv Room- Temperature" sensor update to 16.9 °C
2019-03-31 08:59:10.210   DEBUG   RCVD nodeAwake: 01 08 00 04 00 1C 02 84 07 6E
2019-03-31 08:59:10.210   DEBUG   . .  nodeAwake: node 028
2019-03-31 08:59:10.210   DEBUG   . . . . . . . : skipping battery check (next check in 538 mins)
2019-03-31 08:59:10.210   DEBUG   SENT goToSleep: 01 09 00 13 1C 02 84 08 24 12 41
2019-03-31 08:59:10.230   DEBUG   RCVD packet: 01 07 00 13 12 00 00 01 F8 (hex)
2019-03-31 08:59:26.593   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3D 06 31 05 03 0A 01 4E BE
2019-03-31 08:59:26.593   DEBUG   . .  requestVarSensorStatus: node 061, endpoint None, type 3, raw value 0A01...
2019-03-31 08:59:26.594   DEBUG   . .  requestVarSensorStatus: 334 lux (float: 334.000000)
2019-03-31 08:59:26.594   INFO   received "(U) Ensuite Bathroom - Luminance" sensor update to 334 lux

& this one turns on - but then requestMeterLevel fails - despite receiving it a few seconds later...

Code: Select all

2019-03-31 09:00:48.557   DEBUG   queueing energy request of "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (activity detected)
2019-03-31 09:00:48.557   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 09:00:48.557   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 09:00:48.558   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 09:00:48.558   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 09:00:48.558   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 09:00:48.558   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 09:00:53.563   DEBUG   polling status of node "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (post-activity energy request)
2019-03-31 09:00:53.574   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 00 25 15 88
2019-03-31 09:00:54.518   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 73 02 A5 00 00 30 71 00 00 00 00 4F
2019-03-31 09:00:54.518   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:00:54.518   DEBUG   . .  requestMeterLevel: 12.403 kWh (float: 12.403000)
2019-03-31 09:00:54.519   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" energy total to 12.403 kWh
2019-03-31 09:00:54.519   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 10 25 16 9B
2019-03-31 09:00:58.917   DEBUG   RCVD requestMeterLevel: 01 07 00 13 16 01 01 B5 48 (node NAK)
2019-03-31 09:00:58.917   DEBUG   . .  requestMeterLevel: requeuing 2 unsolicited packets
2019-03-31 09:00:58.918   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" requestMeterLevel command failed (module might be asleep, or is unreachable)
2019-03-31 09:00:58.918   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3D 06 31 05 03 0A 04 F8 0D
2019-03-31 09:00:58.918   DEBUG   . .  requestVarSensorStatus: node 061, endpoint None, type 3, raw value 0A04...
2019-03-31 09:00:58.918   DEBUG   . .  requestVarSensorStatus: 1272 lux (float: 1272.000000)
2019-03-31 09:00:58.918   INFO   received "(U) Ensuite Bathroom - Luminance" sensor update to 1272 lux
2019-03-31 09:00:58.919   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 3A 96 00 00 00 00 00 00 00 00 00 00 56
2019-03-31 09:00:58.919   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:00:58.919   DEBUG   . .  requestMeterLevel: 14.998 W (float: 14.998000)
2019-03-31 09:00:58.919   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" power load to 14.998 W
2019-03-31 09:01:02.713   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 73 00 09 00 00 30 73 00 00 00 00 E3
2019-03-31 09:01:02.713   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:01:02.714   DEBUG   . .  requestMeterLevel: 12.403 kWh (float: 12.403000)
2019-03-31 09:01:02.989   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 73 00 09 00 00 30 73 00 00 00 00 E3
2019-03-31 09:01:02.989   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:01:02.990   DEBUG   . .  requestMeterLevel: 12.403 kWh (float: 12.403000)
2019-03-31 09:01:03.162   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 64 00 00 30 73 00 09 00 00 30 73 00 00 00 00 E3
2019-03-31 09:01:03.162   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:01:03.162   DEBUG   . .  requestMeterLevel: 12.403 kWh (float: 12.403000)
2019-03-31 09:01:08.153   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 3A A3 00 00 00 00 00 00 00 00 00 00 63
2019-03-31 09:01:08.153   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:01:08.153   DEBUG   . .  requestMeterLevel: 15.011 W (float: 15.011000)
2019-03-31 09:01:08.153   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" power load to 15.011 W
2019-03-31 09:01:08.224   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 3A A3 00 00 00 00 00 00 00 00 00 00 63
2019-03-31 09:01:08.225   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:01:08.225   DEBUG   . .  requestMeterLevel: 15.011 W (float: 15.011000)
2019-03-31 09:01:08.496   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 3A A3 00 00 00 00 00 00 00 00 00 00 63
2019-03-31 09:01:08.496   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:01:08.496   DEBUG   . .  requestMeterLevel: 15.011 W (float: 15.011000)

& Here with very little traffic

Code: Select all

019-03-31 09:45:16.743   DEBUG   filtering duplicate command -- old: 20, 0, 0, new: 20, 0, 0 (0.0699 secs)
2019-03-31 09:45:19.752   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 09:45:19.753   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 09:45:19.753   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 09:45:19.753   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 09:45:19.753   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 09:45:19.753   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0006 secs)
2019-03-31 09:45:32.057   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 10 0E 32 02 21 64 00 00 F5 C0 02 58 00 00 F5 BD A3
2019-03-31 09:45:32.057   DEBUG   . .  requestMeterLevel: node 016, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:45:32.057   DEBUG   . .  requestMeterLevel: 62.912 kWh (float: 62.912000)
2019-03-31 09:45:32.058   INFO   received "Dining Room - WallPlug - Now Upright Light" energy total to 62.912 kWh
2019-03-31 09:45:39.503   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1E 03 20 01 00 CE
2019-03-31 09:45:39.503   DEBUG   . .  sensorSetLevel: node 030, endpoint None, cmdClass 20, value 0
2019-03-31 09:45:39.503   INFO   received "Bathroom - Downstairs - Motion Sensor" status update is off
2019-03-31 09:45:48.860   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 03 0A 00 C8 41
2019-03-31 09:45:48.861   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 3, raw value 0A00...
2019-03-31 09:45:48.861   DEBUG   . .  requestVarSensorStatus: 200 lux (float: 200.000000)
2019-03-31 09:45:48.861   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 09:45:48.862   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 03 0A 00 C8 49
2019-03-31 09:45:48.862   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 3, raw value 0A00...
2019-03-31 09:45:48.863   DEBUG   . .  requestVarSensorStatus: 200 lux (float: 200.000000)
2019-03-31 09:45:48.863   INFO   received "(U) Wardrobe - Luminance" sensor update to 200 lux
2019-03-31 09:45:48.936   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 05 01 49 00 CD
2019-03-31 09:45:48.936   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 5, raw value 0149...
2019-03-31 09:45:48.937   DEBUG   . .  requestVarSensorStatus: 73% (float: 73.000000)
2019-03-31 09:45:48.937   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 09:45:48.937   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 05 01 49 00 C5
2019-03-31 09:45:48.937   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 5, raw value 0149...
2019-03-31 09:45:48.937   DEBUG   . .  requestVarSensorStatus: 73% (float: 73.000000)
2019-03-31 09:45:48.938   INFO   received "(U) Wardrobe - Humidity" sensor update to 73%
2019-03-31 09:45:49.011   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 4D 06 31 05 01 22 00 B7 14
2019-03-31 09:45:49.011   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 1, raw value 2200...
2019-03-31 09:45:49.012   DEBUG   . .  requestVarSensorStatus: 18.3 °C (float: 18.300000)
2019-03-31 09:45:49.012   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 09:45:49.014   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 4D 06 31 05 01 22 00 B7 1C
2019-03-31 09:45:49.014   DEBUG   . .  requestVarSensorStatus: node 077, endpoint None, type 1, raw value 2200...
2019-03-31 09:45:49.014   DEBUG   . .  requestVarSensorStatus: 18.3 °C (float: 18.300000)
2019-03-31 09:45:49.014   INFO   received "(U) Wardrobe - Temperature" sensor update to 18.3 °C
2019-03-31 09:46:01.415   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 09:46:01.416   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 09:46:01.416   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 09:46:01.416   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 09:46:01.416   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 09:46:01.416   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0006 secs)
2019-03-31 09:46:17.839   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 3E 06 31 05 03 0A 03 E8 11
2019-03-31 09:46:17.840   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 3, raw value 0A03...
2019-03-31 09:46:17.840   DEBUG   . .  requestVarSensorStatus: 1000 lux (float: 1000.000000)
2019-03-31 09:46:17.840   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 09:46:17.908   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 03 0A 03 E8 19
2019-03-31 09:46:17.908   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 3, raw value 0A03...
2019-03-31 09:46:17.908   DEBUG   . .  requestVarSensorStatus: 1000 lux (float: 1000.000000)
2019-03-31 09:46:17.908   INFO   received "(U) GameRoom-  Luminance" sensor update to 1000 lux
2019-03-31 09:46:17.980   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 08 3E 06 31 05 05 01 3B 00 CC
2019-03-31 09:46:17.980   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 5, raw value 013B...
2019-03-31 09:46:17.980   DEBUG   . .  requestVarSensorStatus: 59% (float: 59.000000)
2019-03-31 09:46:17.980   DEBUG   . .  requestVarSensorStatus: replyId 08 -- duplicate ignored
2019-03-31 09:46:17.981   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 05 01 3B 00 C4
2019-03-31 09:46:17.981   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 5, raw value 013B...
2019-03-31 09:46:17.981   DEBUG   . .  requestVarSensorStatus: 59% (float: 59.000000)
2019-03-31 09:46:17.981   INFO   received "(U) GameRoom- Humidity" sensor update to 59%
2019-03-31 09:46:18.099   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 3E 06 31 05 01 22 00 C6 1E
2019-03-31 09:46:18.100   DEBUG   . .  requestVarSensorStatus: node 062, endpoint None, type 1, raw value 2200...
2019-03-31 09:46:18.100   DEBUG   . .  requestVarSensorStatus: 19.8 °C (float: 19.800000)
2019-03-31 09:46:18.100   INFO   received "(U) GameRoom- Temperature" sensor update to 19.8 °C
2019-03-31 09:46:23.295   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 03 0A 00 A7 75
2019-03-31 09:46:23.295   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 3, raw value 0A00...
2019-03-31 09:46:23.296   DEBUG   . .  requestVarSensorStatus: 167 lux (float: 167.000000)
2019-03-31 09:46:23.296   INFO   received "Bathroom - Downstairs - Luminance" sensor update to 167 lux
2019-03-31 09:46:23.296   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 05 01 2F 00 F0
2019-03-31 09:46:23.296   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 5, raw value 012F...
2019-03-31 09:46:23.297   DEBUG   . .  requestVarSensorStatus: 47% (float: 47.000000)
2019-03-31 09:46:23.297   INFO   received "Bathroom - downstairs - Humidity" sensor update to 47%
2019-03-31 09:46:23.314   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1E 06 31 05 01 22 00 AD 55
2019-03-31 09:46:23.314   DEBUG   . .  requestVarSensorStatus: node 030, endpoint None, type 1, raw value 2200...
2019-03-31 09:46:23.314   DEBUG   . .  requestVarSensorStatus: 17.3 °C (float: 17.300000)
2019-03-31 09:46:23.315   INFO   received "Bathroom - downstairs - Temperature" sensor update to 17.3 °C
2019-03-31 09:47:08.222   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 4F 12 32 02 21 64 00 00 9F 1B 0E 10 00 00 9F 1B 00 00 00 00 D5
2019-03-31 09:47:08.223   DEBUG   . .  requestMeterLevel: node 079, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:47:08.224   DEBUG   . .  requestMeterLevel: 40.731 kWh (float: 40.731000)
2019-03-31 09:47:08.295   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 4F 12 32 02 21 74 00 00 00 00 00 00 00 00 00 00 00 00 00 00 DB
2019-03-31 09:47:08.295   DEBUG   . .  requestMeterLevel: node 079, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:47:08.296   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 09:47:10.148   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 03 0A 02 AE 7C
2019-03-31 09:47:10.148   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 3, raw value 0A02...
2019-03-31 09:47:10.149   DEBUG   . .  requestVarSensorStatus: 686 lux (float: 686.000000)
2019-03-31 09:47:10.149   INFO   received "TV Room - Luminance" sensor update to 686 lux
2019-03-31 09:47:10.149   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 05 01 2E 00 F3
2019-03-31 09:47:10.149   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 5, raw value 012E...
2019-03-31 09:47:10.149   DEBUG   . .  requestVarSensorStatus: 46% (float: 46.000000)
2019-03-31 09:47:10.150   INFO   received "Tv room - Humidity" sensor update to 46%
2019-03-31 09:47:10.166   DEBUG   RCVD requestVarSensorStatus: 01 0C 00 04 00 1C 06 31 05 01 22 00 A7 5D
2019-03-31 09:47:10.166   DEBUG   . .  requestVarSensorStatus: node 028, endpoint None, type 1, raw value 2200...
2019-03-31 09:47:10.166   DEBUG   . .  requestVarSensorStatus: 16.7 °C (float: 16.700000)
2019-03-31 09:47:10.166   INFO   received "Tv Room- Temperature" sensor update to 16.7 °C
2019-03-31 09:47:12.458   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 29 0E 32 02 21 64 00 15 73 90 02 58 00 15 73 90 E7
2019-03-31 09:47:12.458   DEBUG   . .  requestMeterLevel: node 041, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:47:12.458   DEBUG   . .  requestMeterLevel: 1405.840 kWh (float: 1405.840000)
2019-03-31 09:47:13.098   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 09:47:13.099   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 09:47:13.099   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 09:47:13.115   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 09:47:13.115   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 09:47:13.115   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0168 secs)
2019-03-31 09:47:43.558   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 09:47:43.558   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 09:47:43.559   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 09:47:43.560   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 09:47:43.561   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 09:47:43.561   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0026 secs)
2019-03-31 09:47:50.902   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 65 03 20 01 00 B5
2019-03-31 09:47:50.903   DEBUG   . .  sensorSetLevel: node 101, endpoint None, cmdClass 20, value 0
2019-03-31 09:47:50.903   INFO   received "TV Room New 101 - Motion Sensor" status update is off
2019-03-31 09:47:50.904   DEBUG   SENT setMultiLevelValue: 01 0A 00 13 1D 03 26 01 00 25 8D 77
2019-03-31 09:47:51.054   INFO   sent "Bathroom Downstairs - Light" off
2019-03-31 09:47:51.056   DEBUG   SENT setRelayValue: 01 0A 00 13 0E 03 25 01 00 25 8E 64
2019-03-31 09:47:51.087   INFO   sent "TV Room Xmas Lights Switch" off
2019-03-31 09:47:51.088   DEBUG   queueing energy request of "014 - TV Room Xmas Lights Switch" (activity detected)
2019-03-31 09:47:51.107   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 0E 03 20 03 00 DC
2019-03-31 09:47:51.107   DEBUG   . .  relaySetLevel: node 014, endpoint None, value 0
2019-03-31 09:47:51.342   DEBUG   RCVD requestAlarmSensorStatus: 01 10 00 04 00 65 0A 71 05 00 00 00 FF 07 00 00 00 08
2019-03-31 09:47:51.343   DEBUG   . .  requestAlarmSensorStatus: node 101, endpoint None, cmdClass 71, type 0, value 0, classSubKey 710000
2019-03-31 09:47:51.343   DEBUG   . .  requestAlarmSensorStatus: typeExt 7, valueExt 0, classSubKeyExt 7100000700
2019-03-31 09:47:51.343   DEBUG   . .  requestAlarmSensorStatus: defnStatusByte 0
2019-03-31 09:47:51.343   INFO   received "TV Room New 101 - Tamper" status update is off
2019-03-31 09:47:51.846   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 FF 26
2019-03-31 09:47:51.846   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 255
2019-03-31 09:47:51.846   INFO   received "Dining Room Round - Motion Sensor" status update is on
2019-03-31 09:47:51.847   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 FF 34
2019-03-31 09:47:51.847   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 255
2019-03-31 09:47:51.847   DEBUG   filtering duplicate command -- old: 30, 0, FF, new: 20, 0, FF (0.0005 secs)
2019-03-31 09:47:55.146   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 66 0E 32 02 21 64 00 03 37 53 02 58 00 03 37 53 A8
2019-03-31 09:47:55.147   DEBUG   . .  requestMeterLevel: node 102, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:47:55.147   DEBUG   . .  requestMeterLevel: 210.771 kWh (float: 210.771000)
2019-03-31 09:47:58.043   DEBUG   polling status of node "014 - TV Room Xmas Lights Switch" (post-activity energy request)
2019-03-31 09:47:58.067   DEBUG   SENT requestMeterLevel: 01 0A 00 13 0E 03 32 01 00 25 8F 72
2019-03-31 09:47:58.358   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 0E 0E 32 02 21 64 00 00 10 F8 01 07 00 00 10 F8 9C
2019-03-31 09:47:58.358   DEBUG   . .  requestMeterLevel: node 014, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:47:58.358   DEBUG   . .  requestMeterLevel: 4.344 kWh (float: 4.344000)
2019-03-31 09:47:58.358   DEBUG   SENT requestMeterLevel: 01 0A 00 13 0E 03 32 01 10 25 90 7D
2019-03-31 09:47:58.640   DEBUG   RCVD requestMeterLevel: 01 0E 00 04 00 0E 08 32 02 21 74 00 00 00 00 96
2019-03-31 09:47:58.641   DEBUG   . .  requestMeterLevel: node 014, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:47:58.641   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 09:49:24.729   DEBUG   RCVD requestBinarySensorStatus: 01 09 00 04 00 1B 03 30 03 00 D9
2019-03-31 09:49:24.729   DEBUG   . .  requestBinarySensorStatus: node 027, endpoint None, value 0
2019-03-31 09:49:24.730   INFO   received "Dining Room Round - Motion Sensor" status update is off
2019-03-31 09:49:24.730   DEBUG   RCVD sensorSetLevel: 01 09 00 04 00 1B 03 20 01 00 CB
2019-03-31 09:49:24.730   DEBUG   . .  sensorSetLevel: node 027, endpoint None, cmdClass 20, value 0
2019-03-31 09:49:24.730   DEBUG   filtering duplicate command -- old: 30, 0, 0, new: 20, 0, 0 (0.0007 secs)
2019-03-31 09:49:26.912   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 91 E4
2019-03-31 09:49:31.260   DEBUG   RCVD setRelayValue: 01 07 00 13 91 01 01 AE D4 (node NAK)
2019-03-31 09:49:31.261   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" on failed
2019-03-31 09:49:36.029   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 92 E7
2019-03-31 09:49:40.181   DEBUG   RCVD setRelayValue: 01 07 00 13 92 01 01 9C E5 (node NAK)
2019-03-31 09:49:40.181   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" on failed
2019-03-31 09:49:41.180   DEBUG   RCVD nodeAwake: 01 08 00 04 00 69 02 84 07 1B
2019-03-31 09:49:41.180   DEBUG   . .  nodeAwake: node 105
2019-03-31 09:49:41.180   DEBUG   . . . . . . . : skipping battery check (next check in 536 mins)
2019-03-31 09:49:41.181   DEBUG   SENT goToSleep: 01 09 00 13 69 02 84 08 24 93 B5
2019-03-31 09:49:41.199   DEBUG   RCVD packet: 01 07 00 13 93 00 00 02 7A (hex)
2019-03-31 09:49:48.486   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 94 E1
2019-03-31 09:49:52.631   DEBUG   RCVD setRelayValue: 01 07 00 13 94 01 01 99 E6 (node NAK)
2019-03-31 09:49:52.632   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" on failed
2019-03-31 09:49:59.564   DEBUG   RCVD requestDimmerStatus: 01 09 00 04 00 24 03 26 03 63 93
2019-03-31 09:49:59.564   DEBUG   . .  requestDimmerStatus: node 036, endpoint None, value 99
2019-03-31 09:49:59.564   INFO   received "Projector Room - Halogen Lights" status update brightness 100
2019-03-31 09:50:00.211   DEBUG   SENT setRelayValue: 01 0A 00 13 6E 03 25 01 FF 25 95 E0
2019-03-31 09:50:00.351   INFO   sent "Projector Room - Power - Smart Switch 6 (ZW096)" on
2019-03-31 09:50:00.351   DEBUG   queueing energy request of "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (activity detected)
2019-03-31 09:50:00.527   DEBUG   RCVD relaySetLevel: 01 09 00 04 00 6E 03 20 03 FF 43
2019-03-31 09:50:00.527   DEBUG   . .  relaySetLevel: node 110, endpoint None, value 255
2019-03-31 09:50:05.401   DEBUG   polling status of node "110 - Projector Room - Power - Smart Switch 6 (ZW096)" (post-activity energy request)
2019-03-31 09:50:05.448   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 00 25 96 0B
2019-03-31 09:50:09.556   DEBUG   RCVD requestMeterLevel: 01 07 00 13 96 01 01 98 E5 (node NAK)
2019-03-31 09:50:09.556   DEBUG   . .  requestMeterLevel: requeuing 2 unsolicited packets
2019-03-31 09:50:09.557   ERROR   send "Projector Room - Power - Smart Switch 6 (ZW096)" requestMeterLevel command failed (module might be asleep, or is unreachable)
2019-03-31 09:50:09.557   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 21 0E 32 02 21 64 00 00 00 00 17 70 00 00 00 00 D2
2019-03-31 09:50:09.557   DEBUG   . .  requestMeterLevel: node 033, endpoint None, meterType 01, raw value 6400...
2019-03-31 09:50:09.557   DEBUG   . .  requestMeterLevel: 0.000 kWh (float: 0.000000)
2019-03-31 09:50:09.558   DEBUG   RCVD requestMeterLevel: 01 14 00 04 00 21 0E 32 02 21 74 00 00 00 00 17 70 00 00 00 00 C2
2019-03-31 09:50:09.558   DEBUG   . .  requestMeterLevel: node 033, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:50:09.558   DEBUG   . .  requestMeterLevel: 0.000 W (float: 0.000000)
2019-03-31 09:50:09.558   DEBUG   SENT requestMeterLevel: 01 0A 00 13 6E 03 32 01 10 25 97 1A
2019-03-31 09:50:10.579   DEBUG   RCVD requestMeterLevel: 01 18 00 04 00 6E 12 32 02 21 74 00 00 2A E1 00 00 00 00 00 00 00 00 00 00 31
2019-03-31 09:50:10.579   DEBUG   . .  requestMeterLevel: node 110, endpoint None, meterType 01, raw value 7400...
2019-03-31 09:50:10.579   DEBUG   . .  requestMeterLevel: 10.977 W (float: 10.977000)
2019-03-31 09:50:10.580   INFO   received "Projector Room - Power - Smart Switch 6 (ZW096)" power load to 10.977 W
2019-03-31 09:50:11.281   DEBUG   SENT setRelayValue: 01 0E 00

[matt (support)]

If I understand correctly: 1) The module consistently always works if it is next to the Z-Stick, and 2) If moved away from the Z-Stick and you optimize a module near the problem module it doesn't show in its neighbor's list. It is definitely strange the neighbor lists aren't updating on the module (or on the modules near it). Could the problem be something causing Z-Wave interference? I don't think traffic/collisions are the problem based on your log snippets.

The energy report errors in the log even though the debug logging shows the commands coming in is probably because the module itself sends out energy changes periodically. The error is from where Indigo is specifically requesting (polling) the energy or power value and that particular command fails to respond. That is just a side note to explain how you can have NAK errors even though there are energy/power reports coming in. The specific problem here definitely seems to be not specific or related to energy reports since you also have seen it just trying to turn a module on/off in low traffic scenarios.

If I understand correctly: 1) The module consistently always works if it is next to the Z-Stick, and 2) If moved away from the Z-Stick and you optimize a module near the problem module it doesn't show in its neighbor's list. It is definitely strange the neighbor lists aren't updating on the module (or on the modules near it). Could the problem be something causing Z-Wave interference? I don't think traffic/collisions are the problem based on your log snippets.

The energy report errors in the log even though the debug logging shows the commands coming in is probably because the module itself sends out energy changes periodically. The error is from where Indigo is specifically requesting (polling) the energy or power value and that particular command fails to respond. That is just a side note to explain how you can have NAK errors even though there are energy/power reports coming in. The specific problem here definitely seems to be not specific or related to energy reports since you also have seen it just trying to turn a module on/off in low traffic scenarios.

Thanks Matt.

The other couple of points are :
x4 Aeotec ZW096 switches all at once - varying degrees of loosing contact, No Acks, etc.

I wouldn’t rule anything out re: interference but having optimised all close devices - they all ping in 17ms or so, and speed through the info. So if interference only affecting these ZW096 devices ....

The module I have moved next to Stick still only reports one neighbour (just defined and synced now). Should report 20 or so, it’s sitting on the stick so if bad interference here would think would see widespread network issues/slow-down - which I am not.

Still waiting to hear from Aeotec - since I now have extra stick can update firmware fairly easily. (There are reports of range issues and stuck in various stages of setup with some firmware - most advice that I could see seemed to suggest going back to 1.0 - which is the current firmware version)

Thanks

Further to this: Few days later: Turn device On/off a few times. Then Define and Sync - no neighbours found.
Then run optimisation for this device

Code: Select all

   Z-Wave                          Optimizing - started network optimization for nodes: 110
   Z-Wave                          Optimizing - starting "110 - Projector Room - Power - Smart Switch 6 (ZW096)"
   Z-Wave Debug                    SENT sendPingZwaveCommand: 01 09 00 13 6E 02 00 00 25 23 8F
   Z-Wave                          Optimizing - ping completed in 176 ms
   Z-Wave                          Optimizing - finding neighbors
   Z-Wave                          Optimizing - requesting neighbor list update
   Z-Wave Debug                    SENT requestNeighborUpdate: 01 04 00 48 6E DD
   Z-Wave Debug                    RCVD requestNeighborUpdate: 06 (ACK)
   Z-Wave Debug                    RCVD requestNeighborUpdate: 01 05 00 48 02 21 91
   Z-Wave Debug                    . .  requestNeighborUpdate: node 110, update starting
   Z-Wave Debug                    RCVD requestMeterLevel: 01 14 00 04 00 21 0E 32 02 21 64 00 00 00 00 17 70 00 00 00 00 D2
   Z-Wave Debug                    . .  requestMeterLevel: node 033, endpoint None, meterType 01, raw value 6400...
   Z-Wave Debug                    . .  requestMeterLevel: 0.000 kWh (float: 0.000000)
   Z-Wave Debug                    RCVD requestMeterLevel: 01 14 00 04 00 21 0E 32 02 21 74 00 00 00 00 17 70 00 00 00 00 C2
   Z-Wave Debug                    . .  requestMeterLevel: node 033, endpoint None, meterType 01, raw value 7400...
   Z-Wave Debug                    . .  requestMeterLevel: 0.000 W (float: 0.000000)
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    RCVD requestNeighborUpdate: 01 05 00 48 02 21 91
   Z-Wave Debug                    . .  requestNeighborUpdate: node 110, update starting
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    RCVD requestNeighborUpdate: 01 05 00 48 02 21 91
   Z-Wave Debug                    . .  requestNeighborUpdate: node 110, update starting
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    Optimizing - waiting for neighbor find to complete
   Z-Wave Debug                    RCVD requestNeighborUpdate: 01 05 00 48 02 23 93
   Z-Wave Debug                    . .  requestNeighborUpdate: node 110, update failed
   Z-Wave                          Optimizing - neighbor list update failed -- will try to update nearby neighbors first
   Z-Wave                          Optimizing - no known neighbors found
   Z-Wave                          Optimizing - failed "110 - Projector Room - Power - Smart Switch 6 (ZW096)"
   Z-Wave                          Optimizing - complete
   Z-Wave Error                    Optimizing - update failed: "110 - Projector Room - Power - Smart Switch 6 (ZW096)"

Glenn

Hi Matt

Further to this
Aeotec have supplied firmware 1.03 - which I have updated affected switches to - unforunately same issue and still doesn't find neighbours unless next door.
Affected switch finds one neighbour only (neighbor 5), next door device finds 40 devices.

But, when I compare affected and unaffected switches there are differences in how indigo identifies them?

This is affected, now updated to Firmware 1.03 Device

Code: Select all

Indigo Z-Wave Version: 2.0.120
Node ID: 134
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.54
Application Version: 1.03
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: 5
Associations: 1:[1] 2:[]
Config Values: 112:600 3:1 101:12 102:0 113:600 252:0 103:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
 

This is unaffected, still on firmware 1.00 device

Code: Select all

Z-Wave Indigo Device "Projector Rm Power ALL - Smart Switch 6 (ZW096)" Z-Wave Properties:
   Indigo Z-Wave Version: 2.0.120
Node ID: 109
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 81v1 73v1 85v1 86v1 98v1 59v1 5Ev1 20v1 25v1 26v2 27v1 32v3 70v1 72v1 33v1 7Av1
Encryption Status: Supported but not Enabled
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, security, energyMeter
Neighbors: 2, 5, 8, 9, 10, 11, 12, 14, 16, 21, 22, 23, 29, 35, 44, 46, 48, 52, 54, 60, 72, 73, 74, 78, 100, 101, 102, 108
Associations: 1:[1] 2:[]
Config Values: 3:1 80:0 81:1 83:1774619 20:0 90:0 91:25 92:5 101:12 102:0 103:0 111:3600 112:600 113:600 84:3289650 252:0

Comparing the two there are a few differences:
Affected Device: Missing Command Versions 98v1 ?
Encryption: Reports Not Supported on affected version, versus Supported but not Enabled on unaffected
Features: Missing security in affected device

Is this particularly relevant???

This is the define and sync of affected version -

Code: Select all

1 03 60 00 BC
   Z-Wave Debug . . requestVersInfoGen: node 134, protoVers 4.54, appVers 1.03
   Z-Wave Syncing - retrieved protocol version 4.54, app version 1.03
   Z-Wave Debug SENT requestVersInfoCmdClass: 01 0A 00 13 86 03 86 13 26 25 F4 01
   Z-Wave Debug RCVD requestVersInfoCmdClass: 01 0A 00 04 00 86 04 86 14 26 02 C5
   Z-Wave Debug . . requestVersInfoCmdClass: node 134, class command 26 using version 2
   Z-Wave Debug . . requestVersInfoCmdClass: node 134, combined class list: 20v1 81v1 25v1 26v2 27v1 32v1 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
   Z-Wave Debug SENT requestVersInfoCmdClass: 01 0A 00 13 86 03 86 13 32 25 F5 14
   Z-Wave Debug RCVD requestVersInfoCmdClass: 01 0A 00 04 00 86 04 86 14 32 03 D0
   Z-Wave Debug . . requestVersInfoCmdClass: node 134, class command 32 using version 3
   Z-Wave Debug . . requestVersInfoCmdClass: node 134, combined class list: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
   Z-Wave Debug SENT requestVersInfoCmdClass: 01 0A 00 13 86 03 86 13 33 25 F6 16
   Z-Wave Debug RCVD requestVersInfoCmdClass: 01 0A 00 04 00 86 04 86 14 33 01 D3
   Z-Wave Debug . . requestVersInfoCmdClass: node 134, class command 33 using version 1
   Z-Wave Syncing - retrieved class hierarchy: Routing Slave : Relay Switch : Relay Power Switch (04 : 10 : 01, base 25)
   Z-Wave Syncing - retrieved command classes: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
   Z-Wave Syncing - retrieved encrypt commands: - none -
   Z-Wave Syncing - retrieved capabilities: routing, beaming
   Z-Wave Debug SENT requestAssociationGroupCount: 01 09 00 13 86 02 85 05 25 F7 33
   Z-Wave Debug RCVD requestAssociationGroupCount: 01 09 00 04 00 86 03 85 06 02 F6
   Z-Wave Debug . . requestAssociationGroupCount: node 134, group count: 2
   Z-Wave Debug SENT requestAssociations: 01 0A 00 13 86 03 85 02 01 25 F8 38
   Z-Wave Debug RCVD requestAssociations: 01 0B 00 04 00 86 05 85 03 01 05 00 F1
   Z-Wave Debug . . requestAssociations: node 134, group: 1, num associations: 0, max associations: 5, replies left: 0
   Z-Wave Debug . . requestAssociations: node 134, group: 1, associations: []
   Z-Wave Syncing - retrieved group 1 associations: []
   Z-Wave Debug SENT requestAssociations: 01 0A 00 13 86 03 85 02 02 25 F9 3A
   Z-Wave Debug RCVD requestAssociations: 01 0B 00 04 00 86 05 85 03 02 05 00 F2
   Z-Wave Debug . . requestAssociations: node 134, group: 2, num associations: 0, max associations: 5, replies left: 0
   Z-Wave Debug . . requestAssociations: node 134, group: 2, associations: []
   Z-Wave Syncing - retrieved group 2 associations: []
   Z-Wave Debug SENT addInterfaceAssociation: 01 0B 00 13 86 04 85 01 01 01 25 FA 3E
   Z-Wave Syncing - added group 1 association to interface
   Z-Wave Debug . . addInterfaceAssociation: node 134, group: 1, associations: [1]
   Z-Wave Debug SENT requestMeterInfo: 01 09 00 13 86 02 32 03 25 FB 8E
   Z-Wave Debug RCVD requestMeterInfo: 01 0A 00 04 00 86 04 32 04 81 35 F1
   Z-Wave Debug . . requestMeterInfo: node 134, meterType 01, subTypeFlags 35, supportsReset True
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 FC 25 FC 33
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 FC 01 00 F8
   Z-Wave Debug . . requestConfigVal: node 134, parm index 252, value 0 (size 1)
   Z-Wave Syncing - retrieved parameter 252 "Lock configuration" is false
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 14 25 FD DA
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 14 01 00 10
   Z-Wave Debug . . requestConfigVal: node 134, parm index 20, value 0 (size 1)
   Z-Wave Syncing - retrieved parameter 20 "Power up state" is 0 "Last State"
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 20:0 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 51 25 FE 9C
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 51 01 00 55
   Z-Wave Debug . . requestConfigVal: node 134, parm index 81, value 0 (size 1)
   Z-Wave Syncing - retrieved parameter 81 "LED mode" is 0 "Mirrors Load"
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 20:0 252:0 81:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 03 25 FF CF
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 03 01 01 06
   Z-Wave Debug . . requestConfigVal: node 134, parm index 3, value 1 (size 1)
   Z-Wave Syncing - retrieved parameter 3 "Current overload protection" is true
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 20:0 3:1 252:0 81:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 53 25 01 61
   Z-Wave Debug RCVD requestConfigVal: 01 0D 00 04 00 86 07 70 06 53 03 1B 14 1B 45
   Z-Wave Debug . . requestConfigVal: node 134, parm index 83, value 1774619 (size 3)
   Z-Wave Syncing - retrieved parameter 83 "LED RGB nightlight" is 1774619
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 20:0 83:1774619 3:1 252:0 81:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 54 25 02 65
   Z-Wave Debug RCVD requestConfigVal: 01 0D 00 04 00 86 07 70 06 54 03 32 32 32 64
   Z-Wave Debug . . requestConfigVal: node 134, parm index 84, value 3289650 (size 3)
   Z-Wave Syncing - retrieved parameter 84 "LED RGB load brightness" is 3289650
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 3:1 81:0 83:1774619 20:0 84:3289650 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 50 25 03 60
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 50 01 00 54
   Z-Wave Debug . . requestConfigVal: node 134, parm index 80, value 0 (size 1)
   Z-Wave Syncing - retrieved parameter 80 "Automatic notification" is 0
   Z-Wave Debug SENT setConfigVal: 01 0C 00 13 86 05 70 04 50 01 02 25 04 65
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 80 "Automatic notification" changed to 2
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 3:1 81:0 83:1774619 20:0 80:2 84:3289650 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 5A 25 05 6C
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 5A 01 00 5E
   Z-Wave Debug . . requestConfigVal: node 134, parm index 90, value 0 (size 1)
   Z-Wave Syncing - retrieved parameter 90 "Enable energy change reports" is false
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 3:1 81:0 83:1774619 20:0 80:2 84:3289650 90:0 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 5B 25 06 6E
   Z-Wave Debug RCVD requestConfigVal: 01 0C 00 04 00 86 06 70 06 5B 02 00 19 41
   Z-Wave Debug . . requestConfigVal: node 134, parm index 91, value 25 (size 2)
   Z-Wave Syncing - retrieved parameter 91 "Report threshold watts" is 25 watts
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 3:1 81:0 83:1774619 20:0 80:2 84:3289650 90:0 91:25 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 5C 25 07 68
   Z-Wave Debug RCVD requestConfigVal: 01 0B 00 04 00 86 05 70 06 5C 01 05 5D
   Z-Wave Debug . . requestConfigVal: node 134, parm index 92, value 5 (size 1)
   Z-Wave Syncing - retrieved parameter 92 "Report threshold percentage" is 5 %
   Z-Wave Debug . . requestConfigVal: node 134, combined config vals: 3:1 81:0 83:1774619 20:0 92:5 80:2 84:3289650 90:0 91:25 252:0
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 6F 25 08 54
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 6F 04 00 00 00 03 65
   Z-Wave Debug . . requestConfigVal: node 134, parm index 111, value 3 (size 4)
   Z-Wave Syncing - retrieved parameter 111 "Reporting interval" is 3 seconds
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 6F 04 00 00 02 58 25 09 04
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 111 "Reporting interval" changed to 600 seconds (was 3 seconds)
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 3:1 252:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 70 25 0A 49
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 70 04 00 00 02 58 23
   Z-Wave Debug . . requestConfigVal: node 134, parm index 112, value 600 (size 4)
   Z-Wave Syncing - retrieved parameter 112 "Reporting interval2" is 600 seconds
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 70 04 00 00 02 58 25 0B 19
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 112 "Reporting interval2" changed to 600 seconds (was 600 seconds)
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 112:600 3:1 252:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 71 25 0C 4E
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 71 04 00 00 02 58 22
   Z-Wave Debug . . requestConfigVal: node 134, parm index 113, value 600 (size 4)
   Z-Wave Syncing - retrieved parameter 113 "Reporting interval3" is 600 seconds
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 71 04 00 00 02 58 25 0D 1E
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 113 "Reporting interval3" changed to 600 seconds (was 600 seconds)
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 112:600 3:1 113:600 252:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 65 25 0E 58
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 65 04 00 00 00 00 6C
   Z-Wave Debug . . requestConfigVal: node 134, parm index 101, value 0 (size 4)
   Z-Wave Syncing - retrieved parameter 101 "Group 1 flags" is 0
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 65 04 00 00 00 0C 25 0F 5E
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 101 "Group 1 flags" changed to 12
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 112:600 3:1 101:12 113:600 252:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 66 25 10 45
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 66 04 00 00 00 00 6F
   Z-Wave Debug . . requestConfigVal: node 134, parm index 102, value 0 (size 4)
   Z-Wave Syncing - retrieved parameter 102 "Group 2 flags" is 0
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 66 04 00 00 00 00 25 11 4F
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 102 "Group 2 flags" changed to 0
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 112:600 3:1 101:12 102:0 113:600 252:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestConfigVal: 01 0A 00 13 86 03 70 05 67 25 12 46
   Z-Wave Debug RCVD requestConfigVal: 01 0E 00 04 00 86 08 70 06 67 04 00 00 00 00 6E
   Z-Wave Debug . . requestConfigVal: node 134, parm index 103, value 0 (size 4)
   Z-Wave Syncing - retrieved parameter 103 "Group 3 flags" is 0
   Z-Wave Debug SENT setConfigVal: 01 0F 00 13 86 08 70 04 67 04 00 00 00 00 25 13 4C
   Z-Wave Syncing - device "134 - Relay Power Switch" parameter 103 "Group 3 flags" changed to 0
   Z-Wave Debug . . pushNewValToNode: node 134, combined config vals: 112:600 3:1 101:12 102:0 113:600 252:0 103:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5
   Z-Wave Debug SENT requestClockInfo: 01 09 00 13 86 02 81 05 25 14 D4
   Z-Wave Debug RCVD requestClockInfo: 01 0A 00 04 00 86 04 81 06 00 01 F5
   Z-Wave Debug . . requestClockInfo: node 134, 00:01 day-of-week 0
   Z-Wave Debug SENT setClock: 01 0B 00 13 86 04 81 04 C8 04 25 15 1C
   Z-Wave Syncing - synced server clock to module (08:04, Saturday)

In my Aeotec devices, they all say Encryption: Not Supported except for the two that I put them into the encryption mode when I was including them. It is strange that you have some that say supported by not enabled. What did they say before the firmware update?

Thanks.
This is one of the other - not finding neighbors ZW096 - still on 1.00 firmware (only upgraded one device) - again having same points of difference.

Code: Select all

Indigo Z-Wave Version: 2.0.121
Node ID: 110
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: - none -
Associations: 1:[1] 2:[]
Config Values: 112:600 3:0 101:12 102:0 113:600 252:0 103:0 111:4600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5

Without knowing much of what I speak - I would think the bigger point of difference is the lacking command versions - particularly 98v1? On a bit googling that seems to be the security classes and probably explains the other differences. As to why it will not find neighbors? I remain in the dark.

Glenn

[matt (support)]

I do find it odd that some of your ZW096 claim to have support for the security command class but others do not (even under the same firmware version). I know you've tried already, but I would try excluding and re-including it (then re-syncing, of course) to see if that makes any difference. There are 3 different ways to include it after you've excluded it: manually after removing the Z-Stick from your Mac and pressing its button, using Indigo's define/sync dialog with encryption disabled (top button), and from Indigo with encryption enabled (button below it). Since you are troubleshooting I'd try all three techniques. We normally don't recommend using encryption for something like a ZW096, but in this case I'm wondering what happens.

I wonder if your Z-Stick might be in a bad state. The last thing you probably want to do though is reset it and have to re-include all your modules since you have a bunch.

I do find it odd that some of your ZW096 claim to have support for the security command class but others do not (even under the same firmware version). I know you've tried already, but I would try excluding and re-including it (then re-syncing, of course) to see if that makes any difference. There are 3 different ways to include it after you've excluded it: manually after removing the Z-Stick from your Mac and pressing its button, using Indigo's define/sync dialog with encryption disabled (top button), and from Indigo with encryption enabled (button below it). Since you are troubleshooting I'd try all three techniques. We normally don't recommend using encryption for something like a ZW096, but in this case I'm wondering what happens.

I wonder if your Z-Stick might be in a bad state. The last thing you probably want to do though is reset it and have to re-include all your modules since you have a bunch.

Thanks for the reply Matt.

I have already replaced the Z-stick with a new one and restored from a backup (admittedly may copy over stick issues..) Still have 130 z-wave devices, 60 or so behind switches requiring taking the switch off the wall to reinclude.

Ok - have again excluded and reincluded problematic switch

If I use Stick only - it does correctly add security and 98v1 command class.

Code: Select all

Indigo Z-Wave Version: 2.0.121
Node ID: 137
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.54
Application Version: 1.03
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 98v1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Supported but not Enabled
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, security, energyMeter
Neighbors: 5
Associations: 1:[1] 2:[]
Config Values: 112:600 3:1 101:12 102:0 113:600 252:0 103:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5

Tried again with encryption - network wide - times out, does get to exchanging keys though so obviously seems to be supported. Can't add with encryption using stick alone? or at least I did it wrong.
Re-added with Stick alone without encryption and add's okay as above.

Unfortunately despite security/98v1 appearing back in, still only one neighbor found - and initial problem remains.
Suspect the lack of 98v1, security more of a range issue than the true fault.
Have disassembled the switch as much as possible - basically almost completely filled with epoxy, little serviceable parts.

Does seem very similiar to this issue here: http://forum.micasaverde.com/index.php/ ... 468.0.html
Particularly the range and lack of neighbors...

Glenn

Further to this:

I found a unused, unopened ZW096 switch, waiting a home.
Installed next to problematic one.
Using Network Wide inclusion - fast, found, added, synced no problem.
10's of neighbours found first go round. (not the problematic switch though which is 137)

Code: Select all

Indigo Z-Wave Version: 2.0.121
Node ID: 138
Model: Smart Switch 6 (ZW096)
Model ID: 02030060
Manufacturer: Aeon Labs
Manufacturer ID: 0086
Protocol Version: 4.05
Application Version: 1.00
Model Definition Version: 1
Library Type: 3
Class Name: Relay Power Switch
Class Hierarchy: 04 : 10 : 01
Command Class Base: 25
Command Versions: 20v1 81v1 25v1 26v2 27v1 32v3 70v1 72v1 73v1 5Ev1 59v1 7Av1 85v1 86v1 33v1
Encryption Status: Not Supported
Multi-Endpoint Types: - none -
Multi-Endpoint Classes: - none -
Multi-Instance Counts: - none -
Features: routing, beaming, energyMeter
Neighbors: 2, 3, 5, 7, 8, 9, 10, 11, 12, 14, 15, 29, 31, 35, 37, 42, 43, 44, 46, 47, 48, 51, 52, 54, 60, 107
Associations: 1:[1] 2:[]
Config Values: 112:600 3:1 101:12 102:0 113:600 252:0 103:0 111:600 80:2 81:0 83:1774619 20:0 84:3289650 90:0 91:25 92:5

Interestingly enough - this one also says encryption 'not supported' and missed 98v1 command class.
Does not have the neighbor problem and working well.

Seems the encryption aspect changes whether network wide inclusion used, or z-stick inclusion?
Either-way obviously not the source of the no neighbours problem.

Glenn