Geladene kWh / kWh der Session fehlerhaft #9884

allcoolusernamesaregone · 2023-09-14T19:37:54Z

Describe the bug

Eingesetzte Version: Master vom 9.9., 19:30.

Ladevorgang heute morgen, lt. Wallbox Easee bei Zählerstand 2329,271.

[lp-1  ] DEBUG 2023/09/14 09:39:09 charge total import: 2329.271kWh
[db    ] TRACE 2023/09/14 09:39:09 INSERT INTO `sessions` (`created`,`finished`,`loadpoint`,`identifier`,`vehicle`,`odometer`,`meter_start_kwh`,`meter_end_kwh`,`charged_kwh`,`charge_duration`,`solar_percentage`,`price`,`price_per_kwh`,`co2_per_kwh`) VALUES ("2023-09-14 09:39:09.968","0000-00-00 00:00:00","Wallbox","","",NULL,2329.270976,NULL,0.000000,NULL,NULL,NULL,NULL,NULL) RETURNING `id` 1 <nil>

[lp-1  ] DEBUG 2023/09/14 11:44:12 charge total import: 2337.614kWh
[db    ] TRACE 2023/09/14 11:44:12 UPDATE `sessions` SET `created`="2023-09-14 09:39:09.968",`finished`="2023-09-14 11:44:12.412",`loadpoint`="Wallbox",`identifier`="",`vehicle`="e-Golf",`odometer`=41800.000000,`meter_start_kwh`=2329.270976,`meter_end_kwh`=2337.614221,`charged_kwh`=13.283007,`charge_duration`="2h5m2s",`solar_percentage`=100.000000,`price`=0.000000,`price_per_kwh`=0.000000,`co2_per_kwh`=NULL WHERE `id` = 99 1 <nil>

Ladeende, Zählerstand lt. Easee 2337,614. Differenz 8,34 kwh. In die Session wird 13,28 geschrieben.
Beim Ladestart glaube ich mich auch zu erinnern gesehen zu haben, dass der Ladevorgang schon direkt nach dem Start mit 5,x kWh angegeben war in der UI. Ob 13,x oder 8,x geladen, das fällt ja nicht mal so sehr auf.

Aber stutzig wurde ich eben, da In der Statistik 2x die gleiche Menge erscheint - und die Ladedauer für 13 kWh am Nachmittag viel zu kurz war.

Ladevorgang anderes KFZ am Nachmittag, knapp 3 kWh geladen - wieder gute 13.

[lp-1  ] DEBUG 2023/09/14 16:27:03 charge total import: 2342.635kWh
[db    ] TRACE 2023/09/14 16:27:03 INSERT INTO `sessions` (`created`,`finished`,`loadpoint`,`identifier`,`vehicle`,`odometer`,`meter_start_kwh`,`meter_end_kwh`,`charged_kwh`,`charge_duration`,`solar_percentage`,`price`,`price_per_kwh`,`co2_per_kwh`) VALUES ("2023-09-14 16:27:03.048","0000-00-00 00:00:00","Wallbox","","",NULL,2342.634568,NULL,0.000000,NULL,NULL,NULL,NULL,NULL) RETURNING `id` 1 <nil>

[lp-1  ] DEBUG 2023/09/14 17:29:39 charge total import: 2345.336kWh
[db    ] TRACE 2023/09/14 17:29:39 UPDATE `sessions` SET `created`="2023-09-14 16:27:03.048",`finished`="2023-09-14 17:29:39.698",`loadpoint`="Wallbox",`identifier`="",`vehicle`="Dacia Spring",`odometer`=310.240000,`meter_start_kwh`=2342.634568,`meter_end_kwh`=2345.335522,`charged_kwh`=13.321114,`charge_duration`="59m30s",`solar_percentage`=100.000000,`price`=0.000000,`price_per_kwh`=0.000000,`co2_per_kwh`=NULL WHERE `id` = 100 1 <nil>

Steps to reproduce

Leider nicht bekannt

Configuration details

Ergänze ich gerne falls nötig

Log details

s.o.

What type of operating system are you running?

Linux

Version

Master 9.9. 19:30

The text was updated successfully, but these errors were encountered:

andig · 2023-09-14T20:06:57Z

Die Zählerwerte werden offensichtlich richtig übernommen. Es fehlt der Sessionwert im Logfile um das zu beurteilen. Oder das Ladelog der Easee. Vmtl. schickt die Easee einfach den falschen Wert und dann müsste man würfeln um festzustellen welcher jetzt wohl stimmen könnte. Wie sollte evcc das auflösen?

allcoolusernamesaregone · 2023-09-14T20:45:37Z

Das hier?

Das sind alle Session Updates der Easee während des 2. Ladevorgangs.

[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
[easee ] TRACE 2023/09/14 16:31:24 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
[easee ] TRACE 2023/09/14 16:33:11 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
[easee ] TRACE 2023/09/14 16:36:11 ProductUpdate Easee: (2023-09-14 14:36:10 +0000 UTC) SESSION_ENERGY 1.0028105974197388
[easee ] TRACE 2023/09/14 16:48:53 ProductUpdate Easee: (2023-09-14 14:36:10 +0000 UTC) SESSION_ENERGY 1.0028105974197388
[easee ] TRACE 2023/09/14 16:56:11 ProductUpdate Easee: (2023-09-14 14:56:10 +0000 UTC) SESSION_ENERGY 2.465672731399536
[easee ] TRACE 2023/09/14 16:58:36 ProductUpdate Easee: (2023-09-14 14:56:10 +0000 UTC) SESSION_ENERGY 2.465672731399536
[easee ] TRACE 2023/09/14 17:05:14 ProductUpdate Easee: (2023-09-14 14:56:10 +0000 UTC) SESSION_ENERGY 2.465672731399536
[easee ] TRACE 2023/09/14 17:10:02 ProductUpdate Easee: (2023-09-14 15:10:00 +0000 UTC) SESSION_ENERGY 3.559372663497925
[easee ] TRACE 2023/09/14 17:16:11 ProductUpdate Easee: (2023-09-14 15:10:00 +0000 UTC) SESSION_ENERGY 3.559372663497925
[easee ] TRACE 2023/09/14 17:29:52 ProductUpdate Easee: (2023-09-14 15:29:50 +0000 UTC) SESSION_ENERGY 5.0153398513793945
[easee ] TRACE 2023/09/14 17:29:52 ProductUpdate Easee: (2023-09-14 15:29:50 +0000 UTC) SESSION_ENERGY 5.0153398513793945

Und in der Tat erscheint dort am Anfang die falschen 13,3 kWh. Und zwar immer nach einem neuen SignalR Verbindungsaufbau, z.B.

[easee ] TRACE 2023/09/14 16:27:15 ProductUpdate Easee: (2023-09-14 14:27:14 +0000 UTC) IN_CURRENT_T3 22.847000122070312
[easee ] TRACE 2023/09/14 16:27:15 ProductUpdate Easee: (2023-09-14 14:27:14 +0000 UTC) TOTAL_POWER 5.073999881744385
[easee ] TRACE 2023/09/14 16:27:16 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 16:27:16 {"negotiateVersion":0,"connectionId":"","availableTransports":[{"transport":"WebSockets","transferFormats":["Text","Binary"]},{"transport":"ServerSentEvents","transferFormats":["Text"]},{"transport":"LongPolling","transferFormats":["Text","Binary"]}]}
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 07:16:36 +0000 UTC) SMART_CHARGING true
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-08-16 09:10:04 +0000 UTC) CABLE_LOCKED true
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 14:26:57 +0000 UTC) CHARGER_OP_MODE 3
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 14:27:08 +0000 UTC) TOTAL_POWER 3.427000045776367
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 14:00:00 +0000 UTC) ENERGY_PER_HOUR 0

