search

evcc-io / evcc

Solar Charging ☀️🚘
https://evcc.io
MIT License
3.67k stars 687 forks source link

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

Closed supeerpeer closed 1 year ago

supeerpeer commented 1 year ago

Describe the bug

Im Vergleich der geladenen kWh Meter Wallbox (Easee Home) und EVCC fehlen auf Monatssicht immer knapp 10% der Lademenge:

September / Oktober / Gesamt evcc: 233,4 kWh / 158,5 kWh / 391,9 kWh (GUI Session Übersicht) easee: 246,3 kWh / 179,3 kWh/ 425,6 kWh(Easee App Verbrauchsdaten)

(Hintergrund: Ich würde gern für meine Fahrzeugkosten gerne auf die EVCC Daten zurückgreifen, da die ja auch PV Anteil und die effektiven Ladekosten beinhalten - wenn dort allerdings geladene Mengen fehlen macht das wenig Sinn...)

In der evcc.db habe ich beim Abgleich mit dem Ladedatenlog der Easee einige "problematische Muster" gefunden, die ich hier am Beispiel im Screenshot hervorgehoben habe:

A) Zeile 20: a) meter Start passt nicht zum Meter End der Vorsession, b) Differenz meter Start/End und kWh Charged passen nicht zusammen. der Charged kWh Wert stimmt mit dem Wert der Easee überein (habe verstanden, der wird eigentlich direkt von der Easee übernommen) --> für das Problem gibt /gab es ja glaube ich auch schon Tickets, die ähnlich gelagert sind (#9884 / #9940)

B) Zeile 21: meter Start ca. 4kWh höher als der meter End aus der vorherigen Session. (da fehlen irgendwo schon 4kWh). Der Charged kWh steht für diese Session auf "0", tatsächlich wurden aber laut Easee 0.866 kWh in der Session geladen. Daten wurden anscheinend nicht übernommen. die Differenz aus meter start/meter end kommt nur auf 0.48 kWh, also knapp die Hälfte des tatsächlichen Wertes. PV Anteil / Kosten sind für diese Session entsprechend auch auf null. --> diese Session wird mir in der GUI garnicht angezeigt und fehlt auch dort im Excel-Export, wo ich mir gerne die Daten für meine Kostenauswertung rausziehen würde.

C) Zeile 22: auch hier passt Meter Start wieder nicht mit dem meter End der Vorsession zusammen (+0.35. Charged kWh laut Easee (4.421164) passt dafür nicht mit dem charged kWh Wert bei evcc (4.1992) zusammen.

Evcc db fehlende kWh

Unterm Strich kann ich nicht nachvollziehen, sehr unterschiedlichen Konstellationen entstehen - erklärt aber, warum die Charged-Monatsummen so stark zwischen Easee und EVCC abweichen, da solche Fälle mehrfach vorkommen, Kleinvieh macht da auch Mist. (Habe auch Fälle, wo eine Session von 39kWh laut Easee in EVCC in drei Session aufgeteilt ist mit 0, 14 und 23kWh charged - auch hier fehlen mal eben 2kWh).

Ich vermute auch alle anderen Berechnungen der Kosten für die Session etc. basieren auf dem Charged kWh Wert in der evcc.db?

Und nur zur Orientierung am Rande: ca 1/4 meiner Sessions in der evcc.db hat Charge-Werte von 0 (meistens vermutlich berechtigt, da passen auch die meter start und meter end Werte dazu). Ob die Quote normal ist keine Ahnung :)

Steps to reproduce

n/a, tritt unregelmäßig auf

Configuration details

n/a

Log details

n/a

What type of operating system are you running?

Linux

Version

v0.121.0

andig commented 1 year ago

@GrimmiMeloni das sollte jetzt gelöst sein?

GrimmiMeloni commented 1 year ago

Meiner Ansicht nach, sollte es zumindest seit Lösung von #9940 korrektER (sic!) sein. Vielleicht kann @allcoolusernamesaregone hier auch nochmal sagen, wie es jetzt aktuell nach dem Patch in seinen Stats aussieht und ob der hier beschriebene Fall dazu passt. Ich selbst schaue einfach sehr selten (bis gar nicht) auf diese Statistiken.

