kbialek / deye-inverter-mqtt

Reads Deye solar inverter metrics and posts them over MQTT
Apache License 2.0
230 stars 50 forks source link

day_energy and total_energy reports 0 #189

Closed CarstenGrohmann closed 2 months ago

CarstenGrohmann commented 4 months ago

I use your software for a few months and it runs stable.

Unfortunatelly it reports unexpected 0s in the morning and the evening e.g. for day_enery and total_energy.

Both zeros are illogical for the total_energy, as the total_energy is a steadily increasing value that should not be 0 except at the very beginning.

The situation is similar with day_energy. Zero values are only expected in the morning after the time reset. In the evening, after the values have risen steadily throughout the day, a 0 value is illogical and unexpected.

I prefer to send no values rather than a series of zeros.

In addition, the 0 for day_energy in the evening breaks the calculation of my self-used solar energy as provided by Home Assistant.

What do you think about this behaviour?

Expected behavior Continuous line that is interrupted overnight because the inverter and logger are offline overnight. The line does not go down to 0 either in the morning or in the evening.

Screenshots image

image

Hardware (please complete the following information):

Software (please complete the following information):

Logs

Logger is online for the first time this day:

2024-07-20 03:28:00,909 - DeyeDaemon - DEBUG - Invoking action
2024-07-20 03:28:00,910 - DeyeInverterState - INFO - Reading start
2024-07-20 03:28:00,910 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-07-20 03:28:00,939 - DeyeTcpConnector - INFO - Re-connected to socket on IP 192.168.178.42
2024-07-20 03:28:00,939 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf60200000000000000000000000000000103003c003945d4b615
2024-07-20 03:28:01,114 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000129acebf60201c07a2f012d0000000000000001037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab9415
2024-07-20 03:28:01,116 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-07-20 03:28:01,120 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf602000000000000000000000000000001030028000104025715
2024-07-20 03:28:01,175 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015000229acebf60201c07a2f012d000000000000000103020064b9af5e15
2024-07-20 03:28:01,177 - DeyeInverterState - DEBUG - Production today: 0.0
2024-07-20 03:28:01,177 - DeyeInverterState - DEBUG - Production Total: 0.0
2024-07-20 03:28:01,178 - DeyeInverterState - DEBUG - Phase1 Voltage: 0.0
2024-07-20 03:28:01,179 - DeyeInverterState - DEBUG - Phase1 Current: 0.0
2024-07-20 03:28:01,180 - DeyeInverterState - DEBUG - Phase1 Power: 0.0
2024-07-20 03:28:01,181 - DeyeInverterState - DEBUG - AC Freq: 0.0
2024-07-20 03:28:01,181 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-07-20 03:28:01,181 - DeyeInverterState - DEBUG - PV1 Voltage: 0.0
2024-07-20 03:28:01,182 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-20 03:28:01,182 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-20 03:28:01,183 - DeyeInverterState - DEBUG - PV1 Production today: 0.0
2024-07-20 03:28:01,183 - DeyeInverterState - DEBUG - PV1 Total: 0.0
2024-07-20 03:28:01,183 - DeyeInverterState - DEBUG - PV2 Voltage: 0.0
2024-07-20 03:28:01,184 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-20 03:28:01,184 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-20 03:28:01,185 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-07-20 03:28:01,185 - DeyeInverterState - DEBUG - PV2 Total: 0.0
2024-07-20 03:28:01,185 - DeyeInverterState - DEBUG - PV3 Voltage: 0.0
2024-07-20 03:28:01,186 - DeyeInverterState - DEBUG - PV3 Current: 0.0
2024-07-20 03:28:01,186 - DeyeInverterState - DEBUG - PV3 Power: 0.0
2024-07-20 03:28:01,186 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-07-20 03:28:01,187 - DeyeInverterState - DEBUG - PV3 Total: 0.0
2024-07-20 03:28:01,187 - DeyeInverterState - DEBUG - PV4 Voltage: 0.0
2024-07-20 03:28:01,187 - DeyeInverterState - DEBUG - PV4 Current: 0.0
2024-07-20 03:28:01,188 - DeyeInverterState - DEBUG - PV4 Power: 0.0
2024-07-20 03:28:01,188 - DeyeInverterState - DEBUG - PV4 Production today: 0.0
2024-07-20 03:28:01,189 - DeyeInverterState - DEBUG - PV4 Total: 0.0
2024-07-20 03:28:01,189 - DeyeInverterState - DEBUG - DC Total Power: 0.0
2024-07-20 03:28:01,190 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-07-20 03:28:01,190 - DeyeInverterState - DEBUG - AC Active Power: 0.0
2024-07-20 03:28:01,190 - DeyeInverterState - DEBUG - Radiator temperature: -10.0
2024-07-20 03:28:01,191 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/logger_status', value: 'online'
2024-07-20 03:28:01,192 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17636), 'b'deyemqtt/logger_status'', ... (6 bytes)
2024-07-20 03:28:01,195 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17636)
2024-07-20 03:28:01,197 - DeyeMqttClient - INFO - Logger is online
2024-07-20 03:28:01,197 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/day_energy', value: '0.0'
2024-07-20 03:28:01,198 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17637), 'b'deyemqtt/day_energy'', ... (3 bytes)
2024-07-20 03:28:01,199 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17637)
2024-07-20 03:28:01,201 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/total_energy', value: '0.0'
2024-07-20 03:28:01,201 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17638), 'b'deyemqtt/total_energy'', ... (3 bytes)
2024-07-20 03:28:01,203 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17638)

First zero value in the morning:

2024-07-20 03:33:00,910 - DeyeDaemon - DEBUG - Invoking action
2024-07-20 03:33:00,911 - DeyeInverterState - INFO - Reading start
2024-07-20 03:33:00,911 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-07-20 03:33:00,917 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf60200000000000000000000000000000103003c003945d4b615
2024-07-20 03:33:01,097 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000929acebf602019f7b2f010c0100000000000001037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab5c15
2024-07-20 03:33:01,098 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-07-20 03:33:01,101 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf602000000000000000000000000000001030028000104025715
2024-07-20 03:33:01,158 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015000a29acebf602019f7b2f010c010000000000000103020064b9af2615
2024-07-20 03:33:01,159 - DeyeInverterState - DEBUG - Production today: 0.0
2024-07-20 03:33:01,160 - DeyeInverterState - DEBUG - Production Total: 0.0
2024-07-20 03:33:01,160 - DeyeInverterState - DEBUG - Phase1 Voltage: 0.0
2024-07-20 03:33:01,161 - DeyeInverterState - DEBUG - Phase1 Current: 0.0
2024-07-20 03:33:01,161 - DeyeInverterState - DEBUG - Phase1 Power: 0.0
2024-07-20 03:33:01,162 - DeyeInverterState - DEBUG - AC Freq: 0.0
2024-07-20 03:33:01,163 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-07-20 03:33:01,164 - DeyeInverterState - DEBUG - PV1 Voltage: 0.0
2024-07-20 03:33:01,164 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-20 03:33:01,164 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-20 03:33:01,165 - DeyeInverterState - DEBUG - PV1 Production today: 0.0
2024-07-20 03:33:01,165 - DeyeInverterState - DEBUG - PV1 Total: 0.0
2024-07-20 03:33:01,165 - DeyeInverterState - DEBUG - PV2 Voltage: 0.0
2024-07-20 03:33:01,166 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-20 03:33:01,166 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-20 03:33:01,166 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-07-20 03:33:01,167 - DeyeInverterState - DEBUG - PV2 Total: 0.0
2024-07-20 03:33:01,167 - DeyeInverterState - DEBUG - PV3 Voltage: 0.0
2024-07-20 03:33:01,167 - DeyeInverterState - DEBUG - PV3 Current: 0.0
2024-07-20 03:33:01,168 - DeyeInverterState - DEBUG - PV3 Power: 0.0
2024-07-20 03:33:01,168 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-07-20 03:33:01,168 - DeyeInverterState - DEBUG - PV3 Total: 0.0
2024-07-20 03:33:01,169 - DeyeInverterState - DEBUG - PV4 Voltage: 0.0
2024-07-20 03:33:01,169 - DeyeInverterState - DEBUG - PV4 Current: 0.0
2024-07-20 03:33:01,169 - DeyeInverterState - DEBUG - PV4 Power: 0.0
2024-07-20 03:33:01,170 - DeyeInverterState - DEBUG - PV4 Production today: 0.0
2024-07-20 03:33:01,170 - DeyeInverterState - DEBUG - PV4 Total: 0.0
2024-07-20 03:33:01,170 - DeyeInverterState - DEBUG - DC Total Power: 0.0
2024-07-20 03:33:01,171 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-07-20 03:33:01,171 - DeyeInverterState - DEBUG - AC Active Power: 0.0
2024-07-20 03:33:01,171 - DeyeInverterState - DEBUG - Radiator temperature: -10.0
2024-07-20 03:33:01,172 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-07-20 03:33:01,172 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/logger_status', value: 'online'
2024-07-20 03:33:01,172 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17886), 'b'deyemqtt/logger_status'', ... (6 bytes)
2024-07-20 03:33:01,174 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17886)
2024-07-20 03:33:01,177 - DeyeMqttClient - INFO - Logger is online
2024-07-20 03:33:01,178 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/day_energy', value: '0.0'
2024-07-20 03:33:01,178 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17887), 'b'deyemqtt/day_energy'', ... (3 bytes)
2024-07-20 03:33:01,180 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17887)
2024-07-20 03:33:01,182 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/total_energy', value: '0.0'
2024-07-20 03:33:01,182 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17888), 'b'deyemqtt/total_energy'', ... (3 bytes)
2024-07-20 03:33:01,184 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17888)

First non-zero value in the morning:

2024-07-20 03:34:00,911 - DeyeDaemon - DEBUG - Invoking action
2024-07-20 03:34:00,911 - DeyeInverterState - INFO - Reading start
2024-07-20 03:34:00,912 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-07-20 03:34:00,915 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf60200000000000000000000000000000103003c003945d4b615
2024-07-20 03:34:01,273 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000b29acebf60201db7b2f014801000000000000010372001300000000105700000013000000000000105700000000000009600000000000000000000013880000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000040000000000000000000001320000000000000000000000000000e0723415
2024-07-20 03:34:01,275 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-07-20 03:34:01,279 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf602000000000000000000000000000001030028000104025715
2024-07-20 03:34:01,587 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015000c29acebf60201db7b2f0148010000000000000103020064b9afa015
2024-07-20 03:34:01,588 - DeyeInverterState - DEBUG - Production today: 1.9
2024-07-20 03:34:01,589 - DeyeInverterState - DEBUG - Production Total: 418.3
2024-07-20 03:34:01,589 - DeyeInverterState - DEBUG - Phase1 Voltage: 240.0
2024-07-20 03:34:01,590 - DeyeInverterState - DEBUG - Phase1 Current: 0.0
2024-07-20 03:34:01,590 - DeyeInverterState - DEBUG - Phase1 Power: 0.0
2024-07-20 03:34:01,590 - DeyeInverterState - DEBUG - AC Freq: 50.0
2024-07-20 03:34:01,591 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-07-20 03:34:01,591 - DeyeInverterState - DEBUG - PV1 Voltage: 30.6
2024-07-20 03:34:01,591 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-20 03:34:01,592 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-20 03:34:01,593 - DeyeInverterState - DEBUG - PV1 Production today: 1.9
2024-07-20 03:34:01,593 - DeyeInverterState - DEBUG - PV1 Total: 418.3
2024-07-20 03:34:01,594 - DeyeInverterState - DEBUG - PV2 Voltage: 0.0
2024-07-20 03:34:01,594 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-20 03:34:01,595 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-20 03:34:01,596 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-07-20 03:34:01,597 - DeyeInverterState - DEBUG - PV2 Total: 0.0
2024-07-20 03:34:01,597 - DeyeInverterState - DEBUG - PV3 Voltage: 0.0
2024-07-20 03:34:01,598 - DeyeInverterState - DEBUG - PV3 Current: 0.0
2024-07-20 03:34:01,598 - DeyeInverterState - DEBUG - PV3 Power: 0.0
2024-07-20 03:34:01,599 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-07-20 03:34:01,600 - DeyeInverterState - DEBUG - PV3 Total: 0.0
2024-07-20 03:34:01,600 - DeyeInverterState - DEBUG - PV4 Voltage: 0.0
2024-07-20 03:34:01,601 - DeyeInverterState - DEBUG - PV4 Current: 0.0
2024-07-20 03:34:01,601 - DeyeInverterState - DEBUG - PV4 Power: 0.0
2024-07-20 03:34:01,601 - DeyeInverterState - DEBUG - PV4 Production today: 0.0
2024-07-20 03:34:01,602 - DeyeInverterState - DEBUG - PV4 Total: 0.0
2024-07-20 03:34:01,602 - DeyeInverterState - DEBUG - DC Total Power: 0.0
2024-07-20 03:34:01,603 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-07-20 03:34:01,603 - DeyeInverterState - DEBUG - AC Active Power: 0.0
2024-07-20 03:34:01,604 - DeyeInverterState - DEBUG - Radiator temperature: -10.0
2024-07-20 03:34:01,604 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-07-20 03:34:01,605 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/logger_status', value: 'online'
2024-07-20 03:34:01,605 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17936), 'b'deyemqtt/logger_status'', ... (6 bytes)
2024-07-20 03:34:01,608 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17936)
2024-07-20 03:34:01,609 - DeyeMqttClient - INFO - Logger is online
2024-07-20 03:34:01,609 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/day_energy', value: '1.9'
2024-07-20 03:34:01,610 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17937), 'b'deyemqtt/day_energy'', ... (3 bytes)
2024-07-20 03:34:01,612 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17937)
2024-07-20 03:34:01,613 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/total_energy', value: '418.3'
2024-07-20 03:34:01,614 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m17938), 'b'deyemqtt/total_energy'', ... (5 bytes)
2024-07-20 03:34:01,617 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 17938)

Last non-zero value in the evening:

2024-07-20 18:48:01,108 - DeyeDaemon - DEBUG - Invoking action
2024-07-20 18:48:01,109 - DeyeInverterState - INFO - Reading start
2024-07-20 18:48:01,109 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-07-20 18:48:01,186 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf60200000000000000000000000000000103003c003945d4b615
2024-07-20 18:48:01,363 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015001029acebf60201c34e3001c00100000000000001037200110000000010680000001100000000000010680000000000000938000000000000000000001388000000000000000000000000000a0000000000000fd200000000000000000000000000000000000000000000000000040000000000000000000000b500000000000000000000000000006e210d15
2024-07-20 18:48:01,365 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-07-20 18:48:01,369 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf602000000000000000000000000000001030028000104025715
2024-07-20 18:48:01,423 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015001129acebf60201c34e3001c0010000000000000103020064b9afd915
2024-07-20 18:48:01,424 - DeyeInverterState - DEBUG - Production today: 1.7
2024-07-20 18:48:01,424 - DeyeInverterState - DEBUG - Production Total: 420.0
2024-07-20 18:48:01,425 - DeyeInverterState - DEBUG - Phase1 Voltage: 236.0
2024-07-20 18:48:01,425 - DeyeInverterState - DEBUG - Phase1 Current: 0.0
2024-07-20 18:48:01,426 - DeyeInverterState - DEBUG - Phase1 Power: 0.0
2024-07-20 18:48:01,426 - DeyeInverterState - DEBUG - AC Freq: 50.0
2024-07-20 18:48:01,426 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-07-20 18:48:01,427 - DeyeInverterState - DEBUG - PV1 Voltage: 18.1
2024-07-20 18:48:01,427 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-20 18:48:01,428 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-20 18:48:01,428 - DeyeInverterState - DEBUG - PV1 Production today: 1.7
2024-07-20 18:48:01,429 - DeyeInverterState - DEBUG - PV1 Total: 420.0
2024-07-20 18:48:01,429 - DeyeInverterState - DEBUG - PV2 Voltage: 0.0
2024-07-20 18:48:01,430 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-20 18:48:01,430 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-20 18:48:01,431 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-07-20 18:48:01,432 - DeyeInverterState - DEBUG - PV2 Total: 0.0
2024-07-20 18:48:01,433 - DeyeInverterState - DEBUG - PV3 Voltage: 0.0
2024-07-20 18:48:01,433 - DeyeInverterState - DEBUG - PV3 Current: 0.0
2024-07-20 18:48:01,433 - DeyeInverterState - DEBUG - PV3 Power: 0.0
2024-07-20 18:48:01,434 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-07-20 18:48:01,435 - DeyeInverterState - DEBUG - PV3 Total: 0.0
2024-07-20 18:48:01,435 - DeyeInverterState - DEBUG - PV4 Voltage: 0.0
2024-07-20 18:48:01,436 - DeyeInverterState - DEBUG - PV4 Current: 0.0
2024-07-20 18:48:01,436 - DeyeInverterState - DEBUG - PV4 Power: 0.0
2024-07-20 18:48:01,437 - DeyeInverterState - DEBUG - PV4 Production today: 0.0
2024-07-20 18:48:01,437 - DeyeInverterState - DEBUG - PV4 Total: 0.0
2024-07-20 18:48:01,438 - DeyeInverterState - DEBUG - DC Total Power: 0.0
2024-07-20 18:48:01,438 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-07-20 18:48:01,439 - DeyeInverterState - DEBUG - AC Active Power: 1.0
2024-07-20 18:48:01,439 - DeyeInverterState - DEBUG - Radiator temperature: 30.5
2024-07-20 18:48:01,440 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-07-20 18:48:01,440 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/logger_status', value: 'online'
2024-07-20 18:48:01,441 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63071), 'b'deyemqtt/logger_status'', ... (6 bytes)
2024-07-20 18:48:01,443 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63071)
2024-07-20 18:48:01,446 - DeyeMqttClient - INFO - Logger is online
2024-07-20 18:48:01,446 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/day_energy', value: '1.7'
2024-07-20 18:48:01,447 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63072), 'b'deyemqtt/day_energy'', ... (3 bytes)
2024-07-20 18:48:01,449 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63072)
2024-07-20 18:48:01,450 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/total_energy', value: '420.0'
2024-07-20 18:48:01,451 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63073), 'b'deyemqtt/total_energy'', ... (5 bytes)
2024-07-20 18:48:01,453 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63073)

First zero value in the evening:

2024-07-20 18:50:01,109 - DeyeDaemon - DEBUG - Invoking action
2024-07-20 18:50:01,109 - DeyeInverterState - INFO - Reading start
2024-07-20 18:50:01,110 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-07-20 18:50:01,118 - DeyeTcpConnector - INFO - Re-connected to socket on IP 192.168.178.42
2024-07-20 18:50:01,119 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf60200000000000000000000000000000103003c003945d4b615
2024-07-20 18:50:01,300 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000129acebf602019c4e3001310000000000000001037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab4915
2024-07-20 18:50:01,302 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-07-20 18:50:01,311 - DeyeTcpConnector - DEBUG - Request frame: a517001045000029acebf602000000000000000000000000000001030028000104025715
2024-07-20 18:50:01,523 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015000229acebf602019c4e300131000000000000000103020064b9af1315
2024-07-20 18:50:01,524 - DeyeInverterState - DEBUG - Production today: 0.0
2024-07-20 18:50:01,525 - DeyeInverterState - DEBUG - Production Total: 0.0
2024-07-20 18:50:01,525 - DeyeInverterState - DEBUG - Phase1 Voltage: 0.0
2024-07-20 18:50:01,525 - DeyeInverterState - DEBUG - Phase1 Current: 0.0
2024-07-20 18:50:01,526 - DeyeInverterState - DEBUG - Phase1 Power: 0.0
2024-07-20 18:50:01,527 - DeyeInverterState - DEBUG - AC Freq: 0.0
2024-07-20 18:50:01,527 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-07-20 18:50:01,527 - DeyeInverterState - DEBUG - PV1 Voltage: 0.0
2024-07-20 18:50:01,528 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-20 18:50:01,528 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-20 18:50:01,528 - DeyeInverterState - DEBUG - PV1 Production today: 0.0
2024-07-20 18:50:01,529 - DeyeInverterState - DEBUG - PV1 Total: 0.0
2024-07-20 18:50:01,529 - DeyeInverterState - DEBUG - PV2 Voltage: 0.0
2024-07-20 18:50:01,529 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-20 18:50:01,530 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-20 18:50:01,530 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-07-20 18:50:01,530 - DeyeInverterState - DEBUG - PV2 Total: 0.0
2024-07-20 18:50:01,531 - DeyeInverterState - DEBUG - PV3 Voltage: 0.0
2024-07-20 18:50:01,531 - DeyeInverterState - DEBUG - PV3 Current: 0.0
2024-07-20 18:50:01,531 - DeyeInverterState - DEBUG - PV3 Power: 0.0
2024-07-20 18:50:01,532 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-07-20 18:50:01,532 - DeyeInverterState - DEBUG - PV3 Total: 0.0
2024-07-20 18:50:01,532 - DeyeInverterState - DEBUG - PV4 Voltage: 0.0
2024-07-20 18:50:01,533 - DeyeInverterState - DEBUG - PV4 Current: 0.0
2024-07-20 18:50:01,533 - DeyeInverterState - DEBUG - PV4 Power: 0.0
2024-07-20 18:50:01,533 - DeyeInverterState - DEBUG - PV4 Production today: 0.0
2024-07-20 18:50:01,533 - DeyeInverterState - DEBUG - PV4 Total: 0.0
2024-07-20 18:50:01,534 - DeyeInverterState - DEBUG - DC Total Power: 0.0
2024-07-20 18:50:01,534 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-07-20 18:50:01,534 - DeyeInverterState - DEBUG - AC Active Power: 0.0
2024-07-20 18:50:01,535 - DeyeInverterState - DEBUG - Radiator temperature: -10.0
2024-07-20 18:50:01,535 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-07-20 18:50:01,536 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/logger_status', value: 'online'
2024-07-20 18:50:01,536 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63124), 'b'deyemqtt/logger_status'', ... (6 bytes)
2024-07-20 18:50:01,538 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63124)
2024-07-20 18:50:01,541 - DeyeMqttClient - INFO - Logger is online
2024-07-20 18:50:01,541 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/day_energy', value: '0.0'
2024-07-20 18:50:01,542 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63125), 'b'deyemqtt/day_energy'', ... (3 bytes)
2024-07-20 18:50:01,544 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63125)
2024-07-20 18:50:01,547 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deyemqtt/total_energy', value: '0.0'
2024-07-20 18:50:01,549 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m63126), 'b'deyemqtt/total_energy'', ... (3 bytes)
2024-07-20 18:50:01,551 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 63126)
kbialek commented 3 months ago