Da ist wohl die Easee Api schuld, die liefert total veraltete Daten nach einem Neuaufbau.
Wobei
a) warum diese neuen Verbindung zu https://streams.easee.com/hubs/chargers/negotiate (s.u.)
b) es "gewinnt" nicht der neueste/letzte Session Wert von ca. 5 kWh, sondern offenbar der höchste in der Sitzung..

Während der Sitzung erfolgte wiederholt eine neue SignalR Verbindung

[easee ] TRACE 2023/09/14 16:27:16 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 16:31:23 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 16:33:10 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 16:48:52 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 16:58:35 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 17:05:13 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/14 17:16:10 POST https://streams.easee.com/hubs/chargers/negotiate

Lt. Easee App hatten die Ladevorgänge heute 13,3 kWh (1. also korrekt in EVCC) und 5 kWh (nicht korrekt in EVCC).

So oder so, wenn man die Werte von meter_start_kwh,meter_end_kwh,charged_kwh sieht, diese sind ja nicht konsistent.
Entweder müsste man start + end Angabe vertrauen, dann kann charged errechnet werden als Differenz.
Oder start nehmen charged addieren um end zu erhalten.
Beim zweiten Ladevorgang ist meter_end_kwh und charged_kwh falsch.

meter_end_kwh müsste der aktuelle Wert sein, da ist eine Verzögerung in der Easee Api, der richtige Endstand kam erst nach über 40 Minuten nach Ende des Ladevorgangs.

[easee ] TRACE 2023/09/14 18:09:30 ProductUpdate : (2023-09-14 16:00:00 +0000 UTC) ENERGY_PER_HOUR 2.3143856525421143
[easee ] TRACE 2023/09/14 18:09:30 ProductUpdate : (2023-09-14 16:00:00 +0000 UTC) LIFETIME_HOURS 13546
[easee ] TRACE 2023/09/14 18:09:30 ProductUpdate : (2023-09-14 16:00:00 +0000 UTC) LIFETIME_RELAY_SWITCHES 1792
[easee ] TRACE 2023/09/14 18:09:30 ProductUpdate : (2023-09-14 16:00:00 +0000 UTC) LIFETIME_ENERGY 2347.649907777777
[site  ] DEBUG 2023/09/14 18:09:33 ----
[lp-1  ] DEBUG 2023/09/14 18:09:33 charge power: 0W
[site  ] DEBUG 2023/09/14 18:09:33 pv power: 2530W
[site  ] DEBUG 2023/09/14 18:09:33 grid power: -2375W
[site  ] DEBUG 2023/09/14 18:09:33 grid powers: [-862 -751 -762]W
[site  ] DEBUG 2023/09/14 18:09:33 grid currents: [-3.88 -3.47 -3.47]A
[site  ] DEBUG 2023/09/14 18:09:33 site power: -2175W
[lp-1  ] DEBUG 2023/09/14 18:09:33 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/09/14 18:09:33 charge total import: 2347.650kWh

Daher wäre m.E.n. eine Korrektur wie folgt nötig:
charged_kwh müsste ca. 5 kwh sein lt. letztem ProductUpdate SESSION_ENERGY 5.0153398513793945.
Diese Wert wurde als letzter = neuester = richtiger Wert beim Abstecken des Fahrzeugs geliefert. Warum da die falschen 13,3 genommen werden kann ich mangels Kenntnis von Go und dem ganzen Code nicht direkt nachvollziehen.

Meter_start_kwh 2342,6 zzgl. diese 5 ergibt dann auch den aktuellen Stand von 2347,6..

Aber sowohl meter_start als auch meter_end werden mit ggf. veralteten Werten der Easee Updates gefüllt, damit da aber richtige und aktuelle Werte kommen, könnte man ein Update über
https://developer.easee.cloud/reference/post_api-chargers-id-commands-poll-lifetimeenergy
antriggern!?

andig · 2023-09-15T08:27:41Z

Mein Vorschlag wäre Ticket bei Easee. Die API-Daten sollten konsistent sein. Wir verwenden ja genau NICHT das Polling sondern Push via SignalR.

allcoolusernamesaregone · 2023-09-15T13:44:37Z

Ticket kann sicherlich nicht schaden, aber keine entspr. Stelle zum eröffnen gefunden (?).
Aber unabhängig davon, bis (und falls) das gefixt ist, ist das ja ein schon ein oder mehrere Bugs oder seltsames Verhalten in EVCC.

Das Pollen pollt auch nicht im eigentlichen Sinne, sondern löst nur ein kurzfristiges ProductUpdate mit aktuellen Daten aus, s.u.,.
Gepollt wird der Wert durch die Cloud bei der Easee selbst, und das Update der Daten dann per SignalR versendet.
Unten angehängtes Log war die Folge eines Aufrufs von https://api.easee.com/api/chargers/{id}/commands/poll_lifetimeenergy
In dem ProductUpdate steht dann der tatsächlich aktuelle Wert. Dass Easee diese API Funktionalität eingeführt hat, wird ja auch seinen Grund und Nutzen haben.

Ansonsten würden mehr oder weniger viele Korrekturen dass Problem lösen:

a) in EnergyMetrics, wenn der Wert von getChargedEnergy() aus Easee.go einen kleineren Wert liefert als zuvor, diesen kleineren übernehmen, statt auf dem alten / höheren und falschen zu verharren bzw. den neuen Wert als ungültig zu betrachten, nur weil er kleiner ist. Warum das so ist, und ob und welche Wallboxen kleinere Werte im Laufe einer Sitzung senden - k.A.
Aber falls dahinter die Idee einer Ladepause o.ä. ist (Unterbrechung, Wallbox XYZ startet den Zähler wieder bei 0) dann wäre dann wäre doch hier auch ein Fehler, dann hätte es in meinem Beispiel am Ende 13,3 PLUS 5,x als geladene Energie ergeben müssen (oder..?)

