search

evcc-io / evcc

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

Loadpoint enable delay skipped #14833

Closed waynistan closed 3 months ago

waynistan commented 3 months ago

Describe the bug

Hallo, in den letzten Wochen ist mir manchmal aufgefallen, dass der enable-delay nicht abgewartet wird und evcc sofort die Ladung startet, nach nur einem Update mit genug Überschussleistung. Solange kein Fahrzeug angeschlossen ist frage ich auch keine Daten vom Wechselrichter ab und leite stattdessen über MQTT jeweils den Wert 0 an evcc weiter für grid / pv / battery / soc. Sobald ein Auto angeschlossen ist (tagsüber & Ladeziel nicht erreicht) bekommt evcc aktuelle Messwerte vom Wechselrichter. MaxCurrent, residualPower und die enable- / disableThresholds passe ich ebenfalls über MQTT an das ausgewählte Fahrzeug an, da deren tatsächliche Ladeleistung sich um mehrere 100 Watt unterscheidet (das sieht man in dem Log-Abschnitt den ich reinkopiert habe). In dem Fall wurde manuell auf Gastfahrzeug umgestellt und kurz darauf passen sich per MQTT die genannten Werte an und evcc bekommt danach echte Wechselrichter-Messwerte. Anstatt nun die eingestellten 119s zu warten legt evcc sofort mit der Ladung los. Evtl. ist das Überschreiben des enableThresholds über MQTT schuld? Kann das leider heute nicht mehr überprüfen...

Steps to reproduce

1. 2. 3. ...

Configuration details

network:
  port: 7070

interval: 10s

sponsortoken: -

meters:
- name: my_grid
  type: custom
  power:
    source: mqtt
    topic: grid/power
    scale: -1
    timeout: 3s
- name: my_pv
  type: custom
  power:
    source: mqtt
    topic: pv/power
    timeout: 3s
- name: my_battery
  type: custom
  power:
    source: mqtt
    topic: battery/power
    timeout: 3s
  soc:
    source: mqtt
    topic: battery/soc
    timeout: 3s
  capacity: 9.83

chargers:
- name: mennekes_amtron_charge_control
  type: template
  template: bender
  host: 192.168.178.44
  port: 502

vehicles:
- name: opel_corsa_e
  type: template
  template: flobz
  title: Corsa-e
  url: http://127.0.0.1:5000
  vin: -
  capacity: 43.5

site:
- title: Home
  meters:
    grid: my_grid
    pv: my_pv
    battery: my_battery
  residualPower: 200

loadpoints:
- title: Wallbox
  charger: mennekes_amtron_charge_control
  vehicle: opel_corsa_e
  mode: pv
  soc:
    poll:
      mode: charging
      interval: 1000h
    estimate: true
  enable:
    threshold: -3800
    delay: 119s
  disable:
    threshold: 199
    delay: 89s
  guardduration: 299s

mqtt:
  broker: 127.0.0.1:1883
  topic: evcc
  user: -
  password: -

log: debug

Log details