@supeerpeer Wir haben im Rahmen der Lösung von #9940 relativ lange diskutiert. Das grundlegende Problem ist, daß die Messwerte von Easee nur verspätet kommen (sowohl bei Start als auch Ende). Dies deckt sich mit Deinen Beobachtungen. Ab 0.121.0 vertrauen wir den Easee Daten nicht mehr blind, und ignorieren z.B. offensichtlich falsche Werte, daher werden jetzt korrektere Werte in den Stats geschrieben. Aber eine Garantie das alles passt können wir nicht geben - unsere Quelldaten sind mitunter schlicht veraltet oder falsch. 🤷‍♂️ Wir haben meiner Ansicht nach in #9940 das Optimum rausgeholt, sind aber offen für Vorschläge falls Du noch weitere Möglichkeiten siehst es weiter zu verbessern.

Ferner haben wir auch bei Easee die Problematik gemeldet. Mehr können wir leider nicht tun. 😩

allcoolusernamesaregone commented 1 year ago

Meiner Ansicht nach, sollte es zumindest seit Lösung von #9940 korrektER (sic!) sein. Vielleicht kann @allcoolusernamesaregone hier auch nochmal sagen, wie es jetzt aktuell nach dem Patch in seinen Stats aussieht und ob der hier beschriebene Fall dazu passt. Ich selbst schaue einfach sehr selten (bis gar nicht) auf diese Statistiken.

Also, bzgl. Empfang der Session Energy bzw. Lifetime Energy Werte kann ich nichts mehr meckern, sie sind so genau bzw. aktuell wie die API sie mit etwas Nachhilfe (dem Aufruf zum Pollen) hergibt. Allerdings habe ich gelegentliche Hänger bzw. Fehlen von Updates der Session in der Datenbank gesehen. Gab ja auch kürzlich einen Commit zum schließen offener Sessions wenn ich das im Augenwinkel richtig gesehen habe.

Hänge dazu bald ein Beispiel Log an. Es fehlt nach Ladepause (Überschussmangel) das finale Update der Session in der Datenbank. Habe das schon länger aufbereitet. aber die Zeit... aber dann jetzt bei dieser Gelegenheit. Reproduzieren kann ich es leider nicht..

Daher kann es am Ende und in Summe schon zu Abweichungen kommen. Mit der easee hat das m.E.n. aber weniger bis nichts zu tun, sondern das ist Core/Datenbank Thema, imho.

allcoolusernamesaregone commented 1 year ago

Hier das Log. Es fehlt m.E.n. am Ende ein finales Update der Session in der Datenbank nach dem Abstecken. In der Datenbank sind die Werte für finished, meter_end_kwh, charged_kwh als auch charge_duration (je nach Definition) nicht wirklich korrekt. Daher die Frage: sollte nicht letztlich das Abstecken des Fahrzeugs selbst auch ein Update der Datenbank auslösen...?

........ Ladevorgang wird pausiert wg. zu wenig PV Überschuss
[lp-1  ] DEBUG 2023/10/05 17:43:45 pv disable timer elapsed
[lp-1  ] DEBUG 2023/10/05 17:43:46 charger: guard elapse
[lp-1  ] DEBUG 2023/10/05 17:43:46 guard timer inactive
[easee ] TRACE 2023/10/05 17:43:46 POST https://api.easee.com/api/chargers//commands/pause_charging
[easee ] TRACE 2023/10/05 17:43:46 {"device":"","commandId":48,"ticks":638321174262461000}
[easee ] TRACE 2023/10/05 17:43:47 CommandResponse : {SerialNumber: ID:48 Timestamp:2023-10-05 15:43:46.2461 +0000 UTC DeliveredAt:2023-10-05 15:43:45.998 +0000 UTC WasAccepted:true ResultCode:0 Comment: Ticks:638321174262461000}
[easee ] TRACE 2023/10/05 17:43:47 ProductUpdate : (2023-10-05 15:43:46 +0000 UTC) REASON_FOR_NO_CURRENT 52
.... Pause als Opmode gemeldet
[easee ] TRACE 2023/10/05 17:43:48 ProductUpdate : (2023-10-05 15:43:47 +0000 UTC) CHARGER_OP_MODE 2

........ Update für "total import" wird angefordert
[easee ] TRACE 2023/10/05 17:43:48 POST https://api.easee.com/api/chargers//commands/poll_lifetimeenergy
[easee ] TRACE 2023/10/05 17:43:48 {"device":"","commandId":2,"ticks":638321174286334990}
[lp-1  ] DEBUG 2023/10/05 17:43:48 charger disable
[lp-1  ] DEBUG 2023/10/05 17:43:48 wake-up timer: stop
[easee ] TRACE 2023/10/05 17:43:51 CommandResponse : {SerialNumber: ID:2 Timestamp:2023-10-05 15:43:48.633499 +0000 UTC DeliveredAt:2023-10-05 15:43:49.267 +0000 UTC WasAccepted:true ResultCode:0 Comment: Ticks:638321174286334990}

