Koenkk / zigbee2mqtt

Zigbee šŸ to MQTT bridge šŸŒ‰, get rid of your proprietary Zigbee bridges šŸ”Ø
https://www.zigbee2mqtt.io
GNU General Public License v3.0
11.72k stars 1.64k forks source link

Zemismart / Tuya SPM02V2 values incorrect converted randomly by z2m / tuya.ts #23291

Open DanielNagy opened 1 month ago

DanielNagy commented 1 month ago

What happened?

Hello, I have this energy monitoring device, configured in Energy in Home assistant. Sometimes I would see impossibly large values in the graph as per below.

image

Due to this device spamming the network, i've also enabled these debounce settings. image

image

image

Looking at the history of the Energy value, I see the device reports 0 kwh, and then jumps back up to 86kwh. This is obviously bad because HA Energy assumes the device reset its statistics, and suddenly thinks there's a 86kwh increase in consumption when it returns.

It also shows some other random values every now and again, but, i only care for Energy kWh image

Now. I'm not sure if there's zigbee communication issues, parsing issues, or if this is just dodgy firmware in the device. (given the other reports of this device flooding the zigbee network, i'm leaning towards bad firmware)

What did you expect to happen?

no erratic reported details.

How to reproduce it (minimal and precise)

Unable to reproduce. Happens randomly

Zigbee2MQTT version

1.39.0

Adapter firmware version

20240315

Adapter

Ethernet Zubeszb

Setup

Hassio X86 VM on proxmox with z2m addon

Debug log

See Timestamp [2024-07-08 20:39:49] where it is reported as "energy":0

Tuya SPM02V2 TS0601 _TZE200_v9hkz2yn zigbee debug log.txt

DanielNagy commented 1 month ago

Ok, I've looked the following 3 zigbee messages both before and after the reported 0 value.

[2024-07-08 20:39:30] debug:  z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[0,0,33,179],"type":"Buffer"},"datatype":2,"dp":1}],"seq":30464}' from endpoint 1 with groupID 0
[2024-07-08 20:39:30] info:   z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Power monitor Actron', payload '{"ac_frequency":49.98,"current_a":2.15,"current_b":2.162,"current_c":4.253,"energy":86.26,"linkquality":29,"power":1836,"power_a":477,"power_b":484,"power_c":875,"power_factor":88,"produced_energy":0,"voltage_a":238.7,"voltage_b":242.5,"voltage_c":238.4}'

[2024-07-08 20:39:49] debug:  z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[0,0,33,180],"type":"Buffer"},"datatype":2,"dp":1}],"seq":38656}' from endpoint 1 with groupID 0
[2024-07-08 20:39:49] info:   z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Power monitor Actron', payload '{"ac_frequency":50,"current_a":2.15,"current_b":2.17,"current_c":4.273,"energy":0,"linkquality":29,"power":1844,"power_a":479,"power_b":487,"power_c":881,"power_factor":88,"produced_energy":0,"voltage_a":239.2,"voltage_b":242.8,"voltage_c":238.8}'

[2024-07-08 20:40:07] debug:  z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[0,0,33,181],"type":"Buffer"},"datatype":2,"dp":1}],"seq":49664}' from endpoint 1 with groupID 0
[2024-07-08 20:40:07] info:   z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Power monitor Actron', payload '{"ac_frequency":49.96,"current_a":2.195,"current_b":2.22,"current_c":4.138,"energy":86.28,"linkquality":25,"power":1844,"power_a":489,"power_b":500,"power_c":852,"power_factor":88,"produced_energy":0,"voltage_a":238.9,"voltage_b":242.7,"voltage_c":238.7}'

Hrm.. Here's a picture to better highlight my findings in the 3 message logs above. image

It appears the zigbee message recieved is correct [0,0,33,180], 0x21B4, dec 8628, so it should have been parsed as 86.27, but was parsed as 0.

DanielNagy commented 1 month ago

As for other erratic values. Here is the Log file where AC Frequency drops to 0. Tuya SPM02V2 TS0601 _TZE200_v9hkz2yn zigbee debug frequency 0hz 2204 log.txt image

Now, this one is interesting.

It seems that the Tuya Data point for AC Frequency is DP 101 [101, 'ac_frequency', tuya.valueConverter.divideBy100], and searching all instances of 101,2 in the log shows the following image