[site  ] DEBUG 2024/07/11 12:08:45 ----
[lp-1  ] DEBUG 2024/07/11 12:08:45 charge power: 0W
[lp-1  ] DEBUG 2024/07/11 12:08:45 charge currents: [0.004 0.004 0.003]A
[site  ] DEBUG 2024/07/11 12:08:45 pv power: 0W
[site  ] DEBUG 2024/07/11 12:08:45 battery soc: 0%
[site  ] DEBUG 2024/07/11 12:08:45 battery power: 0W
[site  ] DEBUG 2024/07/11 12:08:45 grid meter: -0W
[site  ] DEBUG 2024/07/11 12:08:45 site power: 200W
[lp-1  ] DEBUG 2024/07/11 12:08:45 charge voltages: [235 236 236]V
[lp-1  ] DEBUG 2024/07/11 12:08:45 detected connected phases: 3p
[lp-1  ] DEBUG 2024/07/11 12:08:45 charge total import: 4833.881kWh
[lp-1  ] DEBUG 2024/07/11 12:08:45 charger status: B
[lp-1  ] DEBUG 2024/07/11 12:08:45 limitSoc reached: 85.0% > 60%
[lp-1  ] INFO 2024/07/11 12:08:52 vehicle updated: Corsa-e -> unknown
[lp-1  ] DEBUG 2024/07/11 12:08:52 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger)
[lp-1  ] DEBUG 2024/07/11 12:08:52 set enable threshold: -4200
[lp-1  ] DEBUG 2024/07/11 12:08:53 set max current: 16
[site  ] DEBUG 2024/07/11 12:08:55 ----
[lp-1  ] DEBUG 2024/07/11 12:08:55 charge power: 0W
[lp-1  ] DEBUG 2024/07/11 12:08:55 charge currents: [0.001 0.004 0.003]A
[site  ] DEBUG 2024/07/11 12:08:55 pv power: 14759W
[site  ] DEBUG 2024/07/11 12:08:55 battery soc: 100%
[site  ] DEBUG 2024/07/11 12:08:55 battery power: 0W
[site  ] DEBUG 2024/07/11 12:08:55 grid meter: -13842W
[site  ] DEBUG 2024/07/11 12:08:55 site power: -13642W
[lp-1  ] DEBUG 2024/07/11 12:08:55 charge voltages: [235 236 236]V
[lp-1  ] DEBUG 2024/07/11 12:08:55 detected connected phases: 3p
[lp-1  ] DEBUG 2024/07/11 12:08:55 charge total import: 4833.881kWh
[lp-1  ] DEBUG 2024/07/11 12:08:55 charger status: B
[lp-1  ] DEBUG 2024/07/11 12:08:55 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger)
[lp-1  ] DEBUG 2024/07/11 12:08:55 pv charge current: 19.8A = 0A + 19.8A (-13642W @ 3p)
[lp-1  ] DEBUG 2024/07/11 12:08:55 site power -13642W <= -4200W enable threshold
[lp-1  ] DEBUG 2024/07/11 12:08:55 pv enable in 0s
[lp-1  ] DEBUG 2024/07/11 12:08:55 pv enable timer elapsed
[lp-1  ] DEBUG 2024/07/11 12:08:55 max charge current: 6A
[lp-1  ] DEBUG 2024/07/11 12:08:55 charger enable
[lp-1  ] DEBUG 2024/07/11 12:08:55 wake-up timer: start

What type of operating system are you running?

HomeAssistant Add-on

Version

0.128.2

naltatis commented 3 months ago

Hi, um das bearbeiten zu können, müssen wir das reproduzierbar haben. Wäre gut, wenn du den Effekt isolieren könntest. Gerade weil dein Setup mit MQTT und externer Steuerung ja etwas spezieller ist. Ich mach hier daher erstmal zu. Aber füg gerne neuen Infos an, wenn du hast und dann machen wir den wieder auf.

waynistan commented 3 months ago

Ja, ich werde versuchen, das ganze noch weiter zu beobachten. Problematisch ist nur, dass über Home Assistant immer nur die letzten 1-2 Minuten des Logs abrufbar sind, also muss ich live dabei sein... Mir ist aufgefallen, dass seit ein paar Versionen die 0en im UI auch als 0en angezeigt werden. "Früher" wurde da "keine Messwerte" o.ä. angezeigt, könnte zeitlich hinkommen mit dem übersprungenem enable-Delay Fehler. Andererseits überschreibe ich auch erst seit einigen Wochen u.a. den enable-Threshold, das könnte halt auch passen.

naltatis commented 3 months ago

Problematisch ist nur, dass über Home Assistant immer nur die letzten 1-2 Minuten des Logs abrufbar sind, also muss ich live dabei sein...

Über den evcc Log Viewer müsstest du deutlich mehr (10k Einträge) bekommen.

waynistan commented 3 months ago

Problematisch ist nur, dass über Home Assistant immer nur die letzten 1-2 Minuten des Logs abrufbar sind, also muss ich live dabei sein...

