Channel updates on Aeon energy meters

mhilbush · October 15, 2017, 7:20pm

I just installed two Aeon energy meters – one 1st gen meter (DSB09) and one gen 5 meter (ZW095). I’m not seeing the power (watt) and energy (kWH) channels being updated when reports are received from the gen 1 meter.

Before I dig too much deeper into this, in the log viewer snippets below, the node where the channels are updating correctly show STATE UPDATE after the receipt of each report, versus the other node, which is not showing STATE UPDATE in the viewer. Is this the expected behavior?

This system is using the zwave binding from a recent 2.2 snapshot version (i.e. not the dev version of the zwave binding).

Aeon ZW095, node 67

Gen 5 Aeon energy meter
installed on feed from electric utility
channels seem to be updating correctly
snippet from log viewer below (not sure why the log viewer is not reporting the correct time

Aeon DSB09 Energy Meter, node 68

First generation Aeon energy meter
installed on feed from backup generator
channels do not appear to be updating
snippet from log viewer below

Here’s a snippet of the debug log for the node whose channels are not updating.

15-Oct-2017 14:19:20.887 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Application Command Request (ALIVE:DONE)
15-Oct-2017 14:19:20.887 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 68: Starting initialisation from DONE
15-Oct-2017 14:19:20.887 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2fa5f63c already registered
15-Oct-2017 14:19:20.887 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Incoming command class BATTERY
15-Oct-2017 14:19:20.887 [DEBUG] [nal.protocol.commandclass.ZWaveBatteryCommandClass] - NODE 68: Received Battery Request
15-Oct-2017 14:19:20.888 [DEBUG] [nal.protocol.commandclass.ZWaveBatteryCommandClass] - NODE 68: Battery report value = 100
15-Oct-2017 14:19:20.888 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
15-Oct-2017 14:19:20.888 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 58: Transaction not completed: node address inconsistent.  lastSent=58, incoming=255
15-Oct-2017 14:19:25.848 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 44 08 31 05 04 64 00 07 48 B0 12 
15-Oct-2017 14:19:25.849 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
15-Oct-2017 14:19:25.850 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 04 00 44 08 31 05 04 64 00 07 48 B0 12 
15-Oct-2017 14:19:25.851 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 0E 00 04 00 44 08 31 05 04 64 00 07 48 B0 12 
15-Oct-2017 14:19:25.851 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 44 08 31 05 04 64 00 07 48 B0 
15-Oct-2017 14:19:25.852 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Application Command Request (ALIVE:DONE)
15-Oct-2017 14:19:25.852 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 68: Starting initialisation from DONE
15-Oct-2017 14:19:25.853 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2fa5f63c already registered
15-Oct-2017 14:19:25.853 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Incoming command class SENSOR_MULTILEVEL
15-Oct-2017 14:19:25.853 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 68: Received COMMAND_CLASS_SENSOR_MULTILEVEL command V2
15-Oct-2017 14:19:25.853 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 68: Sensor Multi Level REPORT received
15-Oct-2017 14:19:25.853 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 68: Sensor Type = Power(4), Scale = 0
15-Oct-2017 14:19:25.854 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 68: Sensor Value = 477.36
15-Oct-2017 14:19:25.854 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
15-Oct-2017 14:19:25.854 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 58: Transaction not completed: node address inconsistent.  lastSent=58, incoming=255
15-Oct-2017 14:19:25.890 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 44 0E 32 02 21 74 00 07 48 B0 00 00 00 00 00 00 3F 
15-Oct-2017 14:19:25.892 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
15-Oct-2017 14:19:25.893 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 14 00 04 00 44 0E 32 02 21 74 00 07 48 B0 00 00 00 00 00 00 3F 
15-Oct-2017 14:19:25.894 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 14 00 04 00 44 0E 32 02 21 74 00 07 48 B0 00 00 00 00 00 00 3F 
15-Oct-2017 14:19:25.895 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 44 0E 32 02 21 74 00 07 48 B0 00 00 00 00 00 00 
15-Oct-2017 14:19:25.895 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Application Command Request (ALIVE:DONE)
15-Oct-2017 14:19:25.895 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 68: Starting initialisation from DONE
15-Oct-2017 14:19:25.896 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2fa5f63c already registered
15-Oct-2017 14:19:25.896 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Incoming command class METER
15-Oct-2017 14:19:25.896 [DEBUG] [ernal.protocol.commandclass.ZWaveMeterCommandClass] - NODE 68: Received METER command V2
15-Oct-2017 14:19:25.896 [DEBUG] [ernal.protocol.commandclass.ZWaveMeterCommandClass] - NODE 68: Meter: Type=Electric(1), Scale=W(2), Value=477.36
15-Oct-2017 14:19:25.897 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
15-Oct-2017 14:19:25.897 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 58: Transaction not completed: node address inconsistent.  lastSent=58, incoming=255
15-Oct-2017 14:19:25.989 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 44 0E 32 02 21 64 00 00 00 00 02 D0 00 00 00 00 02 
15-Oct-2017 14:19:25.990 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
15-Oct-2017 14:19:25.990 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 14 00 04 00 44 0E 32 02 21 64 00 00 00 00 02 D0 00 00 00 00 02 
15-Oct-2017 14:19:25.991 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Process Message = 01 14 00 04 00 44 0E 32 02 21 64 00 00 00 00 02 D0 00 00 00 00 02 
15-Oct-2017 14:19:25.991 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 44 0E 32 02 21 64 00 00 00 00 02 D0 00 00 00 00 
15-Oct-2017 14:19:25.991 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Application Command Request (ALIVE:DONE)
15-Oct-2017 14:19:25.991 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 68: Starting initialisation from DONE
15-Oct-2017 14:19:25.992 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2fa5f63c already registered
15-Oct-2017 14:19:25.992 [DEBUG] [tocol.serialmessage.ApplicationCommandMessageClass] - NODE 68: Incoming command class METER
15-Oct-2017 14:19:25.992 [DEBUG] [ernal.protocol.commandclass.ZWaveMeterCommandClass] - NODE 68: Received METER command V2
15-Oct-2017 14:19:25.992 [DEBUG] [ernal.protocol.commandclass.ZWaveMeterCommandClass] - NODE 68: Meter: Type=Electric(1), Scale=kWh(0), Value=0E+1
15-Oct-2017 14:19:25.992 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent

chris · October 15, 2017, 7:40pm

Agreed - looks a bit strange and I would expect the second one to look like the first. The database looks ok (only a quick look, but the channels are there and I think are ok). So, I would next look at what happened when the binding started (ie device initialised and the channels are created). If this is a new device, I’d consider restarting the binding just in case there’s something adrift there.

mhilbush · October 16, 2017, 1:39pm

Yeah, I looked at that too, and it looked fine.

Good idea. By the time I got around to doing that, it had rolled off due to the log file rotation. I guess that’s the consequence of having 50-some nodes…

Yep, I restarted OH and that did the trick. I included both energy meters at nearly the same time, so it’s not clear why one was behaving and one was not. Nevertheless, it’s working now, so I’m not gonna mess with it any longer.