........  aber Wert ist in der Cloud noch nicht aktualisiert. 
........  Tatsächlicher Wert zu diesem Zeitpunkt ist bereits 2449.244022222219
[easee ] TRACE 2023/10/05 17:43:51 ProductUpdate : (2023-10-05 15:43:49 +0000 UTC) LIFETIME_ENERGY 2449.070142499997
[easee ] TRACE 2023/10/05 17:43:51 ProductUpdate : (2023-10-05 15:43:50 +0000 UTC) IN_VOLT_T2_T4 234.8000030517578
[easee ] TRACE 2023/10/05 17:43:51 ProductUpdate : (2023-10-05 15:43:50 +0000 UTC) IN_VOLT_T2_T5 238.64199829101562
[easee ] TRACE 2023/10/05 17:43:51 ProductUpdate : (2023-10-05 15:43:50 +0000 UTC) IN_VOLT_T2_T3 228.83299255371094
[easee ] TRACE 2023/10/05 17:43:51 ProductUpdate : (2023-10-05 15:43:50 +0000 UTC) TEMP_MAX 32
[site  ] DEBUG 2023/10/05 17:43:55 ----
[lp-1  ] DEBUG 2023/10/05 17:43:55 charge power: 0W
[site  ] DEBUG 2023/10/05 17:43:55 pv power: 1612W
[site  ] DEBUG 2023/10/05 17:43:55 grid power: -1406W
[site  ] DEBUG 2023/10/05 17:43:55 grid powers: [-468 -464 -474]W
[site  ] DEBUG 2023/10/05 17:43:55 grid currents: [-2.4 -2.34 -2.3]A
[site  ] DEBUG 2023/10/05 17:43:55 site power: -1206W
[lp-1  ] DEBUG 2023/10/05 17:43:55 charge currents: [0.01 0.02 0.013]A
[lp-1  ] DEBUG 2023/10/05 17:43:55 charge total import: 2449.070kWh
[lp-1  ] DEBUG 2023/10/05 17:43:55 charger status: B
[lp-1  ] INFO 2023/10/05 17:43:55 stop charging <-
[lp-1  ] DEBUG 2023/10/05 17:43:55 pv timer reset
[lp-1  ] DEBUG 2023/10/05 17:43:55 pv timer inactive
[lp-1  ] DEBUG 2023/10/05 17:43:55 charge total import: 2449.070kWh

........ Update der Datenbank nach pause_charging - mit einem veralteten Wert
[db    ] TRACE 2023/10/05 17:43:55 UPDATE `sessions` SET `created`="2023-10-05 17:08:45.733",`finished`="2023-10-05 17:43:55.727",`loadpoint`="Wallbox",`identifier`="",`vehicle`="Dacia Spring",`odometer`=421.42,`meter_start_kwh`=2447.606478888886,`meter_end_kwh`=2449.070142499997,`charged_kwh`=1.46366361111086,`charge_duration`="32m40s",`solar_percentage`=99.99999990910158,`price`=0.0000000004341248642687154,`price_per_kwh`=0.0000000002966015285023262,`co2_per_kwh`=NULL WHERE `id` = 132 1 <nil>
[lp-1  ] DEBUG 2023/10/05 17:43:56 soc estimated: 54.00% (vehicle: 54.00%)
[lp-1  ] DEBUG 2023/10/05 17:43:56 vehicle soc: 54%
[lp-1  ] DEBUG 2023/10/05 17:43:56 vehicle range: 129km
[lp-1  ] DEBUG 2023/10/05 17:43:56 pv charge current: 5.24A = 0A + 5.24A (-1206W @ 1p)
....................................
[db    ] TRACE 2023/10/05 17:47:59 INSERT INTO `settings` (`key`,`value`) VALUES ("savings.started","2023-07-16T22:42:54+02:00"),("savings.gridCharged","10.375034751663327"),("savings.gridCost","3.3853738394677495"),("savings.gridSavedCost","106.88848854453533"),("savings.selfConsumptionCharged","390.31812434083525"),("savings.selfConsumptionCost","20.472315427880126"),("vehicle.1.targetSoc","85"),("vehicle.1.targetEnergy","0"),("vehicle.1.minSoc","0"),("vehicle.1.targetTime","0001-01-01T00:00:00Z"),("vehicle.0.targetSoc","85"),("vehicle.0.targetEnergy","0"),("vehicle.0.minSoc","0"),("vehicle.0.targetTime","0001-01-01T00:00:00Z") ON CONFLICT (`key`) DO UPDATE SET `value`=`excluded`.`value` 14 <nil>
....................................
[db    ] TRACE 2023/10/05 19:40:38 SELECT * FROM `sessions` WHERE charged_kwh>=0.05 ORDER BY created DESC 102 <nil>
[site  ] DEBUG 2023/10/05 19:40:45 ----

