evcc-io / evcc

Sonne tanken ☀️🚘
https://evcc.io
MIT License
3.6k stars 670 forks source link

Easee: api commands ignored #8398

Closed BAltmiks closed 1 year ago

BAltmiks commented 1 year ago

Describe the bug

After Updating from 0.117.4 to 0.118.0:

In Min + PV Mode the loadpoint (charger Easee Home) loads with full power (20A) instead of min. Power (6A) continuously. Expected is min. Power (6A) as it was with 0.117.4

In PV Mode and if bufferSoc is configured (for example with 80%) the loadpoint (charger Easee Home) loads always with full power (20A) instead of minimum Power (6A) continuously, even if there is not enough production. Expected is min. Power (6A) as it was with 0.117.4.

EVCC

Steps to reproduce

  1. Update from 0.117.4 to 0.118.0
  2. ...

Configuration details

# open evcc at http://evcc.local:7070
network:
  schema: http
  host: evcc.local # .local suffix announces the hostname on MDNS
  port: 7070

log: error
levels:
  cache: error

# unique installation id
plant: XXXXXXX

interval: 10s # control cycle interval

sponsortoken: eyJhbGciOiJIUzI1NiIsInR5cXXXXXXXXXXXXXXcreateYourOwn

# sponsors can set telemetry: true to enable anonymous data aggregation
# see https://github.com/evcc-io/evcc/discussions/4554
telemetry: true

meters:
- type: template
  template: varta 
  usage: grid  
  host: 192.168.188.59  
  port: 502  
  name: grid1
- type: template
  template: varta 
  usage: pv  
  host: 192.168.188.59  
  port: 502  
  name: pv2
- type: template
  template: varta 
  usage: battery  
  host: 192.168.188.59  
  port: 502  
  name: battery3
- type: template
  template: sunspec-inverter 
  id: 1  
  host: 192.168.188.61  
  port: 502  
  usage: pv  
  modbus: tcpip  
  name: pv4

chargers:
- type: template
  template: easee 
  user: XXXXXX 
  password: XXXXX
  charger: XXXXX 
  name: wallbox5

vehicles:
- type: template
  template: enyaq 
  title: SkodaEnyaqAdesso  
  user: XXXXX
  password: XXXXXX 
  vin: XXXXX
  capacity: 82  
  name: ev5
  targetSoc: 80
  icon: car

loadpoints:
- title: Garage
  charger: wallbox5
  mode: pv
  phases: 1
  mincurrent: 6
  maxcurrent: 20
  resetOnDisconnect: true

site:
  title: Mein Zuhause
  meters:
    grid: grid1
    pv:
    - pv2
    - pv4
    battery:
    - battery3
  residualPower: 300  
  prioritySoc: 70

tariffs:
  currency: EUR
  grid:
    type: fixed
    price: 0.3977
  feedin:
    type: fixed
    price: 0.06
  planner:
    type: grünstromindex
    zip: 33129

Log details