@CarstenGrohmann hi! This software only publishes the values read from the inverter. Your inverter returns zeros, and that is what is published.

Let's look at this response frame:

a585001015000929acebf602019f7b2f010c0100000000000001037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab5c15

It contains this ModbusRTU frame inside:

01037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab

Even without decoding, it is obvious that it contains zeros only. It's worth noting that the CRC is valid, which indicates, that the communication is working correctly.

EDIT: Two questions:

  1. Is your inverter connected to the internet?
  2. Do you have automatic time setting enabled? (DEYE_FEATURE_SET_TIME config variable)
CarstenGrohmann commented 3 months ago

My converter has no connection to the internet and DEYE_FEATURE_SET_TIME is set to true.

I'll update the firmware to the newest 2.32 releae and check, if this solves this issue.

nifoc commented 3 months ago

I'm sorry for what is essentially a +1, but I'm noticing the same behavior.

At some point during the day day_energy suddenly becomes 0 and then returns to the previous (correct) measurement during the next poll.

Maybe this can be handled so that it simply sends nothing instead of 0 in cases where 0 doesn't make any sense?

CarstenGrohmann commented 3 months ago

@nifoc: Which inverter and which firmware are you using?

kbialek commented 3 months ago

Maybe this can be handled so that it simply sends nothing instead of 0 in cases where 0 doesn't make any sense?

The question is how to define "where 0 doesn't make any sense"?

Options:

Ignore Modbus response frames having zeros only

What do you think? Or maybe you have other proposal?

This feature would have to be put behind a feature flag, and be disabled by default.

CarstenGrohmann commented 3 months ago

I had trouble with the newest firmware and rolled back to MW3_16U_5406_1.63. The firmware 1.63 reports the same zero frames as reported above.

Therefore, I would prefer the first option as it prevents data from being pushed like in the "Logger is online for the first time this day" and "First zero value in the evening" sections.

@nifoc: In such a case, are all your values 0 or only day_energy?

CarstenGrohmann commented 2 months ago

Short update as I tested a small hack to filter 0 frames based on our discussion.

I added this temporary workaround to my docker container:

diff --git a/src/deye_modbus.py b/src/deye_modbus.py
index 1178712..13666d4 100644
--- a/src/deye_modbus.py
+++ b/src/deye_modbus.py
@@ -47,6 +47,9 @@ class DeyeModbus:
         modbus_crc.reverse()

         modbus_resp_frame = self.connector.send_request(modbus_frame + modbus_crc)
+        if "0" * 80 in modbus_resp_frame.hex():
+            self.__log.debug("Ignore empty frame: %s", modbus_resp_frame.hex())
+            return {}
         if modbus_resp_frame is None:
             return {}
         return self.__parse_modbus_read_holding_registers_response(modbus_resp_frame, first_reg, last_reg)
2024-08-31 04:45:50,980 - DeyeModbus - DEBUG - Ignore empty frame: 0103720000000000001292000000000000000000001292000000000000094200000000000000000000138800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000400000000000000000000012a00000000000000000000000000001517
2024-08-31 04:46:51,252 - DeyeModbus - DEBUG - Ignore empty frame: 0103720000000000001292000000000000000000001292000000000000094200000000000000000000138800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000400000000000000000000012a00000000000000000000000000001517

and in combination with a Utility Meter:

utility_meter:
  energy:
    name: "Production today (daily reset)"
    source: sensor.deye_inverter_mqtt_production_today
    cycle: daily

Home Assistent generates diagrams without any outliers in the morning or in the afternoon:

image

kbialek commented 2 months ago

As there is no consensus about the best strategy here, my proposal is to implement them one-by-one, as needed, so the end-user can choose the one that suits him best. Yours will be added first @CarstenGrohmann

kosl commented 2 months ago

Let me note that I am experiencing similar sporadic "spikes" readings from Deye SUN12k SG04LP3 in my fork, where I observe regular +ok=... response with valid CRC. I do not use block reads but single parameter and the reads are not zero but usually close to. I thought that some delay (1 second) between AT+INVDATA=... send and +ok=... recv would solve the problem of getting correct value(s) to the logger. So, there is some bug in the firmware that deyecloud.com is resolving somewhat better that us with AT+ protocol and I am looking for a root cause of such behaviour.

Bhoft commented 2 months ago

@CarstenGrohmann Hi can you add the HA sensor settings of this sensor?

sensor.deye_inverter_mqtt_production_today

I have trouble with my daily sensor values which my small inverter see https://github.com/kbialek/deye-inverter-mqtt/issues/197

CarstenGrohmann commented 2 months ago

I have no special/manual settings for the sensor.deye_inverter_mqtt_production_today sensor as I use my plugin Deye MQTT HA Plugin to announce the MQTT values to HA. In addition, I use several UtilityMeter sensor is used to reset most values at midnight.

Bhoft commented 2 months ago

Hi Carsten I saw that you use a Utility Meter for the daily sensor. But i guess that doesn't solve my issue that my inverter sends it's last known value (before it got offline) for day_energy or your production_today via mqtt when it goes back online, He resets to 0 when the time is set, but sadly he first sends sensor data via mqqt before that.

I just installed your plugin, but that wouldn't change the issue as it only changes the mqtt topics and auto creates the mqtt sensors (which i have done manually before). Nevertheless a plugin to automatically create the sensors is a great benefit.