b) Ignorieren aller veralteten Productupdates
[easee ] TRACE 2023/09/14 16:27:16 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
Wenn man um 16:27 ein Update von 09:44 erhält, dann kann das ja nur veraltet sein. Daher könnte man doch den Wert nur dann übernehmen, wenn seit Start von EVCC kein anderer Wert vorliegt - eigentlich für alle Werte, die über Productupdates kommen. Solange null/nil/"" oder 0: übernehmen egal wie alt, ansonsten nur wenn z.B. < 5 Minuten.
Ja, da mag die blöde Easee Api schuld sein, aber damit bestmöglich umgehen muss halt der Nutzer ;)

c) bei Erkennen Fahrzeug an/abgesteckt, über die API ein Update von Lifetimeenergy auslösen, dann wären zumindest Start- und Endstand richtig(er).

SignalR Output des "Polls":

2023-09-15 15:01:08,920 - SignalRCoreClient - DEBUG - Message received{"type":1,"target":"ProductUpdate","arguments":[{"mid":"xxxx","dataType":3,"id":124,"timestamp":"2023-09-15T13:01:07Z","value":"2360.4966066666666"}]}
2023-09-15 15:01:08,921 - SignalRCoreClient - DEBUG - Raw message incomming:
2023-09-15 15:01:08,921 - SignalRCoreClient - DEBUG - {"type":1,"target":"ProductUpdate","arguments":[{"mid":"xxxx","dataType":3,"id":124,"timestamp":"2023-09-15T13:01:07Z","value":"2360.4966066666666"}]}
received product update: [{'mid': 'xxxx', 'dataType': 3, 'id': 124, 'timestamp': '2023-09-15T13:01:07Z', 'value': '2360.4966066666666'}]
2023-09-15 15:01:09,272 - SignalRCoreClient - DEBUG - Message received{"type":1,"target":"CommandResponse","arguments":[{"serialNumber":"xxxx","id":2,"timestamp":"2023-09-15T13:01:08.03719Z","deliveredAt":"2023-09-15T13:01:07.847Z","wasAccepted":true,"resultCode":null,"comment":null,"ticks":638303796680371900}]}

allcoolusernamesaregone · 2023-09-15T13:51:52Z

@GrimmiMeloni , was meinst Du zu b) ?
Warum da gestern so oft die SignalR Verbindung neu gemacht werden musste weiß ich nicht, aber die erhaltenen Daten nach Verbindungsaufbau sind ja erheblich veraltet.
Insb. SESSION_ENERGY ist wenn mehrere Stunden alt (bzw. wenn der Wert älter als die aktuelle Ladesession alt ist!) ja offensichtlich falsch, bzw. zwangsläufig der Wert der vorigen Ladesession.