Note the 5 underlined messages. It appears to be an additional "0" before the 4, which I assume is throwing off the parsing. Apart from the additional "0", it then continues with the 4, assuming buffer length of 4 bytes, then the actual freq value 0,0,19,135 (4999 / 49.99).

Here is the message in detail. [2024-07-08 22:04:46] debug: z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[],"type":"Buffer"},"datatype":2,"dp":101},{"data":{"data":[],"type":"Buffer"},"datatype":0,"dp":4}],"seq":32512}' from endpoint 1 with groupID 0 It has parsed no data for dp 101, assuming its mistaken the additional "0" for 0 byte length data. but then starts to parse the rest of the packet as dp 4 as 0 buffer length as well. (There doesnt appear to be a documented datapoint 4 in the tuya convertor file)

So in regards to the Frequency showing 0, is it 1) zigbee rf comms? (link quality is reported at 21lqi) would checksum have failed? 2) is the tuya parser not parsing this correctly? 3) firmware bug in the device adding additional 0 byte?

This appears a different issue to the Energy reporting as 0 as noted by my previous comment showing the Zigbee message data was actually parsing correctly according to the payload.

Either way, I don't care so much about frequency, just providing further detail to possibly fix this, but i'm more so interested in the energy issue being fixed.

DanielNagy commented 1 month ago

Not sure if relavent, but i noted my "Power monitor Actron Power A" was reporting zero until 11am this morning when i ran a z2m "reconfigure" on the power device.

look at the blue graph line where i've marked in yellow. 11am i ran reconfigure and it fixed it. However Current for same "a" phase was reporting fine.

image

DanielNagy commented 1 month ago

Another occurance

image

Note the highlighted random "energy":26005.87

image

[2024-07-10 06:41:08] debug:  z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[0,0,39,174],"type":"Buffer"},"datatype":2,"dp":1}],"seq":63744}' from endpoint 1 with groupID 0
[2024-07-10 06:41:08] info:   z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Power monitor Actron', payload '{"ac_frequency":49.97,"current_a":0.142,"current_b":0.143,"current_c":0.378,"energy":26005.87,"linkquality":21,"power":48,"power_a":0,"power_b":1,"power_c":47,"power_factor":30,"produced_energy":0,"voltage_a":238.2,"voltage_b":241.5,"voltage_c":240}'

Not sure how z2m got 26005.87 from bytes [0,0,39,174] 0x27AE, being 10158, which is what it should have been. (as per the correctly reported 101.58 values before and after)

Log attached.

26005.87 energy.log

DanielNagy commented 1 month ago

image

DanielNagy commented 1 month ago

@Koenkk any idea on what else I can look into here?

I've got multiple zemismart (the single phase and 3phase versions) zigbee energy devices, and they all randomly parse random values.

Based on the earlier logs I provided it looks like the zigbee message is parsed correctly, but the Tuya conversation part is randomly failing to parse the value. But even then I'm not entirely sure what I'm looking at.

Ie, I see random values like this at times. image

image

Koenkk commented 1 month ago

Because of the debouncing it's a bit hard to see where exactly the value changes, can you provide a debug log with debounce disabled when getting an incorrect energy value + a correct value after that?

See this on how to enable debug logging.

DanielNagy commented 1 month ago

Thanks @Koenkk

I turned Debounce off for Power Monitor Spa Tuya model: 'SPM02V2', (the 3 phase zemismarts energy meters flood the network, no new firmware available yet to reduce it to 14 seconds like the single phase zemismarts) FYI The single phase SPM01V2's do not have debounce (Power Monitor Pool GPO LeftCB Energy) in previous comment screenshot.

image

"voltage_b":63719.9

Power Monitor Spa voltage_b 63719.9.log

So i can see this value being parsed for DP 105 being voltage_b

image

Is this a Zemismart / Tuya Firmware bug? I assume there might have been a checksum error if it was RF interferance?

Is this a Co-ordinator firmware parsing bug? I'm now running zStack3x0 Coordinator revision 20240710 as i see those beta releases since you said the latest "stable" was broken

Is this a Zigbee2Mqtt Parser bug? (1.39.1)