But as i said an additional utility meter wouldn't change a thing if the sensor which is used has wrong values. But I will see this tomorrow when the inverter comes back online. I also have to say that we all might have different logger firmware versions. Sadly mine has auto updated to MW3_SSL_5408_1.0B so i can't use the AT Commands any more and have to use the tcp mode. Which might also cause the issue, but i can't downgrade.

The sensor has wrong values from 0:00 - 7:20 which would be then used for the utility meter as well. (image of my day_energy sensor) grafik

Btw do you plan to enable the active_power_regulation via mqtt as well? Btw2 why are you using state_class:total and not total_increasing for your total / daily sensors?

@CarstenGrohmann in this forum post they mentioned exactly your issue from your first post and there they had changed the state_class of the mqqt sensor from total to total_increasing as i also asked in my post why you use total. https://www.photovoltaikforum.com/thread/226131-deye-sun-m80-g4-eu-erfahrungen/?postID=3761075#post3761075

kbialek commented 2 months ago

@Bhoft My microinverters behave in the same way. I will think how to solve this in a systemic way. image

Bhoft commented 2 months ago

@kbialek good that i am not the only one πŸ‘ I just checked your code and if you aggregrate over multiple inverters you are already checking if now isn't the last aggregation date. https://github.com/kbialek/deye-inverter-mqtt/blob/8a56a28eee905bff2e3b5e0cf9d54b80db76df88/src/deye_multi_inverter_data_aggregator.py#L43-L46

Maybe something like this would also work for single inverter usage?

CarstenGrohmann commented 2 months ago

But as i said an additional utility meter wouldn't change a thing if the sensor which is used has wrong values.

The utility meter cannot change the values of the origin sensor. The utility meter creates a new sensor with changed values and you can use the new sensor instead of the original sensor.

image

From my perspective the utility meter is a feasible workaround.

CarstenGrohmann commented 2 months ago

Btw do you plan to enable the active_power_regulation via mqtt as well?

Yes, I'll do after I added support for another set of topics.

kosl commented 2 months ago

With 3 Utility meters (battery and production) I have been able to correctly restart the sensors at midnight for the Energy card.

Further, I needed to add several sensor templates to correctly recompute for Sunsynk-Power-Flow-Card

image

where some missing sensors (e.g. frequency) are taken from another inverter (Solaredge).

Btw, I would love to see R/W registers such as peak shaving (191), limit_control (142), (off) grid state, battery limits, ... to be implemented for automated (timed) control of the inverter such as https://github.com/klatremis/esphome-for-deye is!

Bhoft commented 2 months ago

@CarstenGrohmann

But as i said an additional utility meter wouldn't change a thing if the sensor which is used has wrong values.

The utility meter cannot change the values of the origin sensor. The utility meter creates a new sensor with changed values and you can use the new sensor instead of the original sensor. From my perspective the utility meter is a feasible workaround.

What I meant was if your original sensor sends wrong values in the morning when the inverter comes online the utility sensor will also use these wrong values. But it`s strange that your chart of your utility sensor doesn't show wrong values. Does your daily sensor have wrong values as posts of kbialek and me are showing?

kbialek commented 2 months ago

hi!

I'm currently testing this beta image ghcr.io/kbialek/deye-inverter-mqtt:2024.09.1-beta-2 It contains these PRs

I encourage you to give it try

@CarstenGrohmann You will need to add DEYE_DATA_FILTERS=ignore_zeroed_frames to the config to activate this functionality

CarstenGrohmann commented 2 months ago

Thank you for providing this feature. I've updated the my docker container and share the results during the next days.

What do you think about adding an initial status message like:

DeyeProcessorFactory - INFO - Feature "ignore_zeroed_frames": enabled
Bhoft commented 2 months ago

I'm currently testing this beta image ghcr.io/kbialek/deye-inverter-mqtt:2024.09.1-beta-2 It contains these PRs

I have installed the beta version yesterday and have an error in the log (multiple times) but thats now an issue with the Plugin from Carsten with this beta. As now no sensors information is sent to Homeassistent besides application_status and logger_status. So the autocreation of sensors via plugin currently isn't working as the plugin needs some code changes. @CarstenGrohmann

2024-09-13 05:59:04,549 - DeyeDaemon - ERROR - Unexpected error during runner execution
Traceback (most recent call last):
  File "/opt/deye_inverter_mqtt/deye_daemon.py", line 53, in __invoke_action
    self.__action()
  File "/opt/deye_inverter_mqtt/deye_inverter_state.py", line 60, in read_from_logger
    processor.process(events)
  File "/opt/deye_inverter_mqtt/plugins/deye_plugin_ha_discovery.py", line 237, in process
    self.publish_sensor_information(topic, event.observation)
  File "/opt/deye_inverter_mqtt/plugins/deye_plugin_ha_discovery.py", line 167, in publish_sensor_information
    "unit_of_measurement": observation.sensor.unit,
AttributeError: 'DailyResetSensor' object has no attribute 'unit'

@kbialek Besides that the day energy value is now 0 when the inverter comes online and the first value send is now correct. πŸ‘

2024-09-13 05:10:04,354 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/day_energy', value: '0.0'

Same for the PV1-PVx values

2024-09-13 05:10:04,407 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/day_energy', value: '0.0'

Sadly Home Assistant still have the issue with the statistics it saves an value 5 minutes before the mqqt publish changed the value to 0. Just for information the timestamp in the portainer log doesn't have the correct Timezone of Format so 5:10 is 7:10. grafik grafik

Home assistant really saves periodically the current value in the statistics even if no new value is received via MQTT. So through the whole night when the inverter is offline the value isn't changed but saved in the logs.

I guess with "expire_after": 300, to the mqtt sensor this would be possible to solve. Which i now have added to my manually created mqqt sensors. I will write something tomorrow if that helped.

CarstenGrohmann commented 2 months ago

The AttributeError exception is raised from my code. It looks like the unit attribute is missing from DailyResetSensor even if the class is derived from Sensor class.

2024-09-13 11:08:31,622 - DeyeDaemon - ERROR - Unexpected error during runner execution
Traceback (most recent call last):
  File "/opt/deye_inverter_mqtt/deye_daemon.py", line 53, in __invoke_action
    self.__action()
  File "/opt/deye_inverter_mqtt/deye_inverter_state.py", line 60, in read_from_logger
    processor.process(events)
  File "/opt/deye_inverter_mqtt/plugins/deye_plugin_ha_discovery.py", line 320, in process
    self.publish_sensor_information(topic, event.observation)
  File "/opt/deye_inverter_mqtt/plugins/deye_plugin_ha_discovery.py", line 242, in publish_sensor_information
    "unit_of_measurement": observation.sensor.unit,
AttributeError: 'DailyResetSensor' object has no attribute 'unit'

@kbialek: What do you think about this issue?

kbialek commented 2 months ago

A new beta image 2024.09.1-beta-3 is there

  1. I fixed the error reported by @CarstenGrohmann I was actually expecting some errors to appear. The first implementation was quite dirty.
  2. I've added a log message DeyeDaemon - INFO - Active data filters: ignore_zeroed_frames
CarstenGrohmann commented 2 months ago

I've updated my docker image and published a development branch with new metric and total_increasing state class for day_energy in https://github.com/CarstenGrohmann/deye-mqtt-ha-plugin/tree/more_inverters.

Today it was raining. I'll monitor all changes during the days next week with more sun.

Thank you for this fast update.

Bhoft commented 2 months ago

A new beta image 2024.09.1-beta-3 is there

I have installed that beta and have these results:

Issue with total values:

These are the Log lines when my micro inverter came online today the total values are 0 for the first 3 MQTT publishes.

2024-09-14 05:13:50,598 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:14:48,080 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:16:48,082 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:17:48,160 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '201.3'

Same for other total values like PV1 Total energy

2024-09-14 05:13:50,647 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:14:48,105 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:16:48,103 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:17:48,202 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '44.4'

Which results in a wrong value grafik

which was btw already the case in the first beta. I just didn't saw it but can see it in the statistics

Test with expire after

Besides that i have done a test with expire_after. With a mqtt sensor like the following I don't get "wrong" statistics saved in the inverter downtime

  - name: "BKW Tages Produktion"
    unique_id: "bkw_energy_day"
    object_id: "bkw_energy_day"
    state_topic: "deye/day_energy"
    value_template: "{{ value | round(1) }}"
    unit_of_measurement: "kWh"
    state_class: "total_increasing"
    device_class: "energy"
    expire_after: 300
    availability:
      - topic: "deye/logger_status"

grafik

But on the downside i also get any values when the inverter is not reachable e.g. i have some wlan range issues from time to time when the inverter switches to the wrong repeater in my mesh. You then get also no values displayed in the night. Which is of course bad if you look at your dashboard to check your daily production and you don't see anything. This could be of course solved if retain:true is added to the MQTT Publish (would require additional changes to the code)

As counterexample the sensor which is created via Carstens plugin without expire_after grafik

Tests with additional ultimiy_meter sensor in HA

What I can also say is that an additional utility_meter (which is reseted daily) really don't use the values during the night if there is no change. So with an additional ultimity meter like below you get indead get a cleaned daily value as Carsten already mentioned. πŸ‘

bkw_energy_produced_daily_test:
  source: sensor.deye_inverter_mqtt_production_today
  name: "BKW Daily kWh Produced"
  cycle: daily
  unique_id: bkw_daily_kwh_produced_test

grafik

For me it makes not really sense as according to the logs and database there are statistics saved but i am fine with this workaround :) It would make sense if ultility_meter only updates his value when there is a change but then there shoudn't be values saved betwen 19:00 and 0:00 which clearly are.

But it is what it is, thats a good way to clean up the daily values.

kbialek commented 2 months ago

Issue with total values:

These are the Log lines when my micro inverter came online today the total values are 0 for the first 3 MQTT publishes.

2024-09-14 05:13:50,598 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:14:48,080 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:16:48,082 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '0.0'
2024-09-14 05:17:48,160 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '201.3'

Same for other total values like PV1 Total energy

2024-09-14 05:13:50,647 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:14:48,105 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:16:48,103 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-14 05:17:48,202 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '44.4'

@Bhoft I do not think that this behavior is caused by the changes I added in the beta image. I belive that what you see is caused by zeroed frames returned by the logger "just" right after it has powered on in the morning. You may try to add DEYE_DATA_FILTERS=ignore_zeroed_frames config variable to mitigate this.

Bhoft commented 2 months ago

@Bhoft I do not think that this behavior is caused by the changes I added in the beta image. I belive that what you see is caused by zeroed frames returned by the logger "just" right after it has powered on in the morning. You may try to add DEYE_DATA_FILTERS=ignore_zeroed_frames config variable to mitigate this.

You are right i just extended the history in my statistics and it also occur way before the beta. I just didn`t saw this because the default range on the history was only the last 2 days and i didn't checked before that time range. I have just added the settings and check again tomorrow morning.