16:27:16 POST https://streams.easee.com/hubs/chargers/negotiate
16:27:16 {"negotiateVersion":0,"connectionId":"","availableTransports":[{"transport":"WebSockets","transferFormats":["Text","Binary"]},{"transport":"ServerSentEvents","transferFormats":["Text"]},{"transport":"LongPolling","transferFormats":["Text","Binary"]}]}
16:27:16 ProductUpdate Easee: (2023-09-14 07:16:36 +0000 UTC) SMART_CHARGING true
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:04 +0000 UTC) CABLE_LOCKED true
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:57 +0000 UTC) CHARGER_OP_MODE 3
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:08 +0000 UTC) TOTAL_POWER 3.427000045776367
16:27:16 ProductUpdate Easee: (2023-09-14 09:44:03 +0000 UTC) SESSION_ENERGY 13.321113586425781
16:27:16 ProductUpdate Easee: (2023-09-14 14:00:00 +0000 UTC) ENERGY_PER_HOUR 0
16:27:16 ProductUpdate Easee: (2023-09-14 13:55:06 +0000 UTC) WI_FI_RSSI -80
16:27:16 ProductUpdate Easee: (2023-09-14 13:29:43 +0000 UTC) CELL_RSSI -77
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:54 +0000 UTC) OUTPUT_PHASE 10
16:27:16 ProductUpdate Easee: (2023-08-16 09:13:10 +0000 UTC) DYNAMIC_CIRCUIT_CURRENT_P1 32
16:27:16 ProductUpdate Easee: (2023-08-16 09:13:10 +0000 UTC) DYNAMIC_CIRCUIT_CURRENT_P2 0
16:27:16 ProductUpdate Easee: (2023-08-16 09:13:10 +0000 UTC) DYNAMIC_CIRCUIT_CURRENT_P3 0
16:27:16 ProductUpdate Easee: (2023-09-14 14:23:49 +0000 UTC) TEMP_MAX 35
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:27 +0000 UTC) SOFTWARE_RELEASE 310
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:27 +0000 UTC) CHARGER_RAT 1
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) LOCK_CABLE_PERMANENTLY true
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:11 +0000 UTC) IN_CURRENT_T2 18.638999938964844
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:08 +0000 UTC) IN_CURRENT_T3 15.003999710083008
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:38 +0000 UTC) IN_CURRENT_T4 0.007000000216066837
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:38 +0000 UTC) IN_CURRENT_T5 0.008999999612569809
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:09 +0000 UTC) OUTPUT_CURRENT 25
16:27:16 ProductUpdate Easee: (2023-09-14 14:23:49 +0000 UTC) IN_VOLT_T2_T3 231.81199645996094
16:27:16 ProductUpdate Easee: (2023-09-14 14:23:49 +0000 UTC) IN_VOLT_T2_T4 237.5189971923828
16:27:16 ProductUpdate Easee: (2023-09-14 14:23:49 +0000 UTC) IN_VOLT_T2_T5 239.88999938964844
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:58 +0000 UTC) LEDMODE 22
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:04 +0000 UTC) CABLE_RATING 32
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:08 +0000 UTC) DYNAMIC_CHARGER_CURRENT 25
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:09 +0000 UTC) CIRCUIT_TOTAL_ALLOCATED_PHASE_CONDUCTOR_CURRENT_L1 25
16:27:16 ProductUpdate Easee: (2023-08-16 09:13:12 +0000 UTC) CIRCUIT_TOTAL_ALLOCATED_PHASE_CONDUCTOR_CURRENT_L2 0
16:27:16 ProductUpdate Easee: (2023-08-16 09:13:12 +0000 UTC) CIRCUIT_TOTAL_ALLOCATED_PHASE_CONDUCTOR_CURRENT_L3 0
16:27:16 ProductUpdate Easee: (2023-09-14 14:27:12 +0000 UTC) CIRCUIT_TOTAL_PHASE_CONDUCTOR_CURRENT_L1 20.20599937438965
16:27:16 ProductUpdate Easee: (2023-09-14 14:13:40 +0000 UTC) CIRCUIT_TOTAL_PHASE_CONDUCTOR_CURRENT_L2 0.007000000216066837
16:27:16 ProductUpdate Easee: (2023-09-14 14:12:26 +0000 UTC) CIRCUIT_TOTAL_PHASE_CONDUCTOR_CURRENT_L3 0.00800000037997961
16:27:16 ProductUpdate Easee: (2023-09-14 14:26:53 +0000 UTC) REASON_FOR_NO_CURRENT 78
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:15 +0000 UTC) WI_FI_APENABLED false
16:27:16 ProductUpdate Easee: (2023-09-14 14:00:00 +0000 UTC) LIFETIME_ENERGY 2342.6345680555555
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) MAX_CURRENT_OFFLINE_FALLBACK_P1 32
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) MAX_CURRENT_OFFLINE_FALLBACK_P2 32
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) MAX_CURRENT_OFFLINE_FALLBACK_P3 32
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:04 +0000 UTC) ERROR_CODE 0
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:06 +0000 UTC) ObservationID(219) 0
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:05 +0000 UTC) DERATING_ACTIVE false
16:27:16 ProductUpdate Easee: (2023-09-14 12:13:23.345 +0000 UTC) CONNECTED_TO_CLOUD true
16:27:16 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) IS_ENABLED true
16:27:16 ProductUpdate Easee: (2023-08-17 14:05:25 +0000 UTC) AUTHORIZATION_REQUIRED true
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) SMART_BUTTON_ENABLED false
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:27 +0000 UTC) WI_FI_SSID Curieweg
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:04 +0000 UTC) DETECTED_POWER_GRID_TYPE 1
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) CIRCUIT_MAX_CURRENT_P1 32
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) CIRCUIT_MAX_CURRENT_P2 32
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) CIRCUIT_MAX_CURRENT_P3 32
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) ENABLE_IDLE_CURRENT true
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) PHASE_MODE 2
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:21 +0000 UTC) LOCAL_AUTHORIZATION_REQUIRED false
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:43 +0000 UTC) LOCAL_NODE_TYPE 1
16:27:17 ProductUpdate Easee: (2023-09-14 10:20:53 +0000 UTC) LOCAL_RADIO_CHANNEL 2
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:43 +0000 UTC) LOCAL_SHORT_ADDRESS 0
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:43 +0000 UTC) LOCAL_PARENT_ADDR_OR_NUM_OF_NODES 0
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:21 +0000 UTC) ALLOW_OFFLINE_TX_FOR_UNKNOWN_ID true
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:28 +0000 UTC) MAX_CHARGER_CURRENT 32
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:21 +0000 UTC) LOCAL_AUTHORIZE_OFFLINE_ENABLED true
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:21 +0000 UTC) LOCAL_PRE_AUTHORIZE_ENABLED true
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:22 +0000 UTC) LED_STRIP_BRIGHTNESS 50
16:27:17 ProductUpdate Easee: (2023-08-16 09:10:33.680478 +0000 UTC) CHARGING_SCHEDULE 
16:27:17 ProductUpdate Easee: (2023-09-14 12:13:23 +0000 UTC) CHARGER_OFFLINE_REASON 0
16:27:18 ProductUpdate Easee: (2023-09-14 14:27:16 +0000 UTC) IN_CURRENT_T2 24.607999801635742
16:27:19 ProductUpdate Easee: (2023-09-14 14:27:18 +0000 UTC) CIRCUIT_TOTAL_PHASE_CONDUCTOR_CURRENT_L1 24.91699981689453

GrimmiMeloni · 2023-09-15T15:47:31Z

Wir nehmen für alle Product Updates immer das aktuellste was Easee per API zur Verfügung stellt. Insbesondere werden Product Updates rausgefiltert die einen älteren Timestamp haben als wir aktuell im Speicher. (fix dazu bereits im Juli, siehe #9047)

Ansonsten sorry, aber TL;DR - bitte ggf. konkret nochmal Log(ausschnitt) zeigen um den es geht. Das hier ist viel zu detailliert um hier nachträglich einzusteigen.

andig · 2023-09-15T16:10:07Z

Danke @GrimmiMeloni dass Du da rein schaust!

GrimmiMeloni · 2023-09-16T11:39:02Z

@allcoolusernamesaregone ich habe mich jetzt hier mal tapfer eingelesen.
Zur Sicherheit mal mein Verständnis, damit wir auch über die gleichen Probleme reden.

SESSION_ENERGY enthält immer den letzten bekannten Wert. Dies ist blöd, weil wir beim Ladestart diesen Wert nehmen und somit die Energie vom letzten Charge als Startwert nehmen.
SESSION_ENERGY kommt (nach Ladeende) teils erst mit massiver Verspätung (40 Mins). Somit kann auch Problem 1. nicht immer automatisch "ausgebügelt" werden.

Wo oben erläutert, filtern wir bereits veraltete Werte bei den Product Updates, falls diese Out of order kommen. Ich möchte ungern noch weitere "magic" in Bezug auf die Product Updates einbauen. Es wird dann haarig wenn es darum geht den "korrekten" Threshold zu finden. Sind 5mins schon "alt"? Oder erst 1h? Und gilt das für alle, oder nur für manche? Besser nicht zu sehr tricksen - zumindest nicht so lange wir hier andere Optionen haben.

Zu deinen Vorschlägen.
Ich finde die Idee mit dem Polling bei Ladestop ganz OK. Wir müssten aber auch hier schauen das wir dann synchron auf das Product Update warten. Sonst bringt das ganze nichts.
@andig gibt es überhaupt irgendeinen "hook" auf dem ich aufsetzen könnte um bei Ladestop eine Aktion auf dem Charger auszulösen? In ChargedEnergy() das Update zu forcieren ist keine Option, da wir das sonst jedes Intervall machen.

allcoolusernamesaregone · 2023-09-16T11:57:20Z

Hallo, kurz vorab da mobil, bei 2. müsste es LIFETIME_ENERGY heißen denke ich..
Und wenn veraltete/alte Updates schon heute gefiltert werden sollen ist das ja vom Prinzip her wie nein Vorschlag dann muss ich mir mal im #9047 ansehen was da passiert bzw. wie ein 6 Stunden alter Wert durchkommt. War heute morgen schon wieder, angeblich 5,x kwh geladen, was bei <1h Ladedauer mit < 4 kW PV Leistung im Modus PV nicht möglich ist. Denke gleiches Problem, die 5,x kwh stammen von einer Ladesession gestern.

allcoolusernamesaregone · 2023-09-16T19:27:46Z

Ich habe in der Easee.go hinter

	if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.After(res.Timestamp) {
		// received observation is outdated, ignoring
		return

nun mal folgendes ergänzt. Switch, da ich anfänglich dachte, auch andere Werte bräuchten ggf. eine Sonderbehandlung. Ist aber, wenn man sich die ganzen veralteten bzw. älteren Werte ansieht (Übersicht folgt) nicht so.

	switch res.ID {
	  case easee.SESSION_ENERGY:
	    loc, _ := time.LoadLocation("UTC")
	    expiresAt := time.Now().In(loc).Add(-15 * time.Minute)
	    if res.Timestamp.Before(expiresAt) {
		    // received SESSION_ENERGY value too old
		    c.log.TRACE.Printf("ProductUpdate too old");
		    return
	    }
	    if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.Equal(res.Timestamp) && 0 == value.(float64) {
	      // received SESSION_ENERGY value 0 after valid value in the same second
	      c.log.TRACE.Printf("ProductUpdate to 0 invalid, SESSION_ENERGY is not 0");
	      return
	    }

Das erste if filtert die SESSION_ENERGY Updates, deren Erstelldatum älter als 15 Minuten beim Empfangen ist.
Das zweite if filtert Updates auf 0, die reproduzierbar (bzw. wiederholt zu beobachten) nach einem stop_charging auf die korrekten Werte kommen, z.B.

[easee ] TRA.. 11:06:48 ... 09:06:46 +0000 UTC) SESSION_ENERGY 5.206270694732666
[easee ] TRA.. 11:06:48 ... 09:06:46 +0000 UTC) SESSION_ENERGY 5.206270694732666
[easee ] TRA.. 11:06:48 ... 09:06:46 +0000 UTC) SESSION_ENERGY 0