........ nach 1,25h Leerlauf. Auto wird abgesteckt
[site  ] DEBUG 2023/10/05 19:03:15 ----
[lp-1  ] DEBUG 2023/10/05 19:03:15 charge power: 0W
[site  ] DEBUG 2023/10/05 19:03:15 pv power: 180W
[site  ] DEBUG 2023/10/05 19:03:15 grid power: 1W
[site  ] DEBUG 2023/10/05 19:03:15 grid powers: [-100 72 28]W
[site  ] DEBUG 2023/10/05 19:03:15 grid currents: [-1.04 1.12 0.707]A
[site  ] DEBUG 2023/10/05 19:03:15 site power: 201W
[lp-1  ] DEBUG 2023/10/05 19:03:15 charge currents: [0.011 0.009 0.012]A
[lp-1  ] DEBUG 2023/10/05 19:03:15 charge total import: 2449.244kWh
[lp-1  ] DEBUG 2023/10/05 19:03:15 charger status: B
[lp-1  ] DEBUG 2023/10/05 19:03:15 pv charge current: 0A = 0A + -0.873A (201W @ 1p)
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:00:00 +0000 UTC) ENERGY_PER_HOUR 0

........ und die korrekte geladene Menge SESSION_EBERGY wird im Rahmen des Absteckens empfangen
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) SESSION_ENERGY 1.6375433206558228
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) LEDMODE 18
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) TOTAL_POWER 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) IN_CURRENT_T2 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) IN_CURRENT_T3 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) IN_CURRENT_T4 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) IN_CURRENT_T5 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) OUT_VOLT_PIN1_2 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) OUT_VOLT_PIN1_3 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) OUT_VOLT_PIN1_4 0
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) OUT_VOLT_PIN1_5 0

........ OpMode wird richtig empfangen
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) CHARGER_OP_MODE 1
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) PILOT_MODE A
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) REASON_FOR_NO_CURRENT 50
[easee ] TRACE 2023/10/05 19:03:24 ProductUpdate : (2023-10-05 17:03:23 +0000 UTC) CHARGING_SESSION {"Id":413,"Start":"2023-10-05T15:08:27.000Z","Stop":"2023-10-05T17:03:23.000Z","EnergyKwh":1.637543,"MeterValueStart":2447.606479,"MeterValueStop":2449.244022,"Auth":"userid_","AuthReason":6}

........ Update für "total import" wird (wg. OpMode Wechsel auf 1) angefordert
[easee ] TRACE 2023/10/05 19:03:25 POST https://api.easee.com/api/chargers//commands/poll_lifetimeenergy
[easee ] TRACE 2023/10/05 19:03:25 {"device":"","commandId":2,"ticks":638321222054413360}
[site  ] DEBUG 2023/10/05 19:03:25 ----
[lp-1  ] DEBUG 2023/10/05 19:03:25 charge power: 0W
[site  ] DEBUG 2023/10/05 19:03:25 pv power: 182W
[site  ] DEBUG 2023/10/05 19:03:25 grid power: 0W
[site  ] DEBUG 2023/10/05 19:03:25 grid powers: [-101 72 28]W
[site  ] DEBUG 2023/10/05 19:03:25 grid currents: [-1.04 1.12 0.707]A
[site  ] DEBUG 2023/10/05 19:03:25 site power: 200W
[lp-1  ] DEBUG 2023/10/05 19:03:25 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/10/05 19:03:25 charge total import: 2449.244kWh
[lp-1  ] DEBUG 2023/10/05 19:03:25 charger status: A
[lp-1  ] INFO 2023/10/05 19:03:25 car disconnected
[lp-1  ] INFO 2023/10/05 19:03:25 vehicle updated: Dacia Spring -> unknown
[lp-1  ] DEBUG 2023/10/05 19:03:25 set charge mode: pv
[lp-1  ] DEBUG 2023/10/05 19:03:25 set min current: 6
[lp-1  ] DEBUG 2023/10/05 19:03:25 set max current: 32
[lp-1  ] DEBUG 2023/10/05 19:03:25 set priority: 0

