Zwave metering plug not sending notifications

avk · February 27, 2019, 4:04pm

Platform information:
BOARD=orangepione
BOARD_NAME=“Orange Pi One”
BOARDFAMILY=sun8i
VERSION=5.73
LINUXFAMILY=sunxi
USB Z-wave stick on /dev/ttyACM0
- Java Runtime Environment:

openjdk version “1.8.0_152”
OpenJDK Runtime Environment (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 1.8.0_152-b76)
OpenJDK Client VM (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 25.152-b76, mixed mode, Evaluation)

openHAB version: 2.4.0
Device in question: NAS-WR01ZE Smartplug https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/397
Issue: Can not receive scheduled reports from the device (polling works fine).
Issue of the topic:

The plug works fine, I can control the relay from paperui/rules.
Polling is configured (600 seconds) and power data (voltage, current etc) are updated and seem to be consistent.
The device itself is configured (via paperui/thing configuration) to send reports every 60 seconds but those reports are not getting through. I’d really like to avoid polling when possible so the question is why I don’t get scheduled reports.

The device has 3 association groups: 1 (Lifeline), 2 and 3. I guess the device is supposed to send usage data on Lifeline.

image.png1052×337 12.4 KB

The following log shows the network startup and first poll of the device (I’ve filtered out communications with thermostat valves). Note that there were no communications between the device initialization and the first poll. I’ve expected to receive unsolicited data from the plug,