Über den evcc Log Viewer müsstest du deutlich mehr (10k Einträge) bekommen.

Den Log Viewer habe ich noch gar nicht bemerkt, danke für den Tipp. Gerade mal geschaut, reicht etwa 25 Minuten zurück, das ist schonmal wesentlich angenehmer als die 1,x Minuten über Home Assistant ;D

waynistan commented 3 months ago

Möglicherweise handelt es sich nur um ein Initialisierungsproblem des pvTimers. Es kann gut sein, dass jedes Mal, wo bei mir das Problem aufgetaucht ist evcc vorher kein einziges Mal die resetPVTimer()-Funktion aufgerufen hat, da das Standardfahrzeug sein Ladelimit erreicht hatte und das Gastfahrzeug dann sofort beim ersten Refresh zur Mittagszeit genug Leistung zur Verfügung hatte. Hatte zuletzt auch häufiger evcc neu gestartet, wegen Änderungen der Config und evcc-Updates, deswegen könnte der Fall tatsächlich öfter aufgetreten sein. Wenn's stimmt, ist es natürlich nur ein relativ irrelevantes Problem, aber vielleicht lässt sich der Timer ja beim Start von evcc resetten und selbst dieser Fall wäre dann abgedeckt.

Im folgenden Log sieht man, wie beim ersten Wechsel aufs Gastfahrzeug der Timer resettet wird, beim zweiten Wechsel dann nicht mehr, weil die resetPVTimer()-Funktion einfach sofort returned.