[main  ] INFO 2023/06/10 17:32:46 evcc 0.118.0
[main  ] INFO 2023/06/10 17:32:46 using config file: /etc/evcc.yaml
[main  ] INFO 2023/06/10 18:22:58 evcc 0.118.0
[main  ] INFO 2023/06/10 18:22:58 using config file: /etc/evcc.yaml
[main  ] INFO 2023/06/10 18:30:23 evcc 0.118.0
[main

What type of operating system are you running?

Docker container

Version

0.118.0

kai-morich commented 1 year ago

same issue for me with easee charger.

log file contains switching from aus to min+pv resulting in loading with 16A instead of expected 6A note: log output is reversed and prefixed with timestamp by synology nas

evcc.yaml.txt evcc.log.txt

kai-morich commented 1 year ago

here logs for previous version with expected behavior: evcc-0.117.4.log.txt

JMueller86 commented 1 year ago

Same here. It was working fine until the update. Now always full power. Home Assistant + Heidelberg via MQTT

artspe commented 1 year ago

Easee and evcc 0.118 same issue. Now in PV and Min+PV Mode loading with 16A instead of 6A.

andig commented 1 year ago

It's a wellknown problem with the Easee api ignoring commands.

Schlichi83 commented 1 year ago

I have the same problem

andig commented 1 year ago

Kann ab morgen im nightly getestet werden.

jheinitz commented 1 year ago

Moin! Habe das Docker Image schon heute lokal gebaut und getestet. Bei mir lief der Ladevorgang ganz normal. Das einzig Merkwürdige ist, dass ich immer mal wieder einige current mismatch Einträge im Log sehe. Aber das ist anscheinend genau das Problem, das hier adressiert wird, oder?

jens@server2:/opt/evcc$ docker logs evcc | grep misma
[easee ] DEBUG 2023/06/12 13:13:45 current mismatch, expected 6.0, got 16.0
[easee ] DEBUG 2023/06/12 13:17:35 current mismatch, expected 6.0, got 32.0
[easee ] DEBUG 2023/06/12 13:18:21 current mismatch, expected 12.0, got 6.0
[easee ] DEBUG 2023/06/12 13:19:21 current mismatch, expected 6.0, got 32.0
[easee ] DEBUG 2023/06/12 13:19:41 current mismatch, expected 6.0, got 8.0
[easee ] DEBUG 2023/06/12 13:33:41 current mismatch, expected 6.0, got 9.0
[easee ] DEBUG 2023/06/12 13:34:03 current mismatch, expected 9.0, got 11.0
[easee ] DEBUG 2023/06/12 13:37:42 current mismatch, expected 9.0, got 7.0
[easee ] DEBUG 2023/06/12 13:44:00 current mismatch, expected 8.0, got 9.0
[easee ] DEBUG 2023/06/12 14:12:20 current mismatch, expected 7.0, got 6.0
[easee ] DEBUG 2023/06/12 14:12:40 current mismatch, expected 6.0, got 7.0
[easee ] DEBUG 2023/06/12 14:44:20 current mismatch, expected 6.0, got 32.0
[easee ] DEBUG 2023/06/12 14:44:41 current mismatch, expected 6.0, got 14.0
[easee ] DEBUG 2023/06/12 14:45:00 current mismatch, expected 14.0, got 15.0
[easee ] DEBUG 2023/06/12 14:46:00 current mismatch, expected 14.0, got 15.0
[easee ] DEBUG 2023/06/12 14:46:20 current mismatch, expected 15.0, got 14.0
[easee ] DEBUG 2023/06/12 14:50:42 current mismatch, expected 14.0, got 7.0
[easee ] DEBUG 2023/06/12 14:54:41 current mismatch, expected 6.0, got 14.0
[easee ] DEBUG 2023/06/12 14:57:00 current mismatch, expected 8.0, got 9.0
[easee ] DEBUG 2023/06/12 15:03:40 current mismatch, expected 6.0, got 8.0
[easee ] DEBUG 2023/06/12 15:06:41 current mismatch, expected 6.0, got 16.0
jens@server2:/opt/evcc$

Nur komisch, dass die Meldungen auch kommen, wenn zwar das Auto angeschlossen ist, aber nicht geladen wird, weil das Auto Fahrzeuglimit von 80% erreicht hat.

Auf jeden Fall DANKE für euren tollen Job und die Spitzen-Software. Hut ab!

Ciao Jens

kai-morich commented 1 year ago

1p3p Umschaltung kann ich derzeit nicht testen, es scheint zuviel Sonne. Das nightly zeigt aber andere Probleme. Es werden permanent smartCharging:true POST requests abgesetzt die timeouts erzeugen:

[site  ] DEBUG 2023/06/12 16:27:08 ----
[lp-1  ] DEBUG 2023/06/12 16:27:08 charge power: 4694W
[site  ] DEBUG 2023/06/12 16:27:08 static grid tariff
[site  ] DEBUG 2023/06/12 16:27:08 pv power: 5523W
[site  ] DEBUG 2023/06/12 16:27:08 grid power: -499W
[site  ] DEBUG 2023/06/12 16:27:08 site power: -499W
[lp-1  ] DEBUG 2023/06/12 16:27:08 charge currents: [6.66 6.71 6.68]A
[lp-1  ] DEBUG 2023/06/12 16:27:08 detected active phases: 3p
[lp-1  ] DEBUG 2023/06/12 16:27:08 charge meter total import: 1405.067kWh
[easee ] TRACE 2023/06/12 16:27:08 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:08 {"smartCharging":true}
--
[]
[easee ] TRACE 2023/06/12 16:27:09 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:09 {"smartCharging":true}
--
[]
[easee ] TRACE 2023/06/12 16:27:10 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:10 {"smartCharging":true}
--
[]
[easee ] WARN 2023/06/12 16:27:11 smart charging: timeout
[lp-1  ] DEBUG 2023/06/12 16:27:11 charger status: C
[lp-1  ] DEBUG 2023/06/12 16:27:11 vehicle soc: 62%
[lp-1  ] DEBUG 2023/06/12 16:27:11 vehicle soc limit: 90%
[lp-1  ] DEBUG 2023/06/12 16:27:11 vehicle range: 321km
[lp-1  ] DEBUG 2023/06/12 16:27:11 pv charge current: 7.72A = 7A + 0.723A (-499W @ 3p)
[site  ] DEBUG 2023/06/12 16:27:18 ----
[lp-1  ] DEBUG 2023/06/12 16:27:18 charge power: 4694W
[site  ] DEBUG 2023/06/12 16:27:18 static grid tariff
[site  ] DEBUG 2023/06/12 16:27:18 pv power: 5523W
[site  ] DEBUG 2023/06/12 16:27:18 grid power: -545W
[site  ] DEBUG 2023/06/12 16:27:18 site power: -545W
[lp-1  ] DEBUG 2023/06/12 16:27:18 charge currents: [6.66 6.71 6.68]A
[lp-1  ] DEBUG 2023/06/12 16:27:18 detected active phases: 3p
[lp-1  ] DEBUG 2023/06/12 16:27:18 charge meter total import: 1405.067kWh
[easee ] TRACE 2023/06/12 16:27:18 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:18 {"smartCharging":true}
--
[]
[easee ] TRACE 2023/06/12 16:27:19 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:19 {"smartCharging":true}
--
[]
[easee ] TRACE 2023/06/12 16:27:20 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 16:27:20 {"smartCharging":true}
--
[]
[easee ] WARN 2023/06/12 16:27:21 smart charging: timeout
[lp-1  ] DEBUG 2023/06/12 16:27:21 charger status: C
[lp-1  ] DEBUG 2023/06/12 16:27:21 vehicle soc: 62%
[lp-1  ] DEBUG 2023/06/12 16:27:21 vehicle soc limit: 90%
[lp-1  ] DEBUG 2023/06/12 16:27:21 vehicle range: 321km
[lp-1  ] DEBUG 2023/06/12 16:27:21 pv charge current: 7.79A = 7A + 0.79A (-545W @ 3p)
kai-morich commented 1 year ago

smart_charging und enabled Zustand sind irgendwie nicht in sync. Habe easee und evcc restarted, anbei die logs direkt danach: evcc.smart_charging_init.log.txt

kai-morich commented 1 year ago

dies wahrscheinlich das Problem von @jheinitz mit etwas mehr traces:

[lp-1  ] DEBUG 2023/06/12 17:26:18 pv charge current: 16.3A = 6A + 10.3A (-2375W @ 1p)
[easee ] TRACE 2023/06/12 17:26:18 POST https://api.easee.com/api/chargers/EHCUMYZ7/settings
[easee ] TRACE 2023/06/12 17:26:18 {"dynamicChargerCurrent":16}
--
[{"device":"EHCUMYZ7","commandId":48,"ticks":638221803786325060}]
[easee ] TRACE 2023/06/12 17:26:19 ProductUpdate EHCUMYZ7: REASON_FOR_NO_CURRENT 25
[easee ] TRACE 2023/06/12 17:26:19 ProductUpdate EHCUMYZ7: DYNAMIC_CHARGER_CURRENT 16
[easee ] DEBUG 2023/06/12 17:26:19 current mismatch, expected 6.0, got 16.0
[easee ] TRACE 2023/06/12 17:26:19 ProductUpdate EHCUMYZ7: NUMBER_OF_CARS_CHARGING 1
[easee ] TRACE 2023/06/12 17:26:19 ProductUpdate EHCUMYZ7: NUMBER_OF_CARS_FULLY_CHARGED 0
[easee ] TRACE 2023/06/12 17:26:19 CommandResponse EHCUMYZ7: {SerialNumber:EHCUMYZ7 ID:48 Timestamp:2023-06-12 15:26:18.632506 +0000 UTC DeliveredAt:2023-06-12 15:26:17.938 +0000 UTC WasAccepted:true ResultCode:0 Comment: Ticks:638221803786325060}
[lp-1  ] DEBUG 2023/06/12 17:26:19 max charge current: 16A
jheinitz commented 1 year ago

Sag mal @kai-morich , was hast Du denn als interval: konfiguriert. Sieht mir nach einem sehr kleinen Wert aus. Ich habe bei mir 20s. Testen kann ich jetzt aber auch nicht mehr, weil das Auto voll ist. Kann aber bei Bedarf im Laufe der Woche mit log.easee: trace laufen lassen.

kai-morich commented 1 year ago

ich hab interval: 10s

andig commented 1 year ago

@GrimmiMeloni sollen wir erstmal zurück drehen? Wie schätzt Du smartCharging ein? Die Funktion ist nur optisch- kurzfristig deaktivieren oder PR im nightly reverten? /cc @naltatis

kai-morich commented 1 year ago

retry+timeout-Logik in postJSONAndWait scheint noch Eintrübungen zu haben. Betrifft nicht nur smartCharging sondern auch enable, siehe evcc.smart_charging_init.log.txt. Durch den timeout Fehler wird der neue Zustand nicht gesetzt und immer wieder probiert.

Ich vermute das Easee nicht wirklich Befehle vergisst, sondern das bei paralleler Ausführung halt nur einer davon wirkt. Ich würde es erst mal ohne retry aber mit strikter Serialisierung durch das waitForTickResponse probieren.

andig commented 1 year ago

Betrifft nicht nur smartCharging sondern auch enable, ... Durch den timeout Fehler wird der neue Zustand nicht gesetzt und immer wieder probiert.

Das ist ja auch das Wunschverhalten, hat hier aber Nebenwirkungen. Bliebe nur länger zu warten, ist aber ein weiteres Argument für revert- passiert hiermit: 1ba4698b8b85ebb7913d5d440fa91bd6b42ca945

kai-morich commented 1 year ago

bei Timeout nach den eigentlich vorgesehenen 10 Sekunden wäre ein retry wirklich sinnvoll, momentan kommt der timeout-Fehler aber sofort.

GrimmiMeloni commented 1 year ago

Der enable() geht schief, weil wir nie eine Info bekommen das der Charger bereits beim Start Enabled ist. Die Easee API ist so gestrickt, das sie bei /settings nur dann Kommandos an den Charger senden, wenn sich Ihrer(!) Meinung nach eine Änderung ergibt. Wie wir mittlerweile gelernt haben beisst sich das aber mit paralleler Ausführung.

Die Lösung scheint mir relativ einfach. Serialisierung via active wait wie gebaut drin lassen, aber eine leere Antwort sollte kein Fehler darstellen und muß auch keinen Retry auslösen. So lange wir Kommandos nacheinander senden, sollten sich keine Abweichungen zwischen unserem State und dem der Cloud API ergeben. Wir können aber auch nicht wirklich viel machen wenn es anders kommt, da die Easee API unsere Aufrufe ggf. als unnötig filtert und nicht an den Charger weitersendet.

Ich passe den PR entsprechend an.

andig commented 1 year ago

So lange wir Kommandos nacheinander senden

Das machen wir immer.

aber eine leere Antwort sollte kein Fehler darstellen und muß auch keinen Retry auslösen

Woran würdest Du das fest machen?

Vorschlag zur Abschichtung:

Letztlich sollte Enable auch noch sicherstellen, dass es einfach gar keine Aktion auslöst falls wir schon im Zielzustand sind- dessen Abfrage haben wir ja über Enabled() schon, vielleicht hilft das auch nochmal Konflikte zu vermeiden.

Danke, dass Du es nochmal versuchst... nur halb funktionsfähige Api mit dünner Doku ist undankbar...

GrimmiMeloni commented 1 year ago

Woran würdest Du das fest machen?

An der API Dokumentation. 😉 So langsam kommt jetzt ja endlich Licht ins Dunkel. Ich habe ursprünglich angenommen, das die API Aufrufe verschluckt, wenn sie eine leere Antwort sendet. Mittlerweile ist klar geworden, das diese nicht verschluckt, sondern bewusst verworfen werden, wenn Easee glaubt das gesendete Setting sei keine Änderung. Bevor wir die Serialisierung der Kommandos eingebaut haben, ist es somit zur Race Condition zwischen /settings und pause/start Kommandos gekommen, weil beide den internen State auf Easee Seite verändern. Wir testen mal den Fix - wenn das nicht klappt können immer noch "Abschichten".

andig commented 1 year ago

An der API Dokumentation.

Hättest Du mal einen Link?

Mittlerweile ist klar geworden, das diese nicht verschluckt, sondern bewusst verworfen werden, wenn Easee glaubt das gesendete Setting sei keine Änderung.

Das dürfte bei Enable() nicht vorkommen da der Loadpoint keine Änderung schickt wenn keine erforderlich ist. Ausnahme: der Request ist noch bei Easee in flight und das Ergebnis noch nicht wieder via SignalR angekommen.

GrimmiMeloni commented 1 year ago

An der API Dokumentation.

Hättest Du mal einen Link?

Klaro. Einstieg hier. Direkter Link zum Charger settings Aufruf hier.

Mittlerweile ist klar geworden, das diese nicht verschluckt, sondern bewusst verworfen werden, wenn Easee glaubt das gesendete Setting sei keine Änderung.

Das dürfte bei Enable() nicht vorkommen da der Loadpoint keine Änderung schickt wenn keine erforderlich ist. Ausnahme: der Request ist noch bei Easee in flight und das Ergebnis noch nicht wieder via SignalR angekommen.

Korrekt, in Bezug auf den ersten Teil in Enable der das Setting enabled schreibt.

Der zweite Part in Enable(), der das Resume Kommando schickt, kann Inkonsistenzen erzeugen, weil es den Charger Current eigenständig setzt. Da wir vor #8307 nicht auf die Bestätigung der Kommandos gewartet haben, hat Loadpoint.setLimit() beim Ladestart immer zwei Aufrufe gegen die Easee API hintereinander losgeschickt (/setting für Dynamic Charger Current und resumeCharging Kommando). Somit waren dann 2 Aufrufe parallel unterwegs, die beide Dynamic Charger Current verändern.

Wir bekommen sogar für beide Änderungen des Charger Currents ein Product Update zurück. Aber es ist nicht sichergestellt, daß die Reihenfolge der Product Updates auf evcc Seite auch der Ausführungsreihenfolge auf dem Charger entspricht. Außerdem speichern wir zwar im Charger den zuletzt gesehen Wert für Charger Current, aber wir verwenden den außer zum Trägern der Warnung nicht. (Stichwort: fehlender Rückkanal zum LP). So gesehen ist der gesamte Rückkanal über das Product Update zwar informativ, hilft aber nicht ggf. Schießstände zu erkennen.

Wir haben jetzt zwei Kommandos A & B, die asynchron ausgeführt werden, und für die wir Rückmeldung A' & B' ebenfalls asynchron erhalten. Wenn Kommando A das Setting für Dynamic Current und B das Resume Command ist, können dabei folgende Szenarien auftreten.

Verarbeitung      Empfang Reply       Zustand Loadpoint        Zustand Charger        Charger Phsyik

A,B                  A', B'                     6A                    32A                   32A
A,B                  B', A'                     6A                     6A                   32A
B,A                  B', A'                     6A                     6A                    6A
B,A                  A', B'                     6A                    32A                    6A

Immer wenn Zustand Loadpoint und Charger Physik ungleich sind, haben wir Fehlverhalten. Auch der erste Fall der einer vollen Serialisierung entspricht ist nicht sauber. Deswegen habe ich https://github.com/GrimmiMeloni/evcc/blob/30f32a1dcc9787bfeda7029b08a904fa93efccf6/charger/easee.go#LL406C1-L409C3 eingebaut.

Ich bin fest davon überzeugt das die Serialisierung hier Abhilfe schafft.

andig commented 1 year ago

Aber es ist nicht sichergestellt, daß die Reihenfolge der Product Updates auf evcc Seite auch der Ausführungsreihenfolge auf dem Charger entspricht.

Das ist... superschlau :(

andig commented 1 year ago

Gibts Feedback? Funktioniert es jetzt reproduzierbar besser?

kai-morich commented 1 year ago

Läuft damit wieder problemfrei. Hatte vor 0.118 aber auch schon seit längerem keine Probleme mehr.

jheinitz commented 1 year ago

Das Auto lädt gerade, aber die Sonne scheint zu viel, so dass es aktuell keinen Phasenswitch gibt. Beobachte weiter ....

naltatis commented 1 year ago

Same here. Ich hatte bislang auch kein Probleme. Gerade folgt die Ladung erwartungskonform der Sonnenkurve auf 3p. Phasenumschaltung wird später aber kommen. Ich berichte ...

GrimmiMeloni commented 1 year ago

Bin morgen wieder zu Hause und kann laden. Habe den nightly vom Donnerstag probiert, da war alles gut.

andig commented 1 year ago

Bisher gabs keine neuen Beschwerden. Sieht gut aus 👍🏻

naltatis commented 1 year ago

Ja, auch am Tag zwei keine Probleme bei mir. Mehrere Phasenumschaltungen und An/Ausvorgänge sind wie erwartet gelaufen. 💚

GrimmiMeloni commented 1 year ago

Hier funktioniert es auch weiterhin.

jheinitz commented 1 year ago

Heute hat der Enyaq um 11:00 Uhr angefangen zu laden. Jetzt ist er bei 72% und lädt immer noch einphasig mit 1,9 kW. Alles super. Ihr seid spitze! Danke!

tapwork commented 4 months ago

@andig @naltatis Ich weiß, der Bug scheint schon gefixt. aber was war denn der Grund, warum die Easee API die commands schluckt? Ich konnte aus der Diskussion hier nicht so richtig entnehmen, was die Lösung ist. Ich habe leider auch den Effekt bei SolarDashboard, dass start_charging ignoriert wird, obwohl ein HTTP 202 zurück kommt, was angeblich der success case ist.

naltatis commented 4 months ago

@tapwork Ich würde sagen, "it's complicated" 😅. Die REST Endpunkte triggern nur Aktionen und sind asynchron. Die Bestätigung, dass diese Aktion auch vom Gerät durchgeführt wurde, gibts später per SignalR (siehe Code bspw. waitForTickResponse). Und dann gibts noch die Fälle, wo auch das nicht immer sauber funktioniert 🙈. @GrimmiMeloni ist hier am tiefsten im Thema.

tapwork commented 4 months ago

@naltatis oh man. ich habe bisher noch nicht gesehen, dass einer meiner commands oder "Aktionen" ein Laden gestartet haben. Ich habe eh das Gefühl, dass meine Box gar nicht per Wifi oder LTE erreichbar ist. kann mich mit der Easee auch nicht über Wifi connecten. Insgesamt ist die Easee Documentation auch sehr dürftig und chaotisch. Ich habe die mal vom Support angeschrieben, immerhin sind die sehr responsive.

GrimmiMeloni commented 4 months ago

Nataltis hat es gut zusammengefasst.

Zu deinem letzten Kommentar: Wenn Dein Charger keine stabile Verbindung hat, wird es heftigst Probleme geben. Dann ist kaum noch vorhersehbar welcher Zustand wo vorherrscht. Es ist quasi garantiert das Client (evcc, aber auch Easee App), Server (Easee Cloud) und Charger nicht synchron sind und das System sich unvorhersehbar verhält.

tapwork commented 4 months ago

ok da ist die go-e charger API doch wesentlich besser. danke schon mal für die Hinweise