Bhoft commented 2 months ago

I have added the ignore_zeroed_frames filter yesterday but still got the Zero value publishes for total values this morning

relevant log entries

2024-09-14 13:22:33,170 - DeyeDaemon - INFO - Active data filters: ignore_zeroed_frames
2024-09-15 05:10:45,896 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-15 05:11:45,738 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-15 05:12:45,747 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '0.0'
2024-09-15 05:14:45,734 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/dc/pv1/total_energy', value: '45.4'

and register values at that times

2024-09-15 05:10:45,447 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-15 05:10:45,455 - DeyeTcpConnector - INFO - Re-connected to socket on IP 192.168.5.149
2024-09-15 05:10:45,456 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-15 05:10:45,632 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150003067c63e50201c6e6b52e2f00000090853038010372000000000000000000000000000000000000000000000000000008ca0000000000000000000000000000000000000000000000000000000000000000000008ff08f3138400000000000000000000000002920002001d000000000000000000000000000000000000000000000000000000004e27be15
2024-09-15 05:10:45,632 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-15 05:10:45,637 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-15 05:10:45,821 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150004067c63e50201c6e6b52e30000000908530380103020064b9af1915

2024-09-15 05:11:45,447 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-15 05:11:45,452 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-15 05:11:45,637 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000d067c63e5020102e7b52e6b0000008f853038010372000000000000000000000000000000000000000000000000000008d400000000000000000000000000000000000000000000000000000000000000000000090108f5138100000000000000000000000002920002001d00000000000000000000000000000000000000000000000000000000de883d15
2024-09-15 05:11:45,637 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-15 05:11:45,643 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-15 05:11:45,707 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015000e067c63e5020102e7b52e6c0000008f8530380103020064b9af9b15

2024-09-15 05:12:45,447 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-15 05:12:45,453 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-15 05:12:45,635 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a585001015000f067c63e502013ee7b52ea70000008f853038010372000000000000000000000000000000000000000000000000000008ca00000000000000000000000000000000000000000000000000000000000000000000090308f7138600000000000000000000000002920002001d00000000000000000000000000000000000000000000000000000000d8f41c15
2024-09-15 05:12:45,635 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-15 05:12:45,639 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-15 05:12:45,695 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150010067c63e502013ee7b52ea80000008f8530380103020064b9af1515

2024-09-15 05:13:45,447 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-15 05:13:45,452 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-15 05:13:45,635 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150012067c63e5020179e7b52ee30000008f853038010372000000000000000000000000000000000000000000000000000008ca00000000000000000000000000000000000000000000000000000000000000000000090108f5138200000000000000000000000002920002001d000000000000000000000000000000000000000000000000000000008a045015
2024-09-15 05:13:45,635 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-15 05:13:45,640 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-15 05:13:46,007 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150013067c63e502017ae7b52ee40000008f8530380103020064b9af9015