........ und auch empfangen
[easee ] TRACE 2023/10/05 19:03:27 ProductUpdate : (2023-10-05 17:03:25 +0000 UTC) LIFETIME_ENERGY 2449.2440222222194
[easee ] TRACE 2023/10/05 19:03:27 CommandResponse : {SerialNumber: ID:2 Timestamp:2023-10-05 17:03:25.441336 +0000 UTC DeliveredAt:2023-10-05 17:03:25.641 +0000 UTC WasAccepted:true ResultCode:0 Comment: Ticks:638321222054413360}
[easee ] TRACE 2023/10/05 19:03:32 ProductUpdate : (2023-10-05 17:00:00 +0000 UTC) LIFETIME_HOURS 14051
[easee ] TRACE 2023/10/05 19:03:32 ProductUpdate : (2023-10-05 17:00:00 +0000 UTC) LIFETIME_ENERGY 2449.2440222222194
[site  ] DEBUG 2023/10/05 19:03:35 ----
[lp-1  ] DEBUG 2023/10/05 19:03:35 charge power: 0W
[site  ] DEBUG 2023/10/05 19:03:35 pv power: 182W
[site  ] DEBUG 2023/10/05 19:03:35 grid power: 2W

.... aber es folgt kein weiteres, "finales" Update der Datenbank mehr!
GrimmiMeloni commented 1 year ago

Danke für die detaillierte Erklärung @allcoolusernamesaregone.

Generell hast Du erstmal recht, es wird nur bei Stop des Ladevorgangs, nicht aber bei Disconnect geschrieben. Wenn der Charger korrekte Werte liefert, ist das auch ausreichend. Wie Du aber auch sauber dargestellt hast, ist der Wert nach dem pause_charge nicht aktuell.

Jetzt könnten wir zwar relativ einfach die Session noch ein weiteres mal bei Disconnect in der DB aktualisieren (wäre ein 1-Zeiler), aber wir haben dann ein Timingproblem. Der hook der den Disconnect erkennt, läuft in diesem Moment

[lp-1  ] INFO 2023/10/05 19:03:25 car disconnected

Das Update mit dem korrekten finalen Wert kommt aber erst zwei Sekunden später.

[easee ] TRACE 2023/10/05 19:03:27 ProductUpdate : (2023-10-05 17:03:25 +0000 UTC) LIFETIME_ENERGY 2449.2440222222194

Das ist so ohne weiteres auch leider nicht zu lösen. Vielleicht erinnerst Du dich noch: beim PR für #9940 hatte ich zunächst vorgeschlagen auf das LIFETIME_ENERGY update zu warten, mußte dann aber zurückrudern, weil das einen Deadlock gibt (ein ProductUpdate kann nicht auf ein anderes Warten). Genau das bräuchten wir jetzt hier, denn sonst würde ein Update der Session nichts bringen. Wir würden einfach nochmal den veralteten Wert vom Moment der Pause schreiben.

Ach Mann, Easee.... 😩

allcoolusernamesaregone commented 1 year ago

Ja, Easee... das war in meinem Beispiel natürlich auch einfach schlechtes Timing, aber es kommt halt vor. Wie oft - ich weiß es nicht. Mir ist der ganze Missstand vor #9940 auch nur aufgefallen, weil der alte Wert von 11kWh als geladene Menge am Anfang der nächsten Session dargestellt wurde. In die Statistiken selbst schaue ich jetzt auch nicht so wahnsinnig oft rein. Denke aber es summiert sich natürlich zusammen, wenn bis zu 1 kWh fehlt pro Session. 1 kWh daher, da die Easee nach meiner Beobachtung SESSION_ENERGY jeweils spätestens) nach jedem geladenen kWh aktualisiert.

Und es gäbe natürlich noch die Möglichkeiten

Zumindest Variante 2 ist ohne Beeinflussung von EVCC "drumherum" ja probemlos möglich, und hätte in meinem Beispiel hier auch geholfen.

In anderen Beispielen kam das finale Update von LIFETIME_ENERGY nach dem Poll wegen OpMode Änderung ausreichend schnell, um in der Datenbank korrekt gespeichert zu werden.

GrimmiMeloni commented 1 year ago

Zumindest Variante 2 ist ohne Beeinflussung von EVCC "drumherum" ja probemlos möglich, und hätte in meinem Beispiel hier auch geholfen.

Ja dann, ran! 😀 Du weißt ja jetzt wie es geht. Ich freu mich auf einen PR von Dir. 😜

allcoolusernamesaregone commented 1 year ago

10440 - ich denke mehr ist es nicht. Mangels Sonne jetzt aber keine Testserie möglich :-/