Ein Neustart von EVCC und somit auf zwingendem SignalR Neuaufbau:

[easee ] TRACE 2023/09/16 20:51:16 POST https://api.easee.com/api/accounts/login
[easee ] TRACE 2023/09/16 20:51:16 {"userName":"***","password":"***"}
[easee ] TRACE 2023/09/16 20:51:16 GET https://api.easee.com/api/chargers/../site
[easee ] TRACE 2023/09/16 20:51:17 {"id"....]}
[easee ] TRACE 2023/09/16 20:51:17 POST https://streams.easee.com/hubs/chargers/negotiate
[easee ] TRACE 2023/09/16 20:51:17 {"negotiateVersion":0,"connectionId"....
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-09-16 09:43:15 +0000 UTC) CHARGER_OP_MODE 1
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-09-16 09:43:15 +0000 UTC) SESSION_ENERGY 3.904536485671997
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate too old
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-09-16 18:01:29 +0000 UTC) CELL_RSSI -76
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-09-16 18:28:29 +0000 UTC) WI_FI_RSSI -80
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-08-16 09:10:04 +0000 UTC) CABLE_LOCKED true
[easee ] TRACE 2023/09/16 20:51:17 ProductUpdate : (2023-09-16 09:43:15 +0000 UTC) TOTAL_POWER 0

Denke es ist wenig sinnvoll, den Wert SESSION_ENERGY der letzten Ladesession von vor 10 Stunden zu übernehmen..

Ein Ladevorgang->Ende->Ab-/Anstecken - Pause -> Ladegang Szenario teste ich morgen mal..

Anbei außerdem eine Übersicht der empfangenen Productupdates nach Neuaufbau der SignalR Verbindung.
Die Werte teilen sich in 3 Gruppen: recht aktuelle und noch brauchbare Werte (BIS zur Zeile SESSION_ENERGY), dann veraltete falsche Werte - SESSION_ENERGY + SMART_CHARGING (Ansichtssache ob Wert true bei fehlendem Fahrzeug korrekt ist..) - sowie etliche sehr alte Werte, was aber ok ist, da Konfigurationswerte.
Alter einzelner Observations.pdf

Wegen dem Start- und Endzählerstand, habe ältere Logs geprüft, das ist systematisch falsch. Der Eintrag in die Datenbank bzw. das Update der Session erfolgt mit einem nicht aktuellen Wert. Der kommt halt tatsächlich unterschiedlich viel später.
In obigem PDF war das letzte Update des Werts vor 27 Minuten. Im Log oben im Issue ist der Wert erst nach 40 Minuten aktuell.
Eigentlich müsste man hier die "Poll API" aufrufen und kurze Zeit später das empfangene Productupdate verarbeiten für ein Session Update in der Datenbank.

allcoolusernamesaregone · 2023-09-16T19:32:46Z

Nachtrag:

die Session in der Datenbank ist i.A.

für den Startzählerstand nur korrekt, wenn der Ladestart mit zeitlicher Verzögerung zur letzten Veränderung des Stands vor Ort erfolgt / die Api/Cloud das verarbeitet und gesendet hat - gilt ja das gleiche wie für den Endstand. Wäre im Beispiel am Anfang innerhalb der 40 Minuten ein Ladestart erfolgt, wäre der Ladestand ebenfalls veraltet. Würde aber immerhin zum Endstand der vorigen Sitzung passen ;)
die geladene Menge nur korrekt, wenn die in der aktuellen Sitzung geladene Menge größer ist als die Menge der vorigen Sitzung
der Endzählerstand eigentlich nie korrekt