Time	Node	Entry
16:51:38.208		
Binding started. Version 2.4.0
16:52:00.682		
DISCOVERY Active
16:52:03.733		
TX REQ GetVersion
16:52:03.740		
RX ACK 0 /128
16:52:03.760		
RX RES GetVersion  0 /128
16:52:03.919		
TX REQ MemoryGetId
16:52:03.926		
RX ACK 0 /128
16:52:03.940		
RX RES MemoryGetId MemoryGetId: HomeID E671DFE1 ControllerID NODE 1 0 /128
16:52:04.014		
TX REQ SerialApiGetCapabilities
16:52:04.019		
RX ACK 0 /128
16:52:04.031		
RX RES SerialApiGetCapabilities Controller Info 0115:0400:0001 0 /128
16:52:04.091		
TX REQ SerialApiSetTimeouts FRAME=1500s BYTE=150ms
16:52:04.100		
RX ACK 0 /128
16:52:04.116		
RX RES SerialApiSetTimeouts FRAME=1500s BYTE=150ms 0 /128
16:52:04.151		
TX REQ GetSucNodeId
16:52:04.155		
RX ACK 0 /128
16:52:04.162		
RX RES GetSucNodeId SUC ID: NODE 1 0 /128
16:52:04.219		
TX REQ SerialApiGetInitData
16:52:04.223		
RX ACK 0 /128
16:52:04.321		
RX RES SerialApiGetInitData Found 5 nodes  0 /128
16:52:04.431		
TX REQ GetControllerCapabilities
16:52:04.436		
RX ACK 0 /128
16:52:04.466		
RX RES GetControllerCapabilities  0 /128
16:52:05.391	1	
Stage advanced to IDENTIFY_NODE
16:52:05.445	1	
TX REQ IdentifyNode
16:52:05.450		
RX ACK 0 /128
16:52:05.465	1	
RX RES IdentifyNode STATIC_CONTROLLER PC_CONTROLLER LISTENING FLIRS250 FLIRS1000 ROUTING BEAMING 0 /128
16:52:05.575	1	
Stage advanced to DONE
16:52:13.346	6	
THING TYPE zwave:shenzhen_powerplug_00_000
16:52:13.379	6	
Stage advanced to IDENTIFY_NODE
16:52:13.397		
RX ACK 0 /128
16:52:13.606		
RX ACK 0 /128
16:52:13.774		
RX ACK 0 /128
16:52:13.922	6	
TX REQ IdentifyNode
16:52:13.928		
RX ACK 0 /128
16:52:13.944	6	
RX RES IdentifyNode ROUTING_SLAVE POWER_SWITCH_BINARY LISTENING FLIRS250 FLIRS1000 ROUTING BEAMING 0 /128
16:52:14.035	6	
Stage advanced to PING
16:52:14.066	6	
TX REQ SendData 1 NO_OPERATION  ACK AUTO_ROUTE EXPLORE
16:52:14.072		
RX ACK 0 /128
16:52:14.083	6	
RX RES SendData 1 ACCEPTED BY CONTROLLER 0 /128
16:52:14.111	6	
RX REQ SendData 1 ACK RECEIVED from device in 45ms 0 /128
16:52:14.162	6	
Stage advanced to REQUEST_NIF
16:52:14.182	6	
TX REQ RequestNodeInfo
16:52:14.188		
RX ACK 0 /128
16:52:14.195	6	
RX RES RequestNodeInfo OK 0 /128
16:52:14.250	6	
RX REQ ApplicationUpdate UPDATE_STATE_NODE_INFO_RECEIVED  0 /128
16:52:14.318	6	
Stage advanced to STATIC_END
16:52:14.412	6	
Stage advanced to DYNAMIC_VALUES
16:52:14.463	6	
TX REQ SendData 2 METER_GET ELECTRIC_A  ACK AUTO_ROUTE EXPLORE
16:52:14.468		
RX ACK 0 /128
16:52:14.480	6	
RX RES SendData 2 ACCEPTED BY CONTROLLER 0 /128
16:52:14.498	6	
RX REQ SendData 2 ACK RECEIVED from device in 35ms 0 /128
16:52:14.803	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KVAH 0 /128
16:52:14.839	6	
STATE UPDATE zwave:device:52508370:node6:meter_current 0.66 [DecimalType]
16:52:14.882	6	
TX REQ SendData 3 METER_GET ELECTRIC_KWH  ACK AUTO_ROUTE EXPLORE
16:52:14.887		
RX ACK 0 /128
16:52:14.898	6	
RX RES SendData 3 ACCEPTED BY CONTROLLER 0 /128
16:52:14.920	6	
RX REQ SendData 3 ACK RECEIVED from device in 38ms 0 /128
16:52:14.934	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
16:52:14.976	6	
STATE UPDATE zwave:device:52508370:node6:meter_kwh 0.53 [DecimalType]
16:52:15.016	6	
TX REQ SendData 4 METER_GET ELECTRIC_V  ACK AUTO_ROUTE EXPLORE
16:52:15.021		
RX ACK 0 /128
16:52:15.034	6	
RX RES SendData 4 ACCEPTED BY CONTROLLER 0 /128
16:52:15.053	6	
RX REQ SendData 4 ACK RECEIVED from device in 37ms 0 /128
16:52:15.067	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
16:52:15.105	6	
STATE UPDATE zwave:device:52508370:node6:meter_voltage 231.49 [DecimalType]
16:52:15.159	6	
TX REQ SendData 5 METER_GET ELECTRIC_W  ACK AUTO_ROUTE EXPLORE
16:52:15.165		
RX ACK 0 /128
16:52:15.174	6	
RX RES SendData 5 ACCEPTED BY CONTROLLER 0 /128
16:52:15.199	6	
RX REQ SendData 5 ACK RECEIVED from device in 40ms 0 /128
16:52:15.215	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_W 0 /128
16:52:15.244	6	
STATE UPDATE zwave:device:52508370:node6:meter_watts 124.8 [DecimalType]
16:52:15.291	6	
TX REQ SendData 6 SWITCH_BINARY_GET  ACK AUTO_ROUTE EXPLORE
16:52:15.297		
RX ACK 0 /128
16:52:15.308	6	
RX RES SendData 6 ACCEPTED BY CONTROLLER 0 /128
16:52:15.334	6	
RX REQ SendData 6 ACK RECEIVED from device in 43ms 0 /128
16:52:15.347	6	
RX REQ ApplicationCommandHandler SWITCH_BINARY_REPORT ON 0 /128
16:52:15.379	6	
STATE UPDATE zwave:device:52508370:node6:switch_binary ON [OnOffType]
16:52:15.430	6	
TX REQ SendData 7 POWERLEVEL_GET  ACK AUTO_ROUTE EXPLORE
16:52:15.435		
RX ACK 0 /128
16:52:15.442	6	
RX RES SendData 7 ACCEPTED BY CONTROLLER 0 /128
16:52:15.476	6	
RX REQ SendData 7 ACK RECEIVED from device in 46ms 0 /128
16:52:15.490	6	
RX REQ ApplicationCommandHandler POWERLEVEL_REPORT 0 /128
16:52:15.556	6	
Stage advanced to DYNAMIC_END
16:52:15.656	6	
Stage advanced to DONE
16:56:37.331	6	
TX REQ SendData 8 SWITCH_BINARY_GET  ACK AUTO_ROUTE EXPLORE
16:56:37.338		
RX ACK 0 /128
16:56:37.347	6	
RX RES SendData 8 ACCEPTED BY CONTROLLER 0 /128
16:56:37.399	6	
RX REQ SendData 8 ACK RECEIVED from device in 68ms 0 /128
16:56:37.425	6	
RX REQ ApplicationCommandHandler SWITCH_BINARY_REPORT ON 0 /128
16:56:37.508	6	
STATE UPDATE zwave:device:52508370:node6:switch_binary ON [OnOffType]
16:56:37.546	6	
TX REQ SendData 9 METER_GET ELECTRIC_A  ACK AUTO_ROUTE EXPLORE
16:56:37.552		
RX ACK 0 /128
16:56:37.566	6	
RX RES SendData 9 ACCEPTED BY CONTROLLER 0 /128
16:56:37.587	6	
RX REQ SendData 9 ACK RECEIVED from device in 41ms 0 /128
16:56:37.618	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KVAH 0 /128
16:56:37.669	6	
STATE UPDATE zwave:device:52508370:node6:meter_current 0.63 [DecimalType]
16:56:37.708	6	
TX REQ SendData 10 METER_GET ELECTRIC_KWH  ACK AUTO_ROUTE EXPLORE
16:56:37.720		
RX ACK 0 /128
16:56:37.732	6	
RX RES SendData 10 ACCEPTED BY CONTROLLER 0 /128
16:56:37.762	6	
RX REQ SendData 10 ACK RECEIVED from device in 54ms 0 /128
16:56:37.796	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
16:56:37.850	6	
STATE UPDATE zwave:device:52508370:node6:meter_kwh 0.54 [DecimalType]
16:56:37.885	6	
TX REQ SendData 11 METER_GET ELECTRIC_W  ACK AUTO_ROUTE EXPLORE
16:56:37.891		
RX ACK 0 /128
16:56:37.899	6	
RX RES SendData 11 ACCEPTED BY CONTROLLER 0 /128
16:56:37.923	6	
RX REQ SendData 11 ACK RECEIVED from device in 38ms 0 /128
16:56:37.939	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_W 0 /128
16:56:37.995	6	
STATE UPDATE zwave:device:52508370:node6:meter_watts 116.92 [DecimalType]
16:56:38.025	6	
TX REQ SendData 12 METER_GET ELECTRIC_V  ACK AUTO_ROUTE EXPLORE
16:56:38.031		
RX ACK 0 /128
16:56:38.043	6	
RX RES SendData 12 ACCEPTED BY CONTROLLER 0 /128
16:56:38.061	6	
RX REQ SendData 12 ACK RECEIVED from device in 36ms 0 /128
16:56:38.077	6	
RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
16:56:38.127	6	
STATE UPDATE zwave:device:52508370:node6:meter_voltage 231.94 [DecimalType]
16:57:49.376		
RX ACK 0 /128
16:57:49.739		
RX ACK 0 /128
16:57:49.995		
RX ACK 0 /128
16:57:50.206		
RX ACK 0 /128
16:57:50.422		
RX ACK 0 /128
16:57:54.336		
RX ACK 0 /128
16:58:49.460		
RX ACK 0 /128
16:58:49.692		
RX ACK 0 /128
16:58:49.897		
RX ACK 0 /128
16:58:50.112		
RX ACK 0 /128
16:58:50.368		
RX ACK 0 /128
16:58:54.426		
RX ACK 0 /128

I do not have much experience with z-wave so would be grateful for any advice on why the scheduled reports are not working.

giunka · March 7, 2019, 3:51pm

I’ve the same problem!

chris · March 7, 2019, 5:03pm

Please use the latest snapshot of the binding. If there are still issues, reconfigure the device (this is an option in the device configuration - just set it to true and save) and also provide a debug log.

avk · March 10, 2019, 5:40pm

Thank you, started working after healing the network.