[main ] INFO 2024/07/12 00:54:34 evcc 0.128.2 [main ] INFO 2024/07/12 00:54:34 using config file: /config/evcc.yaml [db ] INFO 2024/07/12 00:54:34 using sqlite database: /data/evcc.db [mqtt ] INFO 2024/07/12 00:54:34 connecting evcc-1150975679 at tcp://127.0.0.1:1883 [mqtt ] DEBUG 2024/07/12 00:54:35 tcp://127.0.0.1:1883 connected [main ] INFO 2024/07/12 00:54:35 listening at :7070 [lp-1 ] DEBUG 2024/07/12 00:54:35 charge total import: 4846.524kWh [site ] INFO 2024/07/12 00:54:36 site config: [site ] INFO 2024/07/12 00:54:36 meters: grid ✓ pv ✓ battery ✓ [site ] INFO 2024/07/12 00:54:36 grid: power ✓ energy ✗ currents ✗ [site ] INFO 2024/07/12 00:54:36 pv 1: power ✓ energy ✗ currents ✗ [site ] INFO 2024/07/12 00:54:36 battery 1: power ✓ energy ✗ currents ✗ soc ✓ capacity ✓ [site ] INFO 2024/07/12 00:54:36 vehicles: [site ] INFO 2024/07/12 00:54:36 vehicle 1: range ✓ finish ✗ status ✓ climate ✓ wakeup ✓ [lp-1 ] INFO 2024/07/12 00:54:36 loadpoint 1: [lp-1 ] INFO 2024/07/12 00:54:36 mode: pv [lp-1 ] INFO 2024/07/12 00:54:36 charger: power ✓ energy ✓ currents ✓ phases ✗ wakeup ✗ [lp-1 ] INFO 2024/07/12 00:54:36 meters: charge ✓ [lp-1 ] INFO 2024/07/12 00:54:36 charge: power ✓ energy ✓ currents ✓ [site ] DEBUG 2024/07/12 00:54:36 set buffer soc: 95 [site ] DEBUG 2024/07/12 00:54:36 set buffer start soc: 0 [site ] DEBUG 2024/07/12 00:54:36 set priority soc: 30 [site ] DEBUG 2024/07/12 00:54:36 set residual power: 100 [lp-1 ] DEBUG 2024/07/12 00:54:36 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:54:36 phase timer inactive [lp-1 ] DEBUG 2024/07/12 00:54:36 pv timer inactive [lp-1 ] INFO 2024/07/12 00:54:36 vehicle updated: unknown -> Corsa-e [lp-1 ] DEBUG 2024/07/12 00:54:36 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [site ] WARN 2024/07/12 00:54:36 interval <30s can lead to unexpected behavior, see https://docs.evcc.io/docs/reference/configuration/interval [site ] DEBUG 2024/07/12 00:54:36 ---- [lp-1 ] DEBUG 2024/07/12 00:54:36 charge power: 0W [lp-1 ] DEBUG 2024/07/12 00:54:36 charge currents: [0.004 0.004 0.004]A [site ] DEBUG 2024/07/12 00:54:36 pv power: 0W [site ] DEBUG 2024/07/12 00:54:36 battery soc: 0% [site ] DEBUG 2024/07/12 00:54:36 battery power: 0W [site ] DEBUG 2024/07/12 00:54:36 grid meter: -0W [site ] DEBUG 2024/07/12 00:54:36 site power: 100W [lp-1 ] DEBUG 2024/07/12 00:54:36 vehicle odometer: 17277km [lp-1 ] DEBUG 2024/07/12 00:54:36 charge voltages: [232 232 231]V [lp-1 ] DEBUG 2024/07/12 00:54:36 detected connected phases: 3p [lp-1 ] DEBUG 2024/07/12 00:54:36 charge total import: 4846.524kWh [lp-1 ] DEBUG 2024/07/12 00:54:36 charger status: B [lp-1 ] DEBUG 2024/07/12 00:54:36 charge start energy: 4.85e+03kWh [lp-1 ] INFO 2024/07/12 00:54:36 car connected [lp-1 ] DEBUG 2024/07/12 00:54:36 pv timer elapse [lp-1 ] DEBUG 2024/07/12 00:54:36 pv timer inactive [lp-1 ] DEBUG 2024/07/12 00:54:36 charge total import: 4846.524kWh [lp-1 ] DEBUG 2024/07/12 00:54:36 vehicle status: A [lp-1 ] DEBUG 2024/07/12 00:54:36 vehicle soc: 80% [lp-1 ] DEBUG 2024/07/12 00:54:36 vehicle range: 248km [lp-1 ] DEBUG 2024/07/12 00:54:36 limitSoc reached: 80.0% > 60% [lp-1 ] DEBUG 2024/07/12 00:54:37 set max current: 15 [lp-1 ] INFO 2024/07/12 00:54:41 vehicle updated: Corsa-e -> unknown [lp-1 ] DEBUG 2024/07/12 00:54:41 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:54:41 set enable threshold: -4300 [lp-1 ] DEBUG 2024/07/12 00:54:41 set max current: 16 [site ] DEBUG 2024/07/12 00:54:45 ---- [lp-1 ] DEBUG 2024/07/12 00:54:45 charge power: 0W [lp-1 ] DEBUG 2024/07/12 00:54:45 charge currents: [0.003 0.004 0.004]A [site ] DEBUG 2024/07/12 00:54:45 pv power: 0W [site ] DEBUG 2024/07/12 00:54:45 battery soc: 0% [site ] DEBUG 2024/07/12 00:54:45 battery power: 0W [site ] DEBUG 2024/07/12 00:54:45 grid meter: -0W [site ] DEBUG 2024/07/12 00:54:45 site power: 100W [lp-1 ] DEBUG 2024/07/12 00:54:45 charge voltages: [232 232 232]V [lp-1 ] DEBUG 2024/07/12 00:54:45 detected connected phases: 3p [lp-1 ] DEBUG 2024/07/12 00:54:45 charge total import: 4846.524kWh [lp-1 ] DEBUG 2024/07/12 00:54:45 charger status: B [lp-1 ] DEBUG 2024/07/12 00:54:45 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:54:45 pv charge current: 0A = 0A + -0.145A (100W @ 3p) [lp-1 ] DEBUG 2024/07/12 00:54:45 pv enable timer reset [lp-1 ] DEBUG 2024/07/12 00:54:45 pv timer inactive [lp-1 ] INFO 2024/07/12 00:54:49 vehicle updated: unknown -> Corsa-e [lp-1 ] DEBUG 2024/07/12 00:54:49 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:54:49 set enable threshold: -3900 [lp-1 ] DEBUG 2024/07/12 00:54:50 set max current: 15 [site ] DEBUG 2024/07/12 00:54:54 ---- [lp-1 ] DEBUG 2024/07/12 00:54:54 charge power: 0W [lp-1 ] DEBUG 2024/07/12 00:54:54 charge currents: [0.003 0.003 0.004]A [site ] DEBUG 2024/07/12 00:54:54 pv power: 0W [site ] DEBUG 2024/07/12 00:54:54 battery soc: 0% [site ] DEBUG 2024/07/12 00:54:54 battery power: 0W [site ] DEBUG 2024/07/12 00:54:54 grid meter: -0W [site ] DEBUG 2024/07/12 00:54:54 site power: 100W [lp-1 ] DEBUG 2024/07/12 00:54:54 vehicle odometer: 17277km [lp-1 ] DEBUG 2024/07/12 00:54:54 charge voltages: [232 232 231]V [lp-1 ] DEBUG 2024/07/12 00:54:54 detected connected phases: 3p [lp-1 ] DEBUG 2024/07/12 00:54:54 charge total import: 4846.524kWh [lp-1 ] DEBUG 2024/07/12 00:54:54 charger status: B [lp-1 ] DEBUG 2024/07/12 00:54:54 vehicle status: A [lp-1 ] DEBUG 2024/07/12 00:54:54 vehicle soc: 80% [lp-1 ] DEBUG 2024/07/12 00:54:54 vehicle range: 248km [lp-1 ] DEBUG 2024/07/12 00:54:54 limitSoc reached: 80.0% > 60% [lp-1 ] INFO 2024/07/12 00:54:59 vehicle updated: Corsa-e -> unknown [lp-1 ] DEBUG 2024/07/12 00:54:59 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:54:59 set enable threshold: -4300 [lp-1 ] DEBUG 2024/07/12 00:55:00 set max current: 16 [site ] DEBUG 2024/07/12 00:55:03 ---- [lp-1 ] DEBUG 2024/07/12 00:55:03 charge power: 0W [lp-1 ] DEBUG 2024/07/12 00:55:03 charge currents: [0.005 0.004 0.003]A [site ] DEBUG 2024/07/12 00:55:03 pv power: 0W [site ] DEBUG 2024/07/12 00:55:03 battery soc: 0% [site ] DEBUG 2024/07/12 00:55:03 battery power: 0W [site ] DEBUG 2024/07/12 00:55:03 grid meter: -0W [site ] DEBUG 2024/07/12 00:55:03 site power: 100W [lp-1 ] DEBUG 2024/07/12 00:55:03 charge voltages: [232 232 231]V [lp-1 ] DEBUG 2024/07/12 00:55:03 detected connected phases: 3p [lp-1 ] DEBUG 2024/07/12 00:55:03 charge total import: 4846.524kWh [lp-1 ] DEBUG 2024/07/12 00:55:03 charger status: B [lp-1 ] DEBUG 2024/07/12 00:55:03 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) [lp-1 ] DEBUG 2024/07/12 00:55:03 pv charge current: 0A = 0A + -0.145A (100W @ 3p)

waynistan commented 3 months ago

Ich lag falsch, denn heute hat die Ladung wieder sofort begonnen, ohne dass evcc vorher keine Gelegenheit gehabt hätte den pvTimer zu resetten. Stattdessen ist mir sowohl im Log als auch im Code aufgefallen, dass das Verhalten offenbar beabsichtigt ist. Die Zeilen 488 und 489 in loadpoint.go deuten klar darauf hin: // immediately allow pv mode activity lp.elapsePVTimer()

Dann wäre meine Frage, aus welchem Grund ist das so? Die Absicht hinter den (enable & disable) Delays ist es Schaltvorgänge bei sehr wechselhaftem PV-Überschuss zu vermeiden, wozu braucht man da diese Ausnahme von der Regel?