Fehler geladene Energie bei Ladevorgänge (mit Log)

EfvonIks commented 6 months ago

Describe the bug

Mir ist aufgefallen, dass bei meinen Ladevorgängen ab und zu die nachgeladene Energie nicht richtig gespeichert wird. Es passiert nur bei 2 aufeinanderfolgende Ladevorgängen und nicht immer.

Ich habe dazu ein paar Screenshots gemacht. Im April hatte ich am 27.04. und am 28.04. 2x die selbe nachgeladene Energie. Da es relativ viel war und ich wusste, dass ich am 28.04. nicht so lange geladen habe, ist mir das komisch vorgekommen. Klicke ich auf den Ladevorgang steht bei Geladen weiterhin 40,5kWh. Bei den Zählerständen sieht man aber direkt, dass die Differenz zwischen den Zählerständen 19,2kWh entsprach, was auch von der Zeit in etwa hinkommt. Am 28.04. hatte ich dann ein zweites Mal geladen und zwar 19,4kWh (laut Historie und auch Zählerstand). Das nächste Mal hatte ich am 1.5. geladen und auch hier wurden mir in der Historie wieder 19,4kWh angezeigt. Auch hier ist mir wieder aufgefallen, dass es mit der Ladezeit (knapp 1h) nicht hinkommt. In den Details sieht man bei den Zählerständen wieder die Differenz von 11,2kWh, was der Ladezeit entspricht.

Installiert hatte ich zu dem Zeitpunkt 0.123.9. Ich habe jetzt auf Version 0.126.1 aktualisiert und schaue ob das Problem weiterhin besteht.

evcc4.log

Steps to reproduce

Bisher lies sich der Bug nicht reproduzieren.

Configuration details

Ist die Konfiguration nötig? Wenn ja, kann ich diese nachreichen.

Log details

Siehe angehängte Datei.

What type of operating system are you running?

Linux

Version

0.123.9

naltatis commented 6 months ago

Hi @EfvonIks bitte ergänze noch Infos zu deiner Konfiguration. Also vor allem Zähler und Wallbox.

EfvonIks commented 6 months ago

Hi @EfvonIks bitte ergänze noch Infos zu deiner Konfiguration. Also vor allem Zähler und Wallbox. Ich verwende als Stromzähler den Tibber Pulse und als Wallbox eine Mennekes Amtron Charge Control.

Hier ist meine Konfiguration. Ich habe die Sponsor- und Tibber-Token hier entfernt.

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

log: debug
levels:
  cache: error

# unique installation id
interval: 10s # control cycle interval

sponsortoken: removed

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

meters:
- type: template
  template: tibber-pulse 
  usage: grid  
  token: removed  
  name: grid1

chargers:
- type: template
  template: bender 
  host: 192.168.0.51  
  port: 502  
  name: wallbox3

vehicles:
- type: template
  template: offline 
  title: EQV300  
  capacity: 90  
  name: ev2
  identifiers: 
    - 04957232707384

loadpoints:
- title: Carport P8
  charger: wallbox3
  vehicle: ev2
  mode: now
  phases: 3
  mincurrent: 6
  maxcurrent: 16

site:
  title: NYR13
  meters:
    grid: grid1

tariffs:
  grid:
    type: tibber
    token: removed

philg1234 commented 6 months ago