2024-09-15 05:14:45,448 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-15 05:14:45,452 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-15 05:14:45,631 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150014067c63e50201b5e7b52e1f0100008f85303801037200000000000008020000000000000000000001c6000001ac000008ca025c0000000001dc0000138800000000000000000000000000000000000000000000090308f7138400000000000000000000000002920002001d000000000000000000000000013f0000013e0000013f0000013f000035915c15
2024-09-15 05:14:45,631 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-15 05:14:45,637 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-15 05:14:45,700 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150015067c63e50201b6e7b52e200100008f8530380103020064b9af0b15

"Ignoring zeroed frame" wasn't found in the log files, so i guess the skipping doesn't work in my case?

What i found strange is that i don't see it today in the popup statistics (where it was visible yesterday) grafik

but in the detailed statistics grafik

but i guess it has something to do with the resolution of the timeline or some usage of function like mean. I just mentioning this because it seems you can't rely on the display of the statistics in the popup.

kbialek commented 2 months ago

@CarstenGrohmann @Bhoft I've built a new beta image 2024.09.1-beta-4

  1. I decided to remove https://github.com/kbialek/deye-inverter-mqtt/pull/198 - it's based on a heuristic which does not work reliably.
  2. Added https://github.com/kbialek/deye-inverter-mqtt/pull/200 - values will be published only when total energy sensor value is higher than zero
  3. I kept https://github.com/kbialek/deye-inverter-mqtt/pull/199
CarstenGrohmann commented 2 months ago

I've updated the docker image to beta-4. The last version beta-3 runs without any anormalities:

2024-09-16 16:20:38,398 - DeyeModbus - DEBUG - Ignoring zeroed frame: 01037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab
2024-09-16 16:24:39,445 - DeyeModbus - DEBUG - Ignoring zeroed frame: 01037200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000078ab
kbialek commented 2 months ago

@CarstenGrohmann Maybe I should explain it a bit more. Modbus responses shared by @Bhoft contain mostly zeros, but not only zeros, thus zeroed frames ignoring does not work for him. This convinced me that ignoring zeroed frames is only an unreliable weak heuristic. That's why I decided to replace it with "data readiness check". The service will publish the values to MQTT only when "data readiness check" is successful. Now what "data readiness check" actually is? It simply checks if "Production Total" value is greater than zero. This check should work for all inverters I belive.

I'm testing beta-4 now. I see that probably I did there something wrong. I will come back to you.

EDIT: I see that data readiness check can be improved a bit, but in overall it works as expected

Bhoft commented 2 months ago

Hi i have tested the beta-4 now for two days and can say that the Data readiness check seems to work. I have no publishes for the deye/total_energy in the mornings with Zero.

e.g. first connect this morning and its publishes

2024-09-18 05:16:21,099 - DeyeTcpConnector - INFO - Re-connected to socket on IP 192.168.5.149
2024-09-18 05:16:21,099 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-18 05:16:21,311 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150005067c63e50201fbddb72e360100002a843238010372000d00000000084a0000000200020003000201d7000001b9000008de02700000000001eb0000138800000000000000000000000000000000000000000000091409081380000000000000000000000000028f0002001d001000000000000000000000012d0000012e0000012d0000012e00005768d115
2024-09-18 05:16:21,311 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-18 05:16:21,321 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-18 05:16:21,382 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150006067c63e50201fbddb72e360100002a8432380103020064b9afeb15

2024-09-18 05:16:21,386 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-18 05:16:21.382964:212.20000000000002]
2024-09-18 05:16:21,386 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-09-18 05:16:21,387 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/logger_status', value: 'online'
2024-09-18 05:16:21,392 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/day_energy', value: '1.3'
2024-09-18 05:16:21,398 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '212.2'

So everthing is fine πŸ‘

The only strange thing is that the debug message of the readiness check is always true, so even when offline

2024-09-18 05:14:27,235 - DeyeTcpConnector - DEBUG - Could not open socket on IP 192.168.5.149: [Errno 113] Host is unreachable
2024-09-18 05:14:27,236 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-09-18 05:14:27,236 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-09-18 05:14:27,236 - DeyeInverterState - DEBUG - No observation events received (offline)

I couldn't find a single line in my logs with Data readiness check result: False or Data readiness observations: [total_energy@timestamp:0]

What i also find a bit strange is I find many entries in the log with 0000000000002.

...
Data readiness observations: [total_energy@2024-09-17 14:50:21.082968:212.0]
Data readiness observations: [total_energy@2024-09-17 14:51:21.089482:212.0]
Data readiness observations: [total_energy@2024-09-17 14:52:21.079735:212.10000000000002]
Data readiness observations: [total_energy@2024-09-17 14:53:21.086853:212.10000000000002]
....100 of times
Data readiness observations: [total_energy@2024-09-18 05:49:21.348573:212.20000000000002]
Data readiness observations: [total_energy@2024-09-18 05:50:21.348877:212.20000000000002]
Data readiness observations: [total_energy@2024-09-18 05:51:21.350037:212.3]
Data readiness observations: [total_energy@2024-09-18 05:52:21.354751:212.3]
Data readiness observations: [total_energy@2024-09-18 05:53:21.351361:212.3]

also for other numbers
Data readiness observations: [total_energy@2024-09-18 07:23:21.379221:212.5]
Data readiness observations: [total_energy@2024-09-18 07:24:21.377085:212.5]
Data readiness observations: [total_energy@2024-09-18 07:25:21.687514:212.60000000000002]
Data readiness observations: [total_energy@2024-09-18 07:53:21.396904:212.70000000000002]
.. also multiple times
Data readiness observations: [total_energy@2024-09-18 07:54:21.431255:212.70000000000002]
Data readiness observations: [total_energy@2024-09-18 07:55:21.384730:212.8]
Data readiness observations: [total_energy@2024-09-18 07:56:21.436309:212.8]

The 0000000000002 seems a bit strange in my opinion. There are multiple entries and its always ends with 0000000000002. For me it looks like something isn't read correctly from the registers?

Reading before where no 0000000000002 is added

2024-09-18 07:24:21,122 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-18 07:24:21,127 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-18 07:24:21,305 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150027067c63e502017bfbb72eab020000aa843238010372000200000000084d0000000000000000000101d8000001b9000008e802700000000e01ed000013880000000000000000000000000cc20000000000000dac091e090f1382000000000000000000000000028f0002001d00000000000000000000000001b4000a01c900080164000801ac00351ccb6a15
2024-09-18 07:24:21,305 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-18 07:24:21,313 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-18 07:24:21,376 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150028067c63e502017bfbb72eab020000aa8432380103020064b9afa115
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Production today: 0.2
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Production Total: 212.5
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Phase1 Voltage: 228.0
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Phase1 Current: 1.4
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Phase1 Power: 319.2
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - AC Freq: 50.0
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - PV1 Voltage: 43.6
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - PV1 Current: 1.0
2024-09-18 07:24:21,377 - DeyeInverterState - DEBUG - PV1 Power: 43.6
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV1 Production today: 0.0
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV1 Total: 47.2
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV2 Voltage: 45.7
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV2 Current: 0.8
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV2 Power: 36.6
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV2 Total: 44.1
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV3 Voltage: 35.6
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV3 Current: 0.8
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV3 Power: 28.5
2024-09-18 07:24:21,378 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV3 Total: 62.4
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV4 Voltage: 42.8
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV4 Current: 5.3
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV4 Power: 226.8
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV4 Production today: 0.1
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - PV4 Total: 49.3
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - DC Total Power: 335.5
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - AC Active Power: 326.6
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - Radiator temperature: 25.0
2024-09-18 07:24:21,379 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-09-18 07:24:21,380 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-18 07:24:21.377085:212.5]
2024-09-18 07:24:21,380 - DeyeInverterState - DEBUG - Data readiness check result: True