Datapoints for your convenience. specifically Voltage b being 105.

            tuyaDatapoints: [
                [1, 'energy', tuya.valueConverter.divideBy100],
                [2, 'produced_energy', tuya.valueConverter.divideBy100],
                // [6, null, tuya.valueConverter.phaseVariant2WithPhase('X')],
                // [7, null, tuya.valueConverter.phaseVariant2WithPhase('Y')],
                // [8, null, tuya.valueConverter.phaseVariant2WithPhase('Z')],
                [15, 'power_factor', tuya.valueConverter.raw],
                [101, 'ac_frequency', tuya.valueConverter.divideBy100],
                [102, 'voltage_a', tuya.valueConverter.divideBy10],
                [103, 'current_a', tuya.valueConverter.divideBy1000],
                [104, 'power_a', tuya.valueConverter.raw],
                [105, 'voltage_b', tuya.valueConverter.divideBy10],
                [106, 'current_b', tuya.valueConverter.divideBy1000],
                [107, 'power_b', tuya.valueConverter.raw],
                [108, 'voltage_c', tuya.valueConverter.divideBy10],
                [109, 'current_c', tuya.valueConverter.divideBy1000],
                [110, 'power_c', tuya.valueConverter.raw],
                [111, 'power', tuya.valueConverter.raw],
            ],
Koenkk commented 4 weeks ago

It looks like the device reports a wrong value, so this doesn't look to be a parser bug.

I assume there might have been a checksum error if it was RF interferance?

Yes

I think the only thing we can do from z2m is ignore values above a certain value.

DanielNagy commented 4 weeks ago

Thanks @Koenkk,

I'll report this intermitant random value bug to zemismart.

Based on what i see in that screenshot above, its almost like they have indexing problems when aligning the data to be transmitted, ie, they forgot a '0'. It Should have been 0, 0, 9, 185 like the rest.

However, i'm still a little confused about the 26005.87 example i posted earlier. That one seemed to parse the data correctly, however, it failed to convert it to the correct value. (the full log was posted earlier 26005.87.energy.log)

[2024-07-10 06:41:08] debug:  z2m: Received Zigbee message from 'Power monitor Actron', type 'commandDataResponse', cluster 'manuSpecificTuya', data '{"dpValues":[{"data":{"data":[0,0,39,174],"type":"Buffer"},"datatype":2,"dp":1}],"seq":63744}' from endpoint 1 with groupID 0
[2024-07-10 06:41:08] info:   z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Power monitor Actron', payload '{"ac_frequency":49.97,"current_a":0.142,"current_b":0.143,"current_c":0.378,"energy":26005.87,"linkquality":21,"power":48,"power_a":0,"power_b":1,"power_c":47,"power_factor":30,"produced_energy":0,"voltage_a":238.2,"voltage_b":241.5,"voltage_c":240}'

As you can see, the data recieved was [0, 0, 39, 174], which should have converted to 10158 (101.58 once divided by 100). How did it end up as 26005.87

Koenkk commented 4 weeks ago

This was still with the debouncing on right? Then you cannot related the Received Zigbee message and MQTT publish 1:1

DanielNagy commented 4 weeks ago

Oh yes. That was with debounce.

Either way, thanks for your help, I've initiated return process for all these zemismart spm01v2, and spm02v2 devices I have. Will look for alternative products to measure circuits.

DanielNagy commented 1 day ago

@Koenkk I think I may have solved the issue. Its been 12 hours so far, and no erratic values usually i'd have a handful already across the multiple zemismart energy meters I have installed.

I've got a older round 2022 TubesZB Ethernet running the CC2652P2 https://github.com/tube0013/tube_gateways/tree/main/models/current/tubeszb-cc2652-eth_usb

Whilst i've tried a number of different Z-Stack firmwares to see if its the problem. I failed to consider the Esphome Firmware on the ESP32, which as you know runs the Serial to IP Bridge. This morning I upgraded the ESP32 using a newer Firmware based on this esphome yaml https://github.com/tube0013/tube_gateways/blob/main/models/current/tubeszb-cc2652-eth_usb/firmware/esphome/tubezb-cc2652p2-ethusb-2022.yaml I note that it now uses a newer esphome-stream-server-v2 instead of Serial-Server, which appears to be newer UART-IP bridge code than mine was shipped with (it now has the current esphome web interface also).

I also updated to the latest esphome firmware also. image

As mentioned, 12 hours in, and so far, no erratic values. Will see how this goes for a few days before comfirming 100% is has been resolved.