Ob das schon länger so ist, oder die API seit kürzlich (da gab's doch vor kurzem einen Ausfall/Wartung!?) - wer weiß.

andig · 2023-09-16T20:48:34Z

Ticket bei Easee?

allcoolusernamesaregone · 2023-09-16T20:52:14Z

Wer wo wie?

GrimmiMeloni · 2023-09-17T07:26:43Z

Wer wo wie?

https://support.easee.com/hc/de/requests/new

GrimmiMeloni · 2023-09-17T08:48:03Z

Hier stellt sich weiterhin die Frage wann zu filtern ist. Auch ein 10h alter Wert für SESSION_ENERGY kann durchaus korrekt sein, z.B. wenn über Nacht pausiert wird und es bei Sonnenaufgang mit der Ladung weitergeht.

Im Kern ist das Problem das SESSION_ENERGY und LIFETIME_ENERGY nicht zuverlässig aktualisiert werden. Während der Ladung "unschön" aber insbesondere am Ende der Session nicht gut, weil wir mit (teils stark) veralteten Werten rechnen, wenn wir die Session abschließen.

Ich habe das jetzt noch nicht selbst testen können, ich mutmaße aber das wir hier eine Race Condition haben, zwischen Session Ende (und Berechnung im Loadpoint) und dem asynchronen Update für SESSION_ENERGY und LIFETIME_ENERGY. Hängt vermutlich auch vom Zeitpunkt im Intervall ab, wann die Ladung physikalisch endet. Selbst wenn Easee die letzten Werte zeitnah sendet, könnte es sein das wir dies nicht mehr berücksichtigen weil wir bereits berechnet haben.

Der zuverlässigste Weg wäre meiner Ansicht nach beim Stoppen der Session die Daten direkt bei Easee abzuholen. Ich sehe aber noch nicht wie das im Code möglich wäre.

Ein Mittelweg könnte es sein, die Werte für ChargedEnergy() und TotalEnergy() regelmäßig (1x pro Minute?) über die Easee API zu pollen. Damit wären die Daten immer noch nicht exakt, aber zumindest nah dran.

allcoolusernamesaregone · 2023-09-17T09:34:23Z

Hier stellt sich weiterhin die Frage wann zu filtern ist. Auch ein 10h alter Wert für SESSION_ENERGY kann durchaus korrekt sein, z.B. wenn über Nacht pausiert wird und es bei Sonnenaufgang mit der Ladung weitergeht.

Das stimmt, allerdings gilt das nur während der selben Ladesitzung, und das weiß man doch, bzw. den Wechsel der Sitzung kann man doch erkennen/auswerten.
Nach Anstecken eines Fahrzeugs kann ein Wert >0 und älter als ein paar Minuten einfach nicht stimmen.
Wieviel kWh z.B. bei 22 kW und in 5 Minuten maximal möglich wären und noch plausibel, das kann man ja leicht rechnen und als Grenze nehmen.

Der zuverlässigste Weg wäre meiner Ansicht nach beim Stoppen der Session die Daten direkt bei Easee abzuholen. Ich sehe aber noch nicht wie das im Code möglich wäre.
... Werte für ChargedEnergy() und TotalEnergy() ...

ChargedEnergy() = SESSION_ENERGY wird nach meinen Logs nach stop_charging umgehend und korrekt übermittelt als Productupdate. Das wird nur heute ja leider ignoriert, da der Wert kleiner als der vorherige Wert der letzten Ladesession ist.

TotalEnergy() = LIFETIME_ENERGY wird periodisch (ca. stündlich außerhalb einer Ladesitzung, während einer Sitzung viel häufiger) als Productupdate gesendet, aber der Wert selbst wird in der Cloud scheinbar nur stündlich aktualisiert.
Siehe nachfolgenden gegrepten Log, ab ca. 11 Uhr wird geladen - vorher sieht man viel seltenere Updates, aber der Zeitstempel des Werts selbst ist in ganzen Stunden sozusagen - mit der Api zum pollen wird ein aktualles Update ausgelöst.
TotalEnergy() könnte man daher eigentlich aus Startzählerstand + ChargedEnergy recht genau errechnen beim Ende einer Ladesession, falls man nicht erst pollen und auf das Update warten möchte.
Und dann NACH Ende der Ladesession und Update der Datenbank einfach die Api zum Pollen aufrufen, damit dann auch der Startstand für die nächste Sitzung ganz exakt ist (wenn diese <= 60 Minuten startet nach Ende der dieser/letzten Sitzung, ansonsten auch automatisch durch das stündliche Update), sonst startet die ja auch mit einem veralteten Wert.

[easee ] TR .. 19:01:41 Prod..: (2023-09-16 17:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 20:02:22 Prod..: (2023-09-16 18:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 20:51:17 Prod..: (2023-09-16 18:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 21:10:08 Prod..: (2023-09-16 19:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 22:09:56 Prod..: (2023-09-16 20:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 23:11:45 Prod..: (2023-09-16 21:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 00:09:36 Prod..: (2023-09-16 22:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 01:09:31 Prod..: (2023-09-16 23:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 02:09:04 Prod..: (2023-09-17 00:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 03:14:40 Prod..: (2023-09-17 01:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 04:01:26 Prod..: (2023-09-17 02:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 05:14:09 Prod..: (2023-09-17 03:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 06:01:39 Prod..: (2023-09-17 04:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 07:02:13 Prod..: (2023-09-17 05:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 08:08:42 Prod..: (2023-09-17 06:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 09:02:39 Prod..: (2023-09-17 07:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 10:05:48 Prod..: (2023-09-17 08:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:04:39 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:07:46 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:14:43 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:16:27 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:20:06 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:21:04 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230
[easee ] TR .. 11:23:02 Prod..: (2023-09-17 09:00:00 +0000 UTC) LIFETIME_ENERGY 2369.230

Mag auch sein dass das Mist ist von Easee - vielleicht hat es aber auch seinen Grund. Ob oder ob nicht, und falls ja, da eine Korrektur käme - wer weiß. Ist eigentlich keine Option darauf zu warten, wenn die Statistik irgendeinen Sinn ergeben sollte..

GrimmiMeloni · 2023-09-17T11:37:05Z

ChargedEnergy() = SESSION_ENERGY wird nach meinen Logs nach stop_charging umgehend und korrekt übermittelt als Productupdate. Das wird nur heute ja leider ignoriert, da der Wert kleiner als der vorherige Wert der letzten Ladesession ist.

Ich glaube wir reden immer noch über unterschiedliche Dinge.
Der Filter schaut nur auf den Timestamp, der Wert an sich wird "blind" übernommen. Ganz explizit spreche ich von

evcc/charger/easee.go

Line 278 in 9e0ceb9

if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.After(res.Timestamp) {

Wo siehst Du das alte und neue Werte verglichen und ggf. ignoriert werden? Kannst Du die Stelle im Code benennen?

allcoolusernamesaregone · 2023-09-17T12:38:24Z

ok, an folgendem Beispiel erklärt:
Ladevorgang 1 morgens endet um 11:44:05:
[easee ] TRACE ./09/14 11:44:05 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 13.321113586425781 -> wird als Wert übernommen
[easee ] TRACE ./09/14 11:44:05 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 0 -> wird ignoriert durch if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.After(res.Timestamp) {

Ladevorgang 2 startet am Nachmittag
[easee ] TRACE ./09/14 16:27:16 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 13.321113586425781 -> wird wie das Setzen auf 0 ignoriert, gleiches "Herkunftsdatum"
[easee ] TRACE ./09/14 16:31:24 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 13.321113586425781 -> wie vorige Zeile
[easee ] TRACE ./09/14 16:33:11 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 13.321113586425781 -> wie vorige Zeile
[easee ] TRACE ./09/14 16:36:11 Pro.23-09-14 14:36:10 ) SESSION_ENERGY 1.0028105974197388 -> erster echter neuer Wert des 2. Ladevorgangs.
Dieser kleinere Wert wird zwar als Productupdate übernommen in der Easee.go - aber (soweit mein Verständnis!)
ignoriert entweder in Loadpoint.go

		if f > lp.chargedAtStartup {
			lp.sessionEnergy.Update(f - lp.chargedAtStartup)
		}

und/oder (vermutlich eher) in energy-metrigs.go

func (em *EnergyMetrics) Update(chargedKWh float64) {
        added := chargedKWh - em.totalKWh
        // nothing changed or invalid lower value
        if added <= 0 {
                return
        }

"...or invalid lower value" sagt denke ich auch genau das.

Daher sah ich auch im Beispiel oben
a) schon zu Beginn des 2. Ladevorgangs in der UI die "13,3 kwh geladen", als auch
b) jetzt in der Statistik bzw. der Auflistung der Ladevorgänge 2x 13,3 kWh.

Der 2. Ladevorgang wäre korrekt protokolliert, wären > 13,3 kWh geladen worden, denke ich.

allcoolusernamesaregone · 2023-09-17T13:12:21Z

Nun, ich habe hinter

	if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.After(res.Timestamp) {
		// received observation is outdated, ignoring
		return
	}

nun folgendes eingebaut:

	switch res.ID {
	  case easee.CHARGER_OP_MODE:
	    //OpMode changed from "no car" to some other state => assume Car connected if Easee not Offline or still disconnected
	    if 1 == c.opMode && value.(int) >= 2 {
	      c.log.TRACE.Printf("XXXX ProductUpdate: Car connected. Reset internal value of SESSION_ENERGY to 0");
	      c.sessionEnergy = 0;
	      
	    	uri := fmt.Sprintf("%s/chargers/%s/commands/%s", easee.API, c.charger, "poll_lifetimeenergy")
				c.Post(uri, request.JSONContent, request.MarshalJSON(nil))
	      
	    }
	    //OpMode changed to "no car" from some other state => car disconnected
	    if (1 == value.(int) && c.opMode >= 2) {
	    	uri := fmt.Sprintf("%s/chargers/%s/commands/%s", easee.API, c.charger, "poll_lifetimeenergy")
				c.Post(uri, request.JSONContent, request.MarshalJSON(nil))
	    }
	  case easee.SESSION_ENERGY:
	    loc, _ := time.LoadLocation("UTC")
	    expiresAt := time.Now().In(loc).Add(-5 * time.Minute)
	    if res.Timestamp.Before(expiresAt) && 0 == c.sessionEnergy {
		  // received SESSION_ENERGY value too old after 1st start_charging of a session
		  c.log.TRACE.Printf("XXXX ProductUpdate too old after charger start");
		  return
	    }
	    if prevTime, ok := c.obsTime[res.ID]; ok && prevTime.Equal(res.Timestamp) && 0 == value.(float64) {
	      // received SESSION_ENERGY value 0 after valid value in the same second, e.g. after stop_charging
	      c.log.TRACE.Printf("XXXX  ProductUpdate SESSION_ENERGY of duplicate timestamp to 0 invalid, ignore");
	      return
	    }
	}

Den case CHARGER_OP_MODE habe ich ergänzt, da der intern vorhandene Wert auch über Ladesessions erhalten bleibt, das ignorieren veralteter Updates im case SESSION_ENERGY allein daher nicht zielführend war.
Bei der Gelegenheit kann dann beim Erkennen des Ab/Ansteckens, also auf/von OP_MODE 1, ein aktueller Wert für LIFETIME_ENERGY "bestellt" werden, der gerade beim Ladestart dann korrekt in der Datenbank landet.

Ebenso nach

	uri := fmt.Sprintf("%s/chargers/%s/commands/%s", easee.API, c.charger, action)
	_, err := c.postJSONAndWait(uri, nil)
	if err != nil {
		return err
	}

ergänzt:

	uri = fmt.Sprintf("%s/chargers/%s/commands/%s", easee.API, c.charger, "poll_lifetimeenergy")
	c.Post(uri, request.JSONContent, request.MarshalJSON(nil))

Nach start/stop / resume/pause charging ebenfalls einen neuen Wert für LIFETIME_ENERGY anfordern.
Allerdings ist das auf "1 mal in 3 Minuten" gedeckelt.

Funktioniert hat das jetzt in mehreren Tests mit unterschiedlichen Ladestarts (EVCC startet neu während Fahrzeug verbunden, Fahrzeug verbinden während EVCC läuft, Ende Ladevorgang über UI, Ende Ladevorgang über Aufsperren Fahrzeug/abstecken) wie erwartet. Start+Endwert korrekt, geladene Menge ebenfalls.

Alternativ könnte man folgendes tun:

Bei Wechsel von "disconnected" auf sonstigen OP_MODE: poll_lifetimeenergy aufrufen -> Startwert korrekt, diesen Wert merken
Dann, solange Ladevorgang aktiv: alle 3 Minutenpoll_lifetimeenergy aufrufen
ChargedEnergy(): aktuellen Wert von LIFETIME_ENERGY minus Startwert
Am Ende des Ladevorgangs poll_lifetimeenergy

GrimmiMeloni · 2023-09-17T13:31:44Z

Die Idee den OP_MODE Wechsel als Trigger für einen Poll zu nehmen finde ich gut. 👍

Das sollte auch die oben genannte Race Condition verhindern, zumindest wenn wir noch auf das async Product Update für LIFETIME_ENERGY warten. Dann können wir sicherstellen, daß der Loadpoint die Zustandsänderungen erst sieht wenn wir definitiv die aktuellen Werte haben. Somit finden dann auch Berechnungen am Session Ende auf korrekten Daten statt.

Was mir überflüssig erscheint ist der Aufruf des Polls explizit nach start/stop/resume/pause. Dabei entsteht implizit ein opMode Übergang, welcher dann den entsprechenden Poll mit Deinem Change auslöst. Oder übersehe ich hier etwas?

Zusätzlich müssen wir noch bei den zeitgleich eintreffenden SESSION_ENERGY Updates aufpassen . Die Reihenfolge der Nachrichten ist erfahrungsgemäß nicht garantiert. Das war der eigentliche Auslöser für den Filter über den Timestamp. Wenn jetzt aber die Nachrichten mal in anderer Reihenfolge kommen, könnte es sein das wir 0 statt dem letzten korrekten Wert der Session übernehmen.

Der explizite Reset auf 0 sollte auch den Timestamp auf den aktuellen Zeitpunkt ändern. Dann ist die Logik bzgl. "älter als 5 mins" nicht mehr erforderlich.

Bitte pack mal Deinen Change in einen PR, damit wir hier sauber zusammenarbeiten können. Danke!

allcoolusernamesaregone · 2023-09-17T14:05:40Z

Die Idee den OP_MODE Wechsel als Trigger für einen Poll zu nehmen finde ich gut. 👍
:)
Dann können wir sicherstellen, daß der Loadpoint die Zustandsänderungen erst sieht wenn wir definitiv die aktuellen Werte haben. Somit finden dann auch Berechnungen am Session Ende auf korrekten Daten statt.

klingt gut, für sowas reichen meine Go / EVCC Kenntnisse leider nicht :(

Was mir überflüssig erscheint ist der Aufruf des Polls explizit nach start/stop/resume/pause. Dabei entsteht implizit ein opMode Übergang, welcher dann den entsprechenden Poll mit Deinem Change auslöst. Oder übersehe ich hier etwas?

Ja, das stimmt. Ich filter aber aktuell ja auf an/abstecken, ein Stop/Start von EVCC wird da ja nicht berücksichtigt.
Wenn man natürlich bei jeder Änderung des opModes triggert ist das nach stop oder start natürlich unnötig.
Wobei durch die 3 Minuten Beschränkung und einem schnellen Wechseln der Opmodes von 1 auf 7 auf 2 auf 6 auf 3 - was beim "authentifizierten Start" so passiert, ein zu schnelles Aufrufen ggf. schädlich für die API (Sperrung) bzw. auch sinnlos ist.

Wenn jetzt aber die Nachrichten mal in anderer Reihenfolge kommen, könnte es sein das wir 0 statt dem letzten korrekten Wert der Session übernehmen.

Deswegen nulle ich nach dem Anstecken den internen letzten Wert, der ja noch > 0 sein kann
"XXXX ProductUpdate: Car connected. Reset internal value of SESSION_ENERGY to 0"

und übernehme dann auch nur aktuelle Werte (man könnte da nach meinen Logfiles auf <1 Minute runter)
"// received SESSION_ENERGY value too old after 1st start_charging of a session"

und verhindere das versehentliche Nullen des letzten Werts durch ein "gleich altes" Update, wenn der neue Wert 0 ist.
"received SESSION_ENERGY value 0 after valid value in the same second, e.g. after stop_charging"

Falls diese gleich alte 0-Meldung im ProductUpdate (wie hier im Log)
[easee ] TRACE ./09/14 11:44:05 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 13.321113586425781
[easee ] TRACE ./09/14 11:44:05 Pro.23-09-14 09:44:03 ) SESSION_ENERGY 0
als ein Art "Nullen" des Werts beim Empfängers durch Easee gedacht war, so ist das nicht nötig, da das durch den Opmode wechsel genullt wurde. Aber denke eher das ist Mist von der Api, denn in der nächsten Session (s.o.) kommt ja wieder der Wert 13,32. Macht sie das nullen rückgängig ... :-|

Der explizite Reset auf 0 sollte auch den Timestamp auf den aktuellen Zeitpunkt ändern. Dann ist die Logik bzgl. "älter als 5 mins" nicht mehr erforderlich.

Muss ich drüber sinnieren 😂 - aber klingt gut. Da scheitere ich beim Analysieren heute morgen ein wenig am Verständnis von Go und der Datenstrukturen.

Bitte pack mal Deinen Change in einen PR, damit wir hier sauber zusammenarbeiten können. Danke!

Äh, ich versuch's mal.. da waren wir glaub ich schon mal, ich habe keine Ahnung, aber setze mich heute abend mal ran...

allcoolusernamesaregone · 2023-09-17T18:22:35Z

Äh, ich versuch's mal.. da waren wir glaub ich schon mal, ich habe keine Ahnung, aber setze mich heute abend mal ran...

#9940 so richtig...?

andig closed this as completed Sep 14, 2023

andig added the question Rather clarification than issue label Sep 14, 2023

allcoolusernamesaregone mentioned this issue Sep 17, 2023

Easee: validate LIFETIME_ENERGY and SESSION_ENERGY #9940

Merged

GrimmiMeloni mentioned this issue Oct 4, 2023

Easee: Falscher TOTAL_POWER verfälscht evcc-Werte #10175

Closed

supeerpeer mentioned this issue Oct 21, 2023

Geladene kWH Easee vs evcc.db vs EVCC GUI Session-Übersicht #10428

Closed

GrimmiMeloni mentioned this issue Jul 24, 2024

Loadstatistic wrong calculated in EVCC with Easee Wallbox. Meter Count in EVCC correct #14923

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Geladene kWh / kWh der Session fehlerhaft #9884

Geladene kWh / kWh der Session fehlerhaft #9884

allcoolusernamesaregone commented Sep 14, 2023 •

edited by naltatis

Loading

andig commented Sep 14, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 14, 2023

andig commented Sep 15, 2023

allcoolusernamesaregone commented Sep 15, 2023

allcoolusernamesaregone commented Sep 15, 2023

GrimmiMeloni commented Sep 15, 2023

andig commented Sep 15, 2023

GrimmiMeloni commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

andig commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

GrimmiMeloni commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023

allcoolusernamesaregone commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 17, 2023

allcoolusernamesaregone commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 17, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 17, 2023 •

edited

Loading

Geladene kWh / kWh der Session fehlerhaft #9884

Geladene kWh / kWh der Session fehlerhaft #9884

Comments

allcoolusernamesaregone commented Sep 14, 2023 • edited by naltatis Loading

Describe the bug

Steps to reproduce

Configuration details

Log details

What type of operating system are you running?

Version

andig commented Sep 14, 2023 • edited Loading

allcoolusernamesaregone commented Sep 14, 2023

andig commented Sep 15, 2023

allcoolusernamesaregone commented Sep 15, 2023

allcoolusernamesaregone commented Sep 15, 2023

GrimmiMeloni commented Sep 15, 2023

andig commented Sep 15, 2023

GrimmiMeloni commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

andig commented Sep 16, 2023

allcoolusernamesaregone commented Sep 16, 2023

GrimmiMeloni commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023

allcoolusernamesaregone commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023 • edited Loading

allcoolusernamesaregone commented Sep 17, 2023

allcoolusernamesaregone commented Sep 17, 2023

GrimmiMeloni commented Sep 17, 2023 • edited Loading

allcoolusernamesaregone commented Sep 17, 2023 • edited Loading

allcoolusernamesaregone commented Sep 17, 2023 • edited Loading

allcoolusernamesaregone commented Sep 14, 2023 •

edited by naltatis

Loading

andig commented Sep 14, 2023 •

edited

Loading

GrimmiMeloni commented Sep 17, 2023 •

edited

Loading

GrimmiMeloni commented Sep 17, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 17, 2023 •

edited

Loading

allcoolusernamesaregone commented Sep 17, 2023 •

edited

Loading