Zwave Binding: Issue with metering and multiple endpoints?

I have a Greenwave 5-port multi-socket which also measures energy consumption for each socket. Today I realized that there might be something wrong with metering the energy consumption, it looks like values getting reported for the wrong endpoint.

To investigate in detail, I switched off and physically removed all but one plug (endpoint 4). But for whatever reason energy values getting reported for endpoint 1 and 4 :confused:

2016-01-28 20:37:41.255 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 1, command class = METER, value = 131.4 2016-01-28 20:37:41.498 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 4, command class = METER, value = 131.4 2016-01-28 20:37:48.755 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 1, command class = METER, value = 257.9 2016-01-28 20:38:06.503 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 3, command class = METER, value = 0E+1 2016-01-28 20:38:11.504 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 2, command class = METER, value = 0E+1 2016-01-28 20:38:16.623 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 1, command class = METER, value = 0E+1 2016-01-28 20:38:16.679 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 5, command class = METER, value = 0E+1 2016-01-28 20:38:36.555 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 4, command class = METER, value = 130.2

Here are the the item definitions:
Number Power_Kueche_Raspb03_Power "Raspb03 [%.1f W]ā€œ (g_Power_Kueche) {zwave="22:1:command=meter,meter_scale=E_W,refresh_interval=55"} Number Power_Kueche_RGB868_Power "RGB868 [%.1f W]ā€œ (g_Power_Kueche) {zwave="22:2:command=meter,meter_scale=E_W,refresh_interval=55" } Number Power_Kueche_Verteil_Power "Verteiler [%.1f W]ā€œ (g_Power_Kueche) {zwave="22:3:command=meter,meter_scale=E_W,refresh_interval=55" } Number Power_Kueche_ECM_Power "ECM [%.1f W]ā€œ (g_Power_Kueche) {zwave="22:4:command=meter,meter_scale=E_W,refresh_interval=55" } Number Power_Kueche_Muehle_Power "Muehle [%.1f W]ā€œ (g_Power_Kueche) {zwave="22:5:command=meter,meter_scale=E_W,refresh_interval=55" }

The mix-up happens both in polling and non-pooling configuration. Has anybody experienced something similar?

Hi Joerg,
Can you provide the debug log please so I can see whatā€™s being received?

Cheers
Chris

Thanks for looking into this. Here is the log:

http://pastebin.com/pS747rPm

Btw, not sure if this is relevant: The association for sending meter reports (non-polling) is still configured in the device.

I donā€™t immediately see anything wrong with what the binding is doing at least. The binding is correctly decoding the endpoint at least (the value is more difficult to decode manually :sunglasses:).

Have you tried plugging in/out more than just number 1 and 4? Can you go through all 6 one by one? It would be interesting to see if endpoint 1 always does this?

Yes, meter readings for all ports are reported with endpoint 1.

Did some internet recherche and it looks like this is a common problem with Greenwave. Most discussions ending with using pollingā€¦

One post (dated 07.1.14) in following thread is mentioning some mapping problems for endpoints. Perhaps it makes sense to you:
https://groups.google.com/forum/#!searchin/openzwave/greenwave/openzwave/MIMVHYlhoYE/vdVFsxa5CeEJ

But frankly, in case this is a device specific issue, I am more than happy to use polling.

I think this link is relating to something we already know - that the discovery of the endpoints isnā€™t 100% correct in the Greenwave. If I remember correctly (I probably should check :wink:) not all endpoints are discovered so we added a comand into the database to add the extra endpointsā€¦

I donā€™t think this affects your problem though since this is associated with multi instance reports :frowning:

Have you scrolled down to the message dated 07.01.14? In my understanding this one is around multi instance reports and describes a possible fix. But I am no expert, so could be unrelated.

In the code I found that in MultiInstance.cpp the instance was defined at position 1:
_uint8 endPoint = data[1] & 0x7f;
_uint8 commandClassId = data[3];

But the endpoint was actually at position 2:
_uint8 endPoint = data[2] & 0x7f;
_uint8 commandClassId = data[3];
Changing this reported the correct power/energy on the instance.

Iā€™d need to look at this more to be sure, but the endpoint isnā€™t always being reported as 1 - based on the log you presented at least. The endpoints are being decoded correctly as your log shows ā€œendpoint 1ā€, ā€œendpoint 4ā€ etcā€¦ But the value is wrong. It seems (I think?) that this must come from the device?

Or maybe Iā€™m still misunderstanding something?

In the meantime I switched the binding to 1.9 (provided by Vincent with the new XML settings.) and also did some restarts / plug-offs. And now the log looks different, all meter reports going to endpoint 1.

Apologize for sending inconsistent messages and the confusion, just realized when I saw you reply :flushed:. But let me double check and upload a new log.

No problem - iā€™ll await your updated logā€¦ Maybe this device is using a newer version of the multi instance command classā€¦ Iā€™ll take a look when I get the logā€¦

Looks like the behavior depends on the binding version.

This is from the 1.9 binding with the XML adjustments made by Vincent and association activated via habmin:
ļ»æ

And this is with the 1.8 binding, config is the same as above.

Log 1.8: https://www.dropbox.com/s/mg334ee0ip8fr3q/zwave.log.1.8?dl=0
Log 1.9: https://www.dropbox.com/s/8bsq5unbgbtzfr4/zwave.log.1.9?dl=0

Sorry - I missed this one - itā€™s been a busy week at work :frowning:

I donā€™t think theres any way that the database can impact the messages the device sends (unless someone reconfigures something), so I canā€™t see how this can really changeā€¦

I also donā€™t know that it has since even in 1.9 log you attach I see multi endpoint messages being sent -:

2016-01-30 15:20:32.797 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 2, command class = METER, value = 0.0002
2016-01-30 15:20:32.881 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 3, command class = SWITCH_BINARY, value = 255
2016-01-30 15:20:32.965 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 3, command class = METER, value = 0.5
2016-01-30 15:20:33.002 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 4, command class = SWITCH_BINARY, value = 255
2016-01-30 15:20:33.083 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 4, command class = METER, value = 134.3
2016-01-30 15:20:33.120 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 5, command class = SWITCH_BINARY, value = 255
2016-01-30 15:20:33.161 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 5, command class = METER, value = 0E+1
2016-01-30 15:20:33.244 [DEBUG] [.z.internal.ZWaveActiveBinding:458 ]- NODE 22: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0.0153

Am I misinterpreting something?

Cheers
Chris