Gleiches Problem hatte ich auch bei mir festgestellt. Leider wurde der Issue geschlossen. (https://github.com/evcc-io/evcc/issues/13390)

Nach wie vor besteht das Problem.

Mein Setup:

GoE Ladestation
SMA Anlage
Tesla Model Y

andig commented 6 months ago

@philg1234 Leider? Dein Issue wurde mangels Logfile geschlossen und weil es bei Dir nciht mehr auftrat.

andig commented 6 months ago

@EfvonIks Dein Logfile zeigt:

[lp-1  ] DEBUG 2024/04/27 12:13:12 charge total import: 2740.518kWh
[lp-1  ] DEBUG 2024/04/27 12:13:12 charger status: C
[lp-1  ] INFO 2024/04/27 12:13:12 start charging ->

[lp-1  ] DEBUG 2024/04/27 16:03:32 charge total import: 2781.061kWh
[lp-1  ] DEBUG 2024/04/27 16:03:32 charger status: A
[lp-1  ] INFO 2024/04/27 16:03:32 stop charging <-

[lp-1  ] DEBUG 2024/04/28 08:40:52 charge total import: 2781.085kWh
[lp-1  ] DEBUG 2024/04/28 08:40:52 charger status: C
[lp-1  ] INFO 2024/04/28 08:40:52 start charging ->

[lp-1  ] DEBUG 2024/04/28 10:30:12 charge total import: 2800.337kWh
[lp-1  ] DEBUG 2024/04/28 10:30:12 charger status: A
[lp-1  ] INFO 2024/04/28 10:30:12 stop charging <-

Was es nicht zeigt, ist welche Energiemenge geschrieben wurde (db: trace). Ohne die Information ist aber kein Fehler zu finden.

andig commented 6 months ago

Mit https://github.com/evcc-io/evcc/commit/8ba04a6a2266bf0bad01eccef611bfbdfa7e669d gibts jetzt nochmal mehr Logging im DEBUG Modus. Wir brauchen (leider) ein neues Log, das verwertbare Informationen zeigt.

@naltatis das Zusammenspiel aus Speicherung in Session und Energymetrics und teilweise einem Roundtrip dazwischen ist nicht ganz klar- müssen wir wohl auch nochmal zusammen anschauen (vmtl. https://github.com/evcc-io/evcc/pull/7380).

HaareistNase commented 6 months ago

Ich klemme mich hier mal dazu. Mir ist heute das erste mal eine wirklich "krasse" Lademenge aufgefallen.

[lp-1 ] DEBUG 2024/05/10 15:30:38 pv disable timer remaining: 1m10s [site ] DEBUG 2024/05/10 15:30:46 ---- [lp-1 ] DEBUG 2024/05/10 15:30:47 charge power: 1467W [lp-1 ] DEBUG 2024/05/10 15:30:47 charge currents: [6.04 0.15 0.15]A [site ] DEBUG 2024/05/10 15:30:47 pv power: 2024W [site ] DEBUG 2024/05/10 15:30:48 battery soc: 65% [site ] DEBUG 2024/05/10 15:30:48 battery power: 1340W [site ] DEBUG 2024/05/10 15:30:48 grid meter: 552W [site ] DEBUG 2024/05/10 15:30:48 site power: 2092W [lp-1 ] DEBUG 2024/05/10 15:30:48 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:30:48 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:30:48 charger status: C [lp-1 ] DEBUG 2024/05/10 15:30:48 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:30:49 pv charge current: 0A = 6A + -9.1A (2092W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:30:49 projected site power 2092W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:30:49 pv disable in 1m0s [lp-1 ] DEBUG 2024/05/10 15:30:49 pv disable timer remaining: 1m0s [site ] DEBUG 2024/05/10 15:30:56 ---- [lp-1 ] DEBUG 2024/05/10 15:30:57 charge power: 1458W [lp-1 ] DEBUG 2024/05/10 15:30:57 charge currents: [6.08 0.15 0.15]A [site ] DEBUG 2024/05/10 15:30:57 pv power: 1789W [site ] DEBUG 2024/05/10 15:30:58 battery soc: 65% [site ] DEBUG 2024/05/10 15:30:58 battery power: 2140W [site ] DEBUG 2024/05/10 15:30:59 grid meter: 2208W [site ] DEBUG 2024/05/10 15:30:59 site power: 4548W [lp-1 ] DEBUG 2024/05/10 15:30:59 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:30:59 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:30:59 charger status: C [lp-1 ] DEBUG 2024/05/10 15:30:59 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:30:59 pv charge current: 0A = 6A + -19.8A (4548W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:30:59 projected site power 4548W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:30:59 pv disable in 49s [lp-1 ] DEBUG 2024/05/10 15:30:59 pv disable timer remaining: 49s [site ] DEBUG 2024/05/10 15:31:06 ---- [lp-1 ] DEBUG 2024/05/10 15:31:07 charge power: 1449W [lp-1 ] DEBUG 2024/05/10 15:31:07 charge currents: [6.04 0.15 0.11]A [site ] DEBUG 2024/05/10 15:31:07 pv power: 1644W [site ] DEBUG 2024/05/10 15:31:07 battery soc: 65% [site ] DEBUG 2024/05/10 15:31:07 battery power: 2940W [site ] DEBUG 2024/05/10 15:31:08 grid meter: 6W [site ] DEBUG 2024/05/10 15:31:08 site power: 3146W [lp-1 ] DEBUG 2024/05/10 15:31:08 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:31:08 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:31:08 charger status: C [lp-1 ] DEBUG 2024/05/10 15:31:08 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:31:08 pv charge current: 0A = 6A + -13.7A (3146W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:31:08 projected site power 3146W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:31:08 pv disable in 40s [lp-1 ] DEBUG 2024/05/10 15:31:08 pv disable timer remaining: 40s [site ] DEBUG 2024/05/10 15:31:16 ---- [lp-1 ] DEBUG 2024/05/10 15:31:17 charge power: 1467W [lp-1 ] DEBUG 2024/05/10 15:31:17 charge currents: [6.04 0.15 0.11]A [site ] DEBUG 2024/05/10 15:31:17 pv power: 2097W [site ] DEBUG 2024/05/10 15:31:18 battery soc: 64% [site ] DEBUG 2024/05/10 15:31:18 battery power: 2710W [site ] DEBUG 2024/05/10 15:31:18 grid meter: -117W [site ] DEBUG 2024/05/10 15:31:18 site power: 2793W [lp-1 ] DEBUG 2024/05/10 15:31:18 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:31:18 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:31:18 charger status: C [lp-1 ] DEBUG 2024/05/10 15:31:18 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:31:18 pv charge current: 0A = 6A + -12.1A (2793W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:31:18 projected site power 2793W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:31:18 pv disable in 30s [lp-1 ] DEBUG 2024/05/10 15:31:18 pv disable timer remaining: 30s [site ] DEBUG 2024/05/10 15:31:26 ---- [lp-1 ] DEBUG 2024/05/10 15:31:27 charge power: 1458W [lp-1 ] DEBUG 2024/05/10 15:31:27 charge currents: [6.08 0.15 0.11]A [site ] DEBUG 2024/05/10 15:31:27 pv power: 2954W [site ] DEBUG 2024/05/10 15:31:28 battery soc: 64% [site ] DEBUG 2024/05/10 15:31:28 battery power: 1710W [site ] DEBUG 2024/05/10 15:31:29 grid meter: 0W [site ] DEBUG 2024/05/10 15:31:29 site power: 1910W [lp-1 ] DEBUG 2024/05/10 15:31:29 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:31:29 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:31:29 charger status: C [lp-1 ] DEBUG 2024/05/10 15:31:29 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:31:29 pv charge current: 0A = 6A + -8.3A (1910W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:31:29 projected site power 1910W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:31:29 pv disable in 19s [lp-1 ] DEBUG 2024/05/10 15:31:29 pv disable timer remaining: 19s [site ] DEBUG 2024/05/10 15:31:36 ---- [lp-1 ] DEBUG 2024/05/10 15:31:37 charge power: 1440W [lp-1 ] DEBUG 2024/05/10 15:31:37 charge currents: [6.04 0.11 0.11]A [site ] DEBUG 2024/05/10 15:31:37 pv power: 2768W [site ] DEBUG 2024/05/10 15:31:37 battery soc: 64% [site ] DEBUG 2024/05/10 15:31:37 battery power: 1930W [site ] DEBUG 2024/05/10 15:31:38 grid meter: 26W [site ] DEBUG 2024/05/10 15:31:38 site power: 2156W [lp-1 ] DEBUG 2024/05/10 15:31:38 detected active phases: 1p [lp-1 ] DEBUG 2024/05/10 15:31:38 charge total import: -872461.562kWh [lp-1 ] DEBUG 2024/05/10 15:31:38 charger status: C [lp-1 ] DEBUG 2024/05/10 15:31:38 vehicle soc: 52% [lp-1 ] DEBUG 2024/05/10 15:31:38 pv charge current: 0A = 6A + -9.38A (2156W @ 1p) [lp-1 ] DEBUG 2024/05/10 15:31:38 projected site power 2156W >= 0W disable threshold [lp-1 ] DEBUG 2024/05/10 15:31:38 pv disable in 10s [lp-1 ] DEBUG 2024/05/10 15:31:38 pv disable timer remaining: 10s [site ] DEBUG 2024/05/10 15:31:46 ---- [lp-1 ] DEBUG 2024/05/10 15:31:47 charge power: 1449W [lp-1 ] DEBUG 2024/05/10 15:31:47 charge currents: [6.04 0.15 0.15]A [site ] DEBUG 2024/05/10 15:31:47 pv power: 2670W

grafik

network: schema: http host: evcc.local port: 7070

influx: url: http://xxxxxxxxx database: homeassistant user: xxxxxxx password: xxxxxx

mqtt: broker: xxxxx topic: xxxxx user: xxxxxx password: xxxxx clientid: xxxxxx

log: info levels: site: debug lp-1: debug lp-2: debug cache: error db: error

plant: a34e9891f3f851942995bc6b38eafffd9a2aa49c1787b7ec87d24ac08c8be018

interval: 10s

sponsortoken: xxxxxxxxx

telemetry: true

meters:

type: template template: growatt-hybrid id: 1 usage: grid modbus: tcpip host: xxxxxxx port: 5021 name: grid1
type: template template: growatt-hybrid id: 1 usage: pv modbus: tcpip host: xxxxxx port: 5021 name: pv1
type: template template: growatt-hybrid id: 1 usage: pv modbus: tcpip host: xxxxxx port: 5021 name: pv2
type: template template: growatt-hybrid id: 1 usage: battery modbus: tcpip host: xxxxx port: 5021 capacity: 19.2 name: battery3

chargers:

type: template template: innogy-ebox id: 1 host: xxxxx port: 502 modbus: tcpip name: wallbox5

vehicles:

type: custom identifiers:
- Upita name: ev2 title: E-Up icon: car phases: 3 capacity: 32 soc: source: mqtt topic: export/e-up
type: custom identifiers:
- Penita name: ev1 title: Kia icon: car phases: 3 capacity: 64 soc: source: mqtt topic: export/niro

loadpoints:

title: Front charger: wallbox5 mode: off soc: poll: mode: allways interval: 2m estimate: false

tariffs: currency: EUR grid: type: tibber token: "xxxxxxx" feedin: type: fixed price: 0.068

site: title: My home meters: grid: grid1 pv:

pv1
pv2

battery:
battery3 residualPower: 200 # additional household usage margin maxGridSupplyWhileBatteryCharging: 1000 # ignore battery charging if AC consumption is above this value

Das ganze Konglomerat besteht aus zwei Growatt-Wechselrichtern mit einer Batterie, einem E-Up, einer innogy/e.o.n. eBox professional und hier einem e-Up. ah.. und bitte entschuldigt, ich bin zu blöd den richtigen Code für ein Code-Schnipsel zu finden um log und config vernünftig in den Post zu packen. Hier ist es heute auch relativ wolkig, das Überschussladen springt dauernd an/aus. Eventuell hängt es ja damit zusammen?

andig commented 6 months ago

Es braucht ein Log der Nightly Version mit dem zusätzlichen Logging.

andig commented 5 months ago

Es braucht ein Log der Nightly Version mit dem zusätzlichen Logging.

Bisher kein neues Log. Das Problem scheint also nicht mehr zu existieren?

EfvonIks commented 5 months ago

Bisher nicht. Mit der 0.126.1 ist es mir noch nicht aufgefallen, allerdings ist das Problem bei der älteren Version auch nur sporadisch aufgetreten.

mintert91 commented 5 months ago

Ich habe ein ähnliches Problem festgestellt. Ich nutze die Version 0.126.4 und habe heute Überschussladung gestartet, also mehrere Start und Stopvorgänge am Tag.

Ich hoffe ich habe das richtige Tracefile gefunden.

Aber man sieht auf den Screenshots gut, dass die geladene Energie leider nicht korrekt zusammengerechnet wird.

evcc-20240525-131407-trace.log evcc-20240525-131836-trace.log

andig commented 5 months ago

@mintert91 gibts ein Logfile und eine Konfiguration? Anscheinend startet hier i.S. Session Log jeweils ein "neuer" Ladevorgang ohne die alte Energiemenge abzugrenzen. Wobei auch die "Zählerstände" des alten Ladevorgangs sehr seltsam aussehen.

Wie immer: bitte VOLLSTÄNDIGE Angaben, nicht nur nutzlose Versatzstücke.

hstreitenberger commented 5 months ago

Ich habe das gleiche Problem, aber kein aktuelles Log-File. Die Differenz zwischen den Zählerständen passt nicht. Beim nächsten Mal werde ich Log posten. Ich vermute es tritt bei mir dann auf, wenn man schnell zwischen 2 Fahrzeugen an der Wallbox wechselt.

phrozen77 commented 5 months ago

Ich hab heute laut Wallbox 40,5kWh geladen, laut evcc warens nur 18,6kWh - Version 0.126.6.

Auszug vom Ladeende (gesamtes Log hängt an, recht lang, Tesla API responses hab ich rauseditiert):

Jun 06 15:54:55 evcc evcc[13956]: [site  ] DEBUG 2024/06/06 15:54:55 ----
Jun 06 15:54:55 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:55 charge power: 0W
Jun 06 15:54:55 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:55 charge currents: [0 0 0]A
Jun 06 15:54:56 evcc evcc[13956]: [site  ] DEBUG 2024/06/06 15:54:56 pv power: 536W
Jun 06 15:54:56 evcc evcc[13956]: [site  ] DEBUG 2024/06/06 15:54:56 grid meter: 1118W
Jun 06 15:54:56 evcc evcc[13956]: [site  ] DEBUG 2024/06/06 15:54:56 site power: 1118W
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:56 !! session: chargeRater.chargedEnergy=16.5 - chargedAtStartup=0.0
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:56 charge total import: 3860.920kWh
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:56 charger status: B
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] INFO 2024/06/06 15:54:56 stop charging <-
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:56 charge total import: 3860.920kWh
Jun 06 15:54:56 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:56 !! session: start=3820.409 stop=3860.920 chargedEnergy=18.640
Jun 06 15:54:56 evcc evcc[13956]: [tesla ] TRACE 2024/06/06 15:54:56 GET https://fleet-api.prd.eu.vn.cloud.tesla.com/api/1/vehicles/<VIN>/vehicle_data
Jun 06 15:54:57 evcc evcc[13956]: [tesla ] TRACE 2024/06/06 15:54:57 {"response":
Jun 06 15:54:57 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:57 vehicle status: B
Jun 06 15:54:57 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:57 soc gradient updated: soc: 79.0%, socDiff: 67.0%, energyDiff: 18531Wh, energyPerSocStep: 276.6Wh, virtualCapacity: 27659Wh
Jun 06 15:54:57 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:57 vehicle soc: 79%
Jun 06 15:54:57 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:57 vehicle soc limit: 100%
Jun 06 15:54:57 evcc evcc[13956]: [lp-1  ] DEBUG 2024/06/06 15:54:57 vehicle range: 335km

Config:

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

log: debug
levels:
  cache: error
  lp-1: trace
  tesla: trace

# unique installation id
plant: plantid

interval: 10s # control cycle interval

#sponsortoken: altertoken
sponsortoken: aktuellertoken

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

meters:
- type: template
  template: fronius-solarapi-v1 
  usage: grid  
  host: 192.168.222.9
  name: grid1
- type: template
  template: fronius-solarapi-v1 
  usage: pv  
  host: 192.168.222.9  
  name: pv2
- type: template
  template: tibber-pulse
  usage: grid
  name: tibber
  token: "token"
  homeid: "homeid"

chargers:
- type: template
  template: go-e-v3 
  host: 192.168.222.104  
  name: wallbox3

loadpoints:
- title: Go-E
  charger: wallbox3
  mode: off
  phases: 0
  mincurrent: 6
  maxcurrent: 16

site:
  title: Dahoam
  meters:
    grid: grid1
    pv:
    - pv2

tariffs:
  grid:
    type: tibber
    token: "token"
    homeid: "homeid"
  feedin:
    type: fixed
    price: 0.0712

vehicles:
  - name: Tesla
    type: template
    template: tesla-command
    accessToken: "token"
    refreshToken: "token"
    title: Tesla_Model_3
    capacity: 60

Ich hoffe inständig, dass man da was rauslesen kann - falls es noch irgendwie (für zukünftige Ladevorgänge) weitere trace/debug Konfigurationseinträge braucht, gerne mit Hinweis für was genau und wie :)

evcc_0606.log

cc @andig

andig commented 5 months ago

Also die gute Nachricht: das Problem ist erkennbar. Yeah!:

2024/06/06 06:34:46 !! session: chargeRater.chargedEnergy=0.0 - chargedAtStartup=0.0
2024/06/06 06:34:46 charge total import: 3820.411kWh
2024/06/06 06:34:46 charger status: C

2024/06/06 15:54:56 stop charging <-
2024/06/06 15:54:56 charge total import: 3860.920kWh
2024/06/06 15:54:56 !! session: start=3820.409 stop=3860.920 chargedEnergy=18.640

~~Jetzt müssen wir nur rausfinden wo das passiert.~~ Das Problem sind die Ladepausen:

2024/06/06 08:05:48 !! session: chargeRater.chargedEnergy=3.6 - chargedAtStartup=0.0
2024/06/06 08:05:48 charge total import: 3823.950kWh
2024/06/06 08:05:48 charger status: B

2024/06/06 08:05:48 wake-up timer: start
2024/06/06 08:05:48 charge total import: 3823.950kWh
2024/06/06 08:05:48 !! session: chargedEnergy=3.6 > chargedEnergy=0.0

06/06 08:05:57 site power: -4254W
2024/06/06 08:05:57 charge total import: 3823.950kWh
2024/06/06 08:05:57 charger status: C

2024/06/06 08:06:08 !! session: chargeRater.chargedEnergy=0.0 - chargedAtStartup=0.0
2024/06/06 08:06:08 charge total import: 3823.950kWh
2024/06/06 08:06:08 charger status: C

/cc @naltatis

andig commented 5 months ago

@phrozen77 leider fehl im Log der go-e und die DB. Diese Zeilen zeigen aber eindeutig, dass die geladene Energiemenge wieder auf 0 zurück geht:

2024/06/06 08:05:48 !! session: chargeRater.chargedEnergy=3.6 - chargedAtStartup=0.0
2024/06/06 08:06:08 !! session: chargeRater.chargedEnergy=0.0 - chargedAtStartup=0.0

Ich tippe auf den Go-E, kann man aber nur raten...

andig commented 5 months ago

Tatsächlich klingt das ein wenig nach https://github.com/evcc-io/evcc/pull/14048. Das ist catch22, siehe Diskussion in dem PR.

phrozen77 commented 5 months ago

Also die gute Nachricht: das Problem ist erkennbar. Yeah!:

Sehr gut :)

Das Problem sind die Ladepausen:

Das trifft auch meine Beobachtung - und je öfter die Ladepause (bei Phasenwechsel) auftritt, umso größer ist die Wahrscheinlichkeit hier - oft reicht aber auch schon einer...

Die Annahme, dass der Go-E die Verbindung verliert (wie im verlinkten PR diskutiert) - mhh, glaub ich nicht, aber mal sehen...

leider fehl im Log der go-e und die DB.

Ich hab jetzt mal die db und den go-e auf trace gesetzt und einen Ladevorgang gestartet.

Ich geb gegen Nachmittag Bescheid und häng ggf. das Log hier rein :)

Edit: natürlich passt heute alles - ich melde mich aber ASAP, sobald ich ein Log mit dem Problem hab!

andig commented 5 months ago

Merker: prüfen ob Sessionenergie kleiner wird und/oder ob Delta Zählerstände grösser Sessionenergie.

premultiply commented 5 months ago

Ich würde vorschlagen die von einem LP gelieferte Sessionenergie ausschließlich als Hilfsgröße für zu diesem Zeitpunkt bereits laufende Sessions beim Start von evcc zu verwenden ansonsten immer nur den Zählerstand bzw. die Differenz zwischen aktuellem Zählerstand und dem vom Start der Session.

andig commented 5 months ago

Gute Idee. Ich meine mich aber zu erinnern (tm) dass wir tw. Sessionenergie in höherer Auflösung als Zählerstände gesehen haben?

premultiply commented 5 months ago

Irgendwas ist immer... 🙄

Das könnten wir bei tatsächlichem Bedarf im Einzelfall aber in der konkreten Implementierung abfangen.

kad49007 commented 5 months ago

Anbei zwei Screenshots aus den Ladelogs meines Wattpiloten. Das gleiche sollte auch für die Go-e-Charger gehen.

Leider komme ich aber nicht an die Rohdaten aus den Ladelogs für die Sessionenergie ran.

Zuerst ein Beispiel mit Auswertung der Sessionenergy durch evcc. Laut evcc wurden 21,8 kWh geladen, laut Ladelog des Chargers 41,998kWh 5A547460-8E9D-44C1-9193-9E9F6455CB98

Hier ein Beispiel mit Auswertung der Gesamtzähler des Wattpilot durch evcc wie in #14048 vorgeschlagen, da passt die geladene Energie zwischen Ladelog des Chargers zu evcc-Ladelog (20,912kWh)

4F090CC7-B18A-43EA-8C20-24672189D12B

Das Log des letzen Ladevorgangs habe ich auch angehängt. Das andere Log ist leider schon überschrieben. Ein Verbingsabbruch habe ich auf die Schnelle nicht gefunden, aber eine Ladeunterbrechung. Laut Graphik wurde danach die Sessionenergy zurückgesetzt. Nicht so schön... evcc_09_06_24.log

phrozen77 commented 5 months ago

@andig so, hier ein frisches Log mit go-e und db auf trace - ich hoffe, man kann daran das Problem erkennen

evcc 0.127.1, WB Zählerstand Start: 3931,9kWh - Zählerstand Ende: 3966,7kWh - somit geladen: 34,8kWh - evcc sagt 25,5kWh (Config zur davor geposteten unverändert bis auf die Änderung der Loglevel)

Jun 16 14:04:51 evcc evcc[18996]: [lp-1 ] DEBUG 2024/06/16 14:04:51 !! session: start=3931.870 stop=3966.742 chargedEnergy=25.502

Danke schon mal im Voraus für die Analyse!

evcc_1606.log

phrozen77 commented 5 months ago

Interessanterweise (vermutlich hat sich da in Home Assistant etwas geändert) habe ich heute und beim letzten Mal auch im Energiedashboard Sprünge in den gemonitorten Werten, das ist bislang noch nicht aufgetreten (eine Erklärung habe ich dafür aber nicht).

Zwei Graphen von heute:

sensor.goechargernummer_eto

sensor.goechargernummer_wh

Ich hatte bislang den "_wh" Sensor im Energiedashboard verarbeitet - was mir jetzt erst auffällt ist, das letzterer als "state_class: total" angegeben ist, während ersterer eigentlich der korrekte wäre (state_class: total_increasing).

Das jetzt nur als Randnotiz, keine Ahnung ob das irgendwie hilft - falls nicht, einfach ignorieren.

kjs-DE commented 5 months ago

Das Problem sieht so aus wie bei mir auch. Passiert nur im Stotterbetrieb (also mit Unterbrechung durch zu wenig PV). EM2GO Wallbox und für den Rest Sonnenbatterie. Auch jetzt mit 0.127.1 (auf RP4) nicht anders und sowohl beim Enyaq als auch beim Tesla M3. Keine einzige Fehlermeldung Im Log sieht man die Abfrage der Wallbox mit richtigen Spannungs- und Stromwerten sowie auch der Leistung und der Energiezähler bleibt einfach hängen.

Vadus commented 4 months ago

Hi, vermutlich habe ich hier dasselbe Problem gemeldet https://github.com/evcc-io/evcc/discussions/14394 .

Durch eine weitere Konfiguration an evcc habe ich dann das Aufkommen von Ladepausen reduziert und seit dem tauchte das Problem bei mir nicht mehr auf.

andig commented 4 months ago

ich hoffe, man kann daran das Problem erkennen

@phrozen77 Dein Log hat mehrere Ladevorgänge. Welcher ist der fehlerhafte? Es skaliert leider nicht, wenn ich mir die Problemfälle erst selbst aus 50tsd Zeilen raus suchen muss.

andig commented 4 months ago

Geht es um den 7:40? Dann sehe ich:

Auto lädt 1p:

[lp-1  ] DEBUG 2024/06/16 07:45:50 !! session: chargeRater.chargedEnergy=0.4 - chargedAtStartup=0.0
[lp-1  ] DEBUG 2024/06/16 07:45:50 charge total import: 3932.256kWh
[lp-1  ] DEBUG 2024/06/16 07:45:50 charger status: C
[lp-1  ] DEBUG 2024/06/16 07:45:50 available power 4166W > 4140W min 3p threshold
[lp-1  ] DEBUG 2024/06/16 07:45:50 phase scale3p in 0s
[lp-1  ] DEBUG 2024/06/16 07:45:50 pv charge current: 18.6A = 16A + 2.55A (-587W @ 1p)

Phasenumschaltung:

[lp-1  ] DEBUG 2024/06/16 07:46:11 charger status: B
[lp-1  ] INFO 2024/06/16 07:46:11 stop charging <-
[lp-1  ] DEBUG 2024/06/16 07:46:11 charge total import: 3932.266kWh
[lp-1  ] DEBUG 2024/06/16 07:46:11 !! session: chargedEnergy=0.4 > chargedEnergy=0.0
[lp-1  ] DEBUG 2024/06/16 07:46:11 !! session: start=3931.870 stop=3932.266 chargedEnergy=0.398
[db    ] TRACE 2024/06/16 07:46:11 UPDATE `sessions` SET `created`="2024-06-16 07:36:30.02",`finished`="2024-06-16 07:46:11.575",`loadpoint`="Go-E",`identifier`="",`vehicle`="Tesla_Model_3",`odometer`=28909.72237274035,`meter_start_kwh`=3931.87,`meter_end_kwh`=3932.266,`charged_kwh`=0.3978473,`charge_duration`="9m42s",`solar_percentage`=96.27723397296174,`price`=0.029987032354287953,`price_per_kwh`=0.07537322071630988,`co2_per_kwh`=NULL WHERE `id` = 189 1 <nil>
[lp-1  ] DEBUG 2024/06/16 07:46:19 !! session: chargeRater.chargedEnergy=0.0 - chargedAtStartup=0.0

Sessionenergie ist jetzt wie 0 obwohl das Auto nicht abgesteckt wurde- schlecht :(

FAZIT

Ich denke für die Charger, bei denen die Sessionenergie blöderweise nicht beim Disconnect, sondern bei Statusänderung zurück gesetzt wird sollten wir api.ChargeRater entfernen. Das betrifft go-e, wattpilot und bender.

@premultiply ok?

phrozen77 commented 4 months ago

Dein Log hat mehrere Ladevorgänge. Welcher ist der fehlerhafte? Es skaliert leider nicht, wenn ich mir die Problemfälle erst selbst aus 50tsd Zeilen raus suchen muss.

Oh. Ist schon wieder ein paar Tage her, bin grad nur mit Handy unterwegs - dachte aber das ist eigentlich auf einen (langen) Ladevorgang eingekürzt 🤔

Geht es um den 7:40? Dann sehe ich:

Dürfte der sein, ja 👍

JoernHei commented 4 months ago

Gute Idee. Ich meine mich aber zu erinnern (tm) dass wir tw. Sessionenergie in höherer Auflösung als Zählerstände gesehen haben?

Hallo Andig, Du hattest recht mit Deiner Vermutung: Die Auflösung beträgt jetzt 1 kWh ohne Nachkommastellen. In der v0.127.3 wurden durch Evcc noch die alten Werte angezeigt. Kann ich irgendwo hinterlegen, dass weiterhin die Werte mit Nachkommastellen genutzt werden? Die Wallbox ist eine Go-e V2 und gibt auch in der App für den Gesamtzähler nur ganze kWh aus.

andig commented 4 months ago

Tja :( https://github.com/evcc-io/evcc/pull/14730 löst das Problem, hat aber eben Nebenwirkungen. Irgendwas ist immer...

evcc-io / evcc