next reading with 0000000000002

024-09-18 07:25:21,123 - DeyeInverterState - INFO - Reading start
2024-09-18 07:25:21,123 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-09-18 07:25:21,132 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e50200000000000000000000000000000103003c003945d4ca15
2024-09-18 07:25:21,317 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5850010150029067c63e50201b7fbb72ee7020000aa843238010372000300000000084e0000000000000000000101d8000001b9000008e802700000000f01ed000013880000000000000000000000000d640000000000000d70091e090d1381000000000000000000000000028f0002001d00000000000000000000000001aa000b01cf00090164000801ae003772320a15
2024-09-18 07:25:21,318 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings_micro', 'settings'}, range: 0028-0028]
2024-09-18 07:25:21,329 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000067c63e502000000000000000000000000000001030028000104026b15
2024-09-18 07:25:21,687 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a515001015002a067c63e50201b7fbb72ee7020000aa8432380103020064b9af1b15
2024-09-18 07:25:21,687 - DeyeInverterState - DEBUG - Production today: 0.3
2024-09-18 07:25:21,687 - DeyeInverterState - DEBUG - Production Total: 212.6
2024-09-18 07:25:21,687 - DeyeInverterState - DEBUG - Phase1 Voltage: 228.0
2024-09-18 07:25:21,687 - DeyeInverterState - DEBUG - Phase1 Current: 1.5
2024-09-18 07:25:21,687 - DeyeInverterState - DEBUG - Phase1 Power: 342.0
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - AC Freq: 50.0
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - Uptime: 0.0
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV1 Voltage: 42.6
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV1 Current: 1.1
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV1 Power: 46.9
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV1 Production today: 0.0
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV1 Total: 47.2
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV2 Voltage: 46.3
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV2 Current: 0.9
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV2 Power: 41.7
2024-09-18 07:25:21,688 - DeyeInverterState - DEBUG - PV2 Production today: 0.0
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV2 Total: 44.1
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV3 Voltage: 35.6
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV3 Current: 0.8
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV3 Power: 28.5
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV3 Production today: 0.0
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV3 Total: 62.4
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV4 Voltage: 43.0
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV4 Current: 5.5
2024-09-18 07:25:21,689 - DeyeInverterState - DEBUG - PV4 Power: 236.5
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - PV4 Production today: 0.1
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - PV4 Total: 49.3
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - DC Total Power: 353.5
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - Operating Power: 0.0
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - AC Active Power: 342.8
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - Radiator temperature: 24.4
2024-09-18 07:25:21,690 - DeyeInverterState - DEBUG - Active power regulation: 100.0
2024-09-18 07:25:21,691 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-18 07:25:21.687514:212.60000000000002]
2024-09-18 07:25:21,691 - DeyeInverterState - DEBUG - Data readiness check result: True

It's still published as 212.6

2024-09-18 07:25:21,700 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/total_energy', value: '212.6'
kbialek commented 2 months ago

@Bhoft

I couldn't find a single line in my logs with Data readiness check result: False

Interesting. Please watch it for few more days.

The 0000000000002 seems a bit strange in my opinion. There are multiple entries and its always ends with 0000000000002. For me it looks like something isn't read correctly from the registers?

This is how floating point number encoding manifests. It's not an issue. You can ignore it.

Bhoft commented 2 months ago

@kbialek

I couldn't find a single line in my logs with Data readiness check result: False

Interesting. Please watch it for few more days.

Checked again this morning and there were 4 readiness checks with false and 0.0.

2024-09-19 05:11:27,652 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-09-19 05:11:27,652 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-09-19 05:12:21,749 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-19 05:12:21.746710:0.0]
2024-09-19 05:12:21,780 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-19 05:13:21,750 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-19 05:13:21.746222:0.0]
2024-09-19 05:13:21,750 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-19 05:14:21,752 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-19 05:14:21.749380:0.0]
2024-09-19 05:14:21,752 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-19 05:15:22,554 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-19 05:15:22.549701:0.0]
2024-09-19 05:15:22,554 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-19 05:16:21,771 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-19 05:16:21.763551:216.9]
2024-09-19 05:16:21,771 - DeyeInverterState - DEBUG - Data readiness check result: True

I checked again older logs and the check with false did occur on the 17th as well (also 4 times).

2024-09-17 05:19:13,757 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-09-17 05:20:13,650 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-17 05:20:13.647024:0.0]
2024-09-17 05:20:13,650 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-17 05:21:13,661 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-17 05:21:13.658232:0.0]
2024-09-17 05:21:13,661 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-17 05:22:13,626 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-17 05:22:13.623930:0.0]
2024-09-17 05:22:13,626 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-17 05:23:13,733 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-17 05:23:13.729732:0.0]
2024-09-17 05:23:13,733 - DeyeInverterState - DEBUG - Data readiness check result: False
2024-09-17 05:24:13,631 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-17 05:24:13.628597:210.9]
2024-09-17 05:24:13,631 - DeyeInverterState - DEBUG - Data readiness check result: True

I have no idea why this didn't occure yesterday on the 18th.

The only thing i see that the first true total energy reading has these 0000000000002

2024-09-18 05:15:27,268 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-09-18 05:15:27,269 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-09-18 05:16:21,386 - DeyeInverterState - DEBUG - Data readiness observations: [total_energy@2024-09-18 05:16:21.382964:212.20000000000002]
2024-09-18 05:16:21,386 - DeyeInverterState - DEBUG - Data readiness check result: True
kbialek commented 2 months ago

Checked again this morning and there were 4 readiness checks with false and 0.0.

Thanks for the feedback @Bhoft This means that the solution works as expected.

I have no idea why this didn't occure yesterday on the 18th.

I suppose, that it's caused by a timing issue in the inverter's firmware. Probably the memory locations that are read over Modbus are being initialized after some delay. Now, it depends when we query the values. We do that either before or after the initialization. If we do before, then we get zeros. If we do after then we get the expected values.

Having said that, I'm getting confident that the new version can be released. What about you @CarstenGrohmann . Did you have a chance to test beta-4?

EDIT:

Also, let me explain why empty data-readiness observation list evaluates to True. I made it this way to keep metric groups other than micro working as before. Only micro metrics group has data-readiness check configured.

CarstenGrohmann commented 2 months ago

I activated beta-4 a few hours after you released it. I see the same true and false behavior as reported by @Bhoft. My Docker logs do not contain any errors.

I am doing fine with the current changes. My data in HA looks good.

Please feel free to publish the changes.

BTW: Did you have a chance to read my comment in https://github.com/kbialek/deye-inverter-mqtt/pull/200#pullrequestreview-2310667825?