Charging with KEBA is not stopped, if mode is set to "stop" in gui

KanteTaete commented 3 years ago

Describe the bug If the charging mode is switched from "Nur PV" (only PV) to "Stop" in the GUI, charging continues and is not stopped

To Reproduce Steps to reproduce the behavior:

Go to the GUI, charging is ongoing in 'Nur PV' (only PV) mode
Click on 'Stop'
Charging should stopp, but in the 'Fahrzeug' (vehicle) information, still 'lädt' (charging) is shown
See error

Expected behavior Charging should stopp if it's selected in the GUI.

EVCC details: Show output of evcc -v:

evcc version 0.56 (cad5996)

Show evcc configuration file evcc.yaml:

uri: xxx.xxx.xxx.xxx:7070 # uri for ui
interval: 10s # control cycle interval

log: debug
levels:
  core: debug
  lp-1: debug
  lp-2: fatal

meters:
- name: grid
  type: default
  power:
    type: calc
    add:
    - type: modbus
      value: Power
      model: sunspec
      uri: xxx.xxx.xxx.xxx:502 # Wechselrichter
      id: 126
      scale: -1
    - type: http
      uri: http://xxx.xxx.xxx:8081/xxx
      jq: .data[0].tuples[0][1] #parste response json
      scale: 0.01
# Berechnung: grid = xxx - Wechselrichter

- name: pv
  type: default
  power:
    type: modbus
    value: Power
    model: sunspec
    uri: xxx.xxx.xxx.xxx:502 # Wechselrichter
    id: 126

chargers:
- name: keba
  type: keba
  uri: xxx.xxx.xxx.xxx

site:
  title: xxx
  meters:
    grid: grid
    pv: pv # pv meter

loadpoints:
- title: Garage # display name for UI
  charger: keba # charger
  mode: pv
  soc:
    min: 0 # immediately charge to 0% regardless of mode unless "off" (disabled)
    target: 100 # always charge to 100%
    estimate: false # set true to interpolate between api updates
    levels: # target soc levels for UI
    - 30
    - 50
    - 80
    - 100
  onDisconnect: # set defaults when vehicle disconnects
    mode: pv # switch back to pv mode
    targetSoC: 100 # charge to 100%
  phases: 2 # ev phases (default 3)
  enable: # pv mode enable behavior
    delay: 1m # threshold must be exceeded for this long
    threshold: -2800 # minimum export power (W). If zero, export must exceed minimum charge power to enable
  disable: # pv mode disable behavior
    delay: 5m # threshold must be exceeded for this long
    threshold: 200 # maximum import power (W)
  guardduration: 10m # switch charger contactor not more often than this (default 10m)
  mincurrent: 0 # minimum charge current (default 6A)
  maxcurrent: 16 # maximum charge current (default 16A)

Show evcc log output with --log error:

[lp-1  ] INFO 2021/06/11 14:18:02 set charge mode: off
[lp-1  ] DEBUG 2021/06/11 14:18:03 charge power: 3801W
[lp-1  ] DEBUG 2021/06/11 14:18:03 charge currents: [8.28 8.19 0]A
[lp-1  ] DEBUG 2021/06/11 14:18:03 detected phases: 2p [8.28 8.19 0]A
[lp-1  ] DEBUG 2021/06/11 14:18:03 charger status: C
[lp-1  ] DEBUG 2021/06/11 14:18:03 charger vehicle id: 0000000000000000
[lp-1  ] DEBUG 2021/06/11 14:18:03 max charge current: 0
[lp-1  ] DEBUG 2021/06/11 14:18:09 charge power: 3824W
[lp-1  ] DEBUG 2021/06/11 14:18:09 charge currents: [8.27 8.2 0]A
[lp-1  ] DEBUG 2021/06/11 14:18:09 detected phases: 2p [8.27 8.2 0]A
[lp-1  ] DEBUG 2021/06/11 14:18:09 charger status: C
[lp-1  ] DEBUG 2021/06/11 14:18:09 charger vehicle id: 0000000000000000

Some more detailed report from a later analysis:

Show evcc log output with --log trace:

[lp-1  ] DEBUG 2021/06/11 14:54:54 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/11 14:54:54 send to xxx.xxx.xxx.xxx:7090 report 2
[keba  ] TRACE 2021/06/11 14:54:54 recv from xxx.xxx.xxx.xxx:7090 {
"ID": "2",
"State": 3,
"Error1": 0,
"Error2": 0,
"Plug": 7,
"AuthON": 0,
"Authreq": 0,
"Enable sys": 1,
"Enable user": 1,
"Max curr": 16000,
"Max curr %": 266,
"Curr HW": 16000,
"Curr user": 16000,
"Curr FS": 0,
"Tmo FS": 0,
"Curr timer": 7595,
"Tmo CT": 0,
"Setenergy": 0,
"Output": 0,
"Input": 0,
"Serial": "xxxxxxxx",
"Sec": 1373381
}
[lp-1  ] DEBUG 2021/06/11 14:54:54 max charge current: 0
[keba  ] TRACE 2021/06/11 14:54:54 send to xxx.xxx.xxx.xxx:7090 curr 0
[keba  ] TRACE 2021/06/11 14:54:54 recv from xxx.xxx.xxx.xxx:7090 TCH-OK :done
[cache ] TRACE 2021/06/11 14:54:54 chargeCurrent: 0
[cache ] TRACE 2021/06/11 14:54:54 remoteDisabled: 
[keba  ] TRACE 2021/06/11 14:54:56 recv from xxx.xxx.xxx.xxx:7090 {"E pres": 60283}
[keba  ] TRACE 2021/06/11 14:54:56 recv: listener blocked
[modbus] TRACE 2021/06/11 14:54:59 modbus: closing connection due to idle timeout: 5.000101031s
[keba  ] TRACE 2021/06/11 14:55:00 recv from xxx.xxx.xxx.xxx:7090 {"Max curr": 6000}
[keba  ] TRACE 2021/06/11 14:55:00 recv: listener blocked
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {"E pres": 60379}
[keba  ] TRACE 2021/06/11 14:55:02 recv: listener blocked
[site  ] DEBUG 2021/06/11 14:55:02 ----
[modbus] ...
[site  ] DEBUG 2021/06/11 14:55:02 pv power: 7890W
[cache ] TRACE 2021/06/11 14:55:02 pvPower: 7890
[modbus] ... read pv power from inverter
[http  ] ... read site power via vzlogger
[site  ] DEBUG 2021/06/11 14:55:02 grid power: -177W
[site  ] DEBUG 2021/06/11 14:55:02 site power: -177W
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 3
[cache ] TRACE 2021/06/11 14:55:02 gridPower: -176.8800000000001
[cache ] TRACE 2021/06/11 14:55:02 mode: off
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
"ID": "3",
"U1": 236,
"U2": 236,
"U3": 237,
"I1": 6041,
"I2": 6008,
"I3": 0,
"P": 2811389,
"PF": 985,
"E pres": 60384,
"E total": xxxxxxx,
"Serial": "xxxxxxxx",
"Sec": 1373390
}
[lp-1  ] DEBUG 2021/06/11 14:55:02 charge power: 2811W
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 3
[cache ] TRACE 2021/06/11 14:55:02 chargePower: 2811.389
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
...
}
[lp-1  ] DEBUG 2021/06/11 14:55:02 charge currents: [6.04 6.01 0]A
[lp-1  ] DEBUG 2021/06/11 14:55:02 detected phases: 2p [6.04 6.01 0]A
[cache ] TRACE 2021/06/11 14:55:02 chargeCurrents: [6.041 6.008 0]
[cache ] TRACE 2021/06/11 14:55:02 activePhases: 2
[cache ] TRACE 2021/06/11 14:55:02 chargeCurrent: 0
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 3
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
...
}
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 2
[cache ] TRACE 2021/06/11 14:55:02 chargedEnergy: 6038.400000000001
[cache ] TRACE 2021/06/11 14:55:02 chargeDuration: 2m10s
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
...
}
[lp-1  ] DEBUG 2021/06/11 14:55:02 charger status: C
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 100
[cache ] TRACE 2021/06/11 14:55:02 connected: true
[cache ] TRACE 2021/06/11 14:55:02 charging: true
[cache ] TRACE 2021/06/11 14:55:02 enabled: true
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
"ID": "100",
...
}
[lp-1  ] DEBUG 2021/06/11 14:55:02 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/11 14:55:02 send to xxx.xxx.xxx.xxx:7090 report 2
[keba  ] TRACE 2021/06/11 14:55:02 recv from xxx.xxx.xxx.xxx:7090 {
"ID": "2",
"State": 3,
"Error1": 0,
"Error2": 0,
"Plug": 7,
"AuthON": 0,
"Authreq": 0,
"Enable sys": 1,
"Enable user": 1,
"Max curr": 6000,
"Max curr %": 100,
"Curr HW": 16000,
"Curr user": 6000,
"Curr FS": 0,
"Tmo FS": 0,
"Curr timer": 7595,
"Tmo CT": 0,
"Setenergy": 0,
"Output": 0,
"Input": 0,
"Serial": "xxxxxxxx",
"Sec": 1373390
}

andig commented 3 years ago

/cc @mark-sch

KanteTaete commented 3 years ago

Please find below some details of my analysis and some information from the KEBA manual which indicates, that the method of stopping charging can't work as implemented.

[keba ] TRACE 2021/06/11 14:54:54 send to xxx.xxx.xxx.xxx:7090 curr 0

It looks as if evcc sets the current 'correctly' to 0A.

[keba ] TRACE 2021/06/11 14:55:00 recv from xxx.xxx.xxx.xxx:7090 {"Max curr": 6000}

But the charger (KEBA) doesn't stop charging then but reduces to the minimum charging current of 6A.

Furthermore, the manual from KEBA says:

In general, it is not recommended to use the curr command, since the current can be easily controlled via the non-permanent currtime.

Command structure: Command: curr [c] Parameters: [c]: Current setting Additional Description: Current value in mA, Possible values: 6000 - 63000

--> so the minimum current which can be set is 6A.

In contrast, with currtime as recommended, the charging can be stopped as well:

Command: currtime [c] [t] Parameters: [c]: Current setting Current value in mA. Additional Description: Possible values: 0; 6000 - 63000 Parameters: [t]: Time delay Additional Description: Timeout in seconds before the current will be applied. Possible values: 0; 1 - 860400. Values higher than 860400 will be discarded.

Would a change to that command be needed?

andig commented 3 years ago

curr hat bisher funktioniert. Dein Log zeigt nirgendwo, welche Daten egtl. an die KEBA geschickt werden, ohne lässt sich auch nicht sagen warum das nicht funktionieren sollte.

andig commented 3 years ago

Nutzt du rfid?

andig commented 3 years ago

ping @KanteTaete

KanteTaete commented 3 years ago

Sorry, wurde von github nicht über die neuen Kommentare informiert... also weiter auf deutsch...

Dein Log zeigt nirgendwo, welche Daten egtl. an die KEBA geschickt werden

doch, hier: [keba ] TRACE 2021/06/11 14:54:54 send to xxx.xxx.xxx.xxx:7090 curr 0

Nein, rfid nuze ich nicht. Das Manual sagt aber ganz klar, dass es nicht funktionieren kann. Gibt's denn jemanden, der mit einer aktuellen Keba WB prüfen kann, ob es dort funktioniert?

andig commented 3 years ago

Das Manual sagt aber ganz klar, dass es nicht funktionieren kann.

Genau deshalb machen wir das ja auch nciht so: https://github.com/andig/evcc/blob/master/charger/keba.go#L231. Du hast in Deinem Log irgendeinen irrelevanten Teil rausgegriffen und machst daran einen Fehler fest den es so nicht gibt :(

andig commented 3 years ago

@mark-sch kannst Du hier Licht ins Dunkel bringen?

andig commented 3 years ago

Da uns hier ein aussagekräftiges Logfile fehlt mache ich mal zu. Gerne mit Log einschl. der ENA Statements wieder öffnen.

mark-sch commented 3 years ago

@andig Kann das Problem auch nicht nachvollziehen, habe ja einige Kebas im Einsatz.

KanteTaete commented 3 years ago

Schade, dass Ihr die Issues so schnell schließt. Da kommt man ja zeitlich nicht mal dazu, die gewünschten Daten zur Verfügung zu stellen... :-(

Jedenfalls ist in den mir derzeit zur Verfügung stehenden Logs kein ena-Kommando enthalten, der betreffende Log ist aber auch nicht vollständig. Da mein Raspi derzeit spinnt, kann ich den vermutlich auch nicht innerhalb von ein paar Stunden zur Verfügung stellen. Sobald ich einen vollständigen Trace-Log habe, werde ich den dahingehend nochmals untersuchen und zur Verfügung stellen.

Was mir allerdings aufgefallen ist in der https://github.com/andig/evcc/blob/master/charger/keba.go#L224: var d int if enable { d = 1 }

Die Variable "d" wird definiert und wenn "enable" true ist, wird diese auf 1 gesetzt. Im Falle von "enable = false" wird diese aber nie auf 0 gesetzt.

Frage: Wird die Variable bei der Definition automatisch mit "0" initialisiert?

...mit Go kenne ich mich nicht aus und bei anderen Programmiersprachen ist dies nicht der Fall.

andig commented 3 years ago

Ja! Es geht ja bei Anderen auch…

andig commented 3 years ago

Schade, dass Ihr die Issues so schnell schließt. Da kommt man ja zeitlich nicht mal dazu, die gewünschten Daten zur Verfügung zu stellen... :-(

meld Dich einfach wenn Du eins hast. Bist dahin gibts nix zu tun.

KanteTaete commented 3 years ago

Also, wie gewünscht, anbei ein neuer Trace-Log.

Aber vorab kann ich bereits sagen, dass im kompletten Trace an keiner Stelle das "ena" Kommando gesendet wird! Es werden folgende Befehle gesendet:

send to 192.168.yyy.xxx:7090 report ... also Report 2, 3, 100)
send to 192.168.yyy.xxx:7090 curr ...

Beschreibung

Evcc wird gestartet, dann wird Ladekabel eingesteckt.
Laden beginnt im voreingestellten Modus PV [cache ] TRACE 2021/06/20 14:44:13 mode: pv
Es wird über Modus "now" in Modus Stopp gewechselt [lp-1 ] INFO 2021/06/20 14:48:49 set charge mode: off

beobachtetes Verhalten

Nach dem Wechsel wird auf der Website weiterhin "lädt" angezeigt.
es wird von evcc kein Kommando zum Stoppen des Ladevorgangs an die Box gesendet
es wird eine Stromvorgabe von 0 gesendet [keba ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx curr 0
Die Wallbox lädt weiterhin mit xA [lp-1 ] DEBUG 2021/06/20 14:48:53 charge currents: [2.43 2.44 0]A
die Stromvorgabe 0 wird von der Box nicht angenomen [keba ] TRACE 2021/06/20 14:48:56 recv from 192.168.yyy.xxx {"Max curr": 6000}

erwartetes Verhalten Nach dem Wechsel in Modus off

sendet evcc an die Wallbox Kommando ena 0 oder currtime 0 0 oder ein anderes Kommando, mit dem der Ladevorgang gestoppt wird
stopt der Ladevorgang und die augelesenen Ladeströme sind 0A
wird auf der Oberfläche nicht mehr "lädt" angezeigt

EVCC details:

Show evcc log output with --log trace:


Da ich nicht die 6000 Zeilen posten wollte, habe ich die [http] und [modbus] Einträge gekürzt.
Bevor der Verdacht aufkommt: Ich habe natürlich kein "send to 192.168..." gelöscht.

[main  ] INFO 2021/06/20 14:44:01 evcc 0.56 (cad5996)
[main  ] INFO 2021/06/20 14:44:01 using config file /etc/evcc.yaml
[main  ] INFO 2021/06/20 14:44:01 listening at 192.168.yyy.yyy:7070
[modbus] ...
[lp-1  ] WARN 2021/06/20 14:44:12 soc.levels are deprecated and will be removed in an upcoming release
[cache ] TRACE 2021/06/20 14:44:12 title: Garage
[cache ] TRACE 2021/06/20 14:44:12 minCurrent: 0
[cache ] TRACE 2021/06/20 14:44:12 maxCurrent: 16
[cache ] TRACE 2021/06/20 14:44:12 phases: 2
[cache ] TRACE 2021/06/20 14:44:12 activePhases: 2
[cache ] TRACE 2021/06/20 14:44:12 hasVehicle: false
[keba  ] TRACE 2021/06/20 14:44:12 send to 192.168.yyy.xxx report 2
[cache ] TRACE 2021/06/20 14:44:12 mode: pv
[cache ] TRACE 2021/06/20 14:44:12 targetSoC: 100
[cache ] TRACE 2021/06/20 14:44:12 minSoC: 0
[keba  ] TRACE 2021/06/20 14:44:12 recv from 192.168.yyy.xxx {
"ID": "2",
"State": 1,
"Error1": 0,
"Error2": 0,
"Plug": 3,
"AuthON": 0,
"Authreq": 0,
"Enable sys": 1,
"Enable user": 1,
"Max curr": 0,
"Max curr %": 1000,
"Curr HW": 16000,
"Curr user": 14448,
"Curr FS": 0,
"Tmo FS": 0,
"Curr timer": 7595,
"Tmo CT": 0,
"Setenergy": 0,
"Output": 0,
"Input": 0,
"Serial": "aaaaaaaa",
"Sec": 2150333
}
[site  ] INFO 2021/06/20 14:44:12 site config:
[site  ] INFO 2021/06/20 14:44:12   meters:    grid ✓ pv ✓ battery ✗
[cache ] TRACE 2021/06/20 14:44:12 siteTitle: daheim
[site  ] INFO 2021/06/20 14:44:12     grid:    power ✓ energy ✗ currents ✗
[cache ] TRACE 2021/06/20 14:44:12 gridConfigured: true
[site  ] INFO 2021/06/20 14:44:12     pv:      power ✓ energy ✗ currents ✗
[cache ] TRACE 2021/06/20 14:44:12 pvConfigured: true
[cache ] TRACE 2021/06/20 14:44:12 batteryConfigured: false
[lp-1  ] INFO 2021/06/20 14:44:12 loadpoint 1:
[lp-1  ] INFO 2021/06/20 14:44:12   mode:      pv
[lp-1  ] INFO 2021/06/20 14:44:12   charger:   power ✓ energy ✓ currents ✓ timer ✗
[lp-1  ] INFO 2021/06/20 14:44:12   meters:    charge ✓
[lp-1  ] INFO 2021/06/20 14:44:12     charge:  power ✓ energy ✓ currents ✓
[lp-1  ] INFO 2021/06/20 14:44:12   vehicles:  ✗
[cache ] TRACE 2021/06/20 14:44:12 chargeConfigured: true
[site  ] DEBUG 2021/06/20 14:44:12 ----
[modbus] ...
[site  ] DEBUG 2021/06/20 14:44:12 pv power: 5820W
[cache ] TRACE 2021/06/20 14:44:12 pvPower: 5820
[modbus] ...
[http  ] ...
[site  ] DEBUG 2021/06/20 14:44:13 grid power: -5480W
[site  ] DEBUG 2021/06/20 14:44:13 site power: -5480W
[cache ] TRACE 2021/06/20 14:44:13 gridPower: -5480.16
[keba  ] TRACE 2021/06/20 14:44:13 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:44:13 mode: pv
[keba  ] TRACE 2021/06/20 14:44:13 recv from 192.168.yyy.xxx {
"ID": "3",
"U1": 0,
"U2": 0,
"U3": 0,
"I1": 0,
"I2": 0,
"I3": 0,
"P": 0,
"PF": 0,
"E pres": 66325,
"E total": xxxxxxx,
"Serial": "aaaaaaaa",
"Sec": 2150334
}
...
[cache ] TRACE 2021/06/20 14:48:22 remoteDisabled: 
[modbus] TRACE 2021/06/20 14:48:27 modbus: closing connection due to idle timeout: 5.000806579s
[site  ] DEBUG 2021/06/20 14:48:32 ----
[modbus] ...
...
[site  ] DEBUG 2021/06/20 14:48:32 pv power: 5960W
[cache ] TRACE 2021/06/20 14:48:32 pvPower: 5960
[modbus] ...
[modbus] TRACE 2021/06/20 14:48:33 Power: 5960
[http  ] ...
[site  ] DEBUG 2021/06/20 14:48:33 grid power: -4308W
[site  ] DEBUG 2021/06/20 14:48:33 site power: -4308W
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:33 gridPower: -4308.139999999999
[cache ] TRACE 2021/06/20 14:48:33 mode: now
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
"ID": "3",
"U1": 234,
"U2": 234,
"U3": 235,
"I1": 2568,
"I2": 2584,
"I3": 0,
"P": 1152809,
"PF": 966,
"E pres": 658,
"E total": xxxxxxx,
"Serial": "aaaaaaaa",
"Sec": 2150594
}
[lp-1  ] DEBUG 2021/06/20 14:48:33 charge power: 1153W
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:33 chargePower: 1152.809
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:33 charge currents: [2.57 2.58 0]A
[lp-1  ] DEBUG 2021/06/20 14:48:33 detected phases: 2p [2.57 2.58 0]A
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:33 chargeCurrents: [2.568 2.584 0]
[cache ] TRACE 2021/06/20 14:48:33 activePhases: 2
[cache ] TRACE 2021/06/20 14:48:33 chargeCurrent: 16
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
...
}
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 2
[cache ] TRACE 2021/06/20 14:48:33 chargedEnergy: 65.8
[cache ] TRACE 2021/06/20 14:48:33 chargeDuration: 2m40s
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:33 charger status: C
[cache ] TRACE 2021/06/20 14:48:33 connected: true
[cache ] TRACE 2021/06/20 14:48:33 charging: true
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 100
[cache ] TRACE 2021/06/20 14:48:33 enabled: true
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:33 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/20 14:48:33 send to 192.168.yyy.xxx report 2
[keba  ] TRACE 2021/06/20 14:48:33 recv from 192.168.yyy.xxx {
...
}
[cache ] TRACE 2021/06/20 14:48:33 remoteDisabled: 
[modbus] TRACE 2021/06/20 14:48:37 modbus: closing connection due to idle timeout: 5.000621825s
[site  ] DEBUG 2021/06/20 14:48:42 ----
[modbus] ...
[site  ] DEBUG 2021/06/20 14:48:42 pv power: 7650W
[cache ] TRACE 2021/06/20 14:48:42 pvPower: 7650
[modbus] ...
[http  ] ...
[site  ] DEBUG 2021/06/20 14:48:43 grid power: -5998W
[site  ] DEBUG 2021/06/20 14:48:43 site power: -5998W
[cache ] TRACE 2021/06/20 14:48:43 gridPower: -5998.139999999999
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:43 mode: now
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:43 charge power: 1101W
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:43 chargePower: 1101.424
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:43 charge currents: [2.52 2.52 0]A
[lp-1  ] DEBUG 2021/06/20 14:48:43 detected phases: 2p [2.52 2.52 0]A
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:43 chargeCurrents: [2.515 2.524 0]
[cache ] TRACE 2021/06/20 14:48:43 activePhases: 2
[cache ] TRACE 2021/06/20 14:48:43 chargeCurrent: 16
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 2
[cache ] TRACE 2021/06/20 14:48:43 chargedEnergy: 69
[cache ] TRACE 2021/06/20 14:48:43 chargeDuration: 2m50s
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:43 charger status: C
[cache ] TRACE 2021/06/20 14:48:43 connected: true
[cache ] TRACE 2021/06/20 14:48:43 charging: true
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 100
[cache ] TRACE 2021/06/20 14:48:43 enabled: true
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:43 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/20 14:48:43 send to 192.168.yyy.xxx report 2
[keba  ] TRACE 2021/06/20 14:48:43 recv from 192.168.yyy.xxx {
...
}
[cache ] TRACE 2021/06/20 14:48:43 remoteDisabled: 
[keba  ] TRACE 2021/06/20 14:48:46 recv from 192.168.yyy.xxx {"E pres": 699}
[keba  ] TRACE 2021/06/20 14:48:46 recv: listener blocked
[modbus] TRACE 2021/06/20 14:48:47 modbus: closing connection due to idle timeout: 5.000682332s
[lp-1  ] INFO 2021/06/20 14:48:49 set charge mode: off
[site  ] DEBUG 2021/06/20 14:48:49 ----
[cache ] TRACE 2021/06/20 14:48:49 mode: off
[modbus] ...
[site  ] DEBUG 2021/06/20 14:48:49 pv power: 7580W
[modbus] ...
[cache ] TRACE 2021/06/20 14:48:49 pvPower: 7580
[modbus] ...
[http  ] ...
[site  ] DEBUG 2021/06/20 14:48:49 grid power: -5928W
[site  ] DEBUG 2021/06/20 14:48:49 site power: -5928W
[cache ] TRACE 2021/06/20 14:48:49 gridPower: -5928.139999999999
[cache ] TRACE 2021/06/20 14:48:49 mode: off
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 3
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
"ID": "3",
"U1": 235,
"U2": 235,
"U3": 235,
"I1": 2430,
"I2": 2445,
"I3": 0,
"P": 1133951,
"PF": 964,
"E pres": 710,
"E total": xxxxxxx,
"Serial": "aaaaaaaa",
"Sec": 2150611
}
[lp-1  ] DEBUG 2021/06/20 14:48:49 charge power: 1134W
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:49 chargePower: 1133.951
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:49 charge currents: [2.43 2.44 0]A
[lp-1  ] DEBUG 2021/06/20 14:48:49 detected phases: 2p [2.43 2.44 0]A
[cache ] TRACE 2021/06/20 14:48:49 chargeCurrents: [2.43 2.445 0]
[cache ] TRACE 2021/06/20 14:48:49 activePhases: 2
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:49 chargeCurrent: 16
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
...
}
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 2
[cache ] TRACE 2021/06/20 14:48:49 chargedEnergy: 71
[cache ] TRACE 2021/06/20 14:48:49 chargeDuration: 2m57s
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:49 charger status: C
[cache ] TRACE 2021/06/20 14:48:49 connected: true
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 100
[cache ] TRACE 2021/06/20 14:48:49 charging: true
[cache ] TRACE 2021/06/20 14:48:49 enabled: true
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:49 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx report 2
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:49 max charge current: 0
[keba  ] TRACE 2021/06/20 14:48:49 send to 192.168.yyy.xxx curr 0
[keba  ] TRACE 2021/06/20 14:48:49 recv from 192.168.yyy.xxx TCH-OK :done
[cache ] TRACE 2021/06/20 14:48:49 chargeCurrent: 0
[cache ] TRACE 2021/06/20 14:48:49 remoteDisabled: 
[site  ] DEBUG 2021/06/20 14:48:52 ----
[modbus] ...
[site  ] DEBUG 2021/06/20 14:48:52 pv power: 7750W
[modbus] ...
[cache ] TRACE 2021/06/20 14:48:52 pvPower: 7750
[modbus] ...
[http  ] ...
[site  ] DEBUG 2021/06/20 14:48:53 grid power: -6098W
[site  ] DEBUG 2021/06/20 14:48:53 site power: -6098W
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:53 gridPower: -6098.139999999999
[cache ] TRACE 2021/06/20 14:48:53 mode: off
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:53 charge power: 1098W
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:53 chargePower: 1097.892
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:53 charge currents: [2.43 2.44 0]A
[lp-1  ] DEBUG 2021/06/20 14:48:53 detected phases: 2p [2.43 2.44 0]A
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:48:53 chargeCurrents: [2.426 2.444 0]
[cache ] TRACE 2021/06/20 14:48:53 activePhases: 2
[cache ] TRACE 2021/06/20 14:48:53 chargeCurrent: 0
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 2
[cache ] TRACE 2021/06/20 14:48:53 chargedEnergy: 72
[cache ] TRACE 2021/06/20 14:48:53 chargeDuration: 3m0s
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:53 charger status: C
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 100
[cache ] TRACE 2021/06/20 14:48:53 connected: true
[cache ] TRACE 2021/06/20 14:48:53 charging: true
[cache ] TRACE 2021/06/20 14:48:53 enabled: true
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:48:53 charger vehicle id: 0000000000000000
[keba  ] TRACE 2021/06/20 14:48:53 send to 192.168.yyy.xxx report 2
[keba  ] TRACE 2021/06/20 14:48:53 recv from 192.168.yyy.xxx {
...
}
[cache ] TRACE 2021/06/20 14:48:53 remoteDisabled: 
[keba  ] TRACE 2021/06/20 14:48:56 recv from 192.168.yyy.xxx {"Max curr": 6000}
[keba  ] TRACE 2021/06/20 14:48:56 recv: listener blocked
[modbus] TRACE 2021/06/20 14:48:57 modbus: closing connection due to idle timeout: 5.000600026s
[site  ] DEBUG 2021/06/20 14:49:02 ----
[modbus] ...
[site  ] DEBUG 2021/06/20 14:49:02 pv power: 7190W
[cache ] TRACE 2021/06/20 14:49:02 pvPower: 7190
[modbus] ...
[http  ] ...
[site  ] DEBUG 2021/06/20 14:49:03 grid power: -5538W
[site  ] DEBUG 2021/06/20 14:49:03 site power: -5538W
[keba  ] TRACE 2021/06/20 14:49:03 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:49:03 gridPower: -5538.139999999999
[cache ] TRACE 2021/06/20 14:49:03 mode: off
[keba  ] TRACE 2021/06/20 14:49:03 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:49:03 charge power: 1041W
[keba  ] TRACE 2021/06/20 14:49:03 send to 192.168.yyy.xxx report 3
[cache ] TRACE 2021/06/20 14:49:03 chargePower: 1040.51
[keba  ] TRACE 2021/06/20 14:49:03 recv from 192.168.yyy.xxx {
...
}
[lp-1  ] DEBUG 2021/06/20 14:49:03 charge currents: [2.28 2.29 0]A
[lp-1  ] DEBUG 2021/06/20 14:49:03 detected phases: 2p [2.28 2.29 0]A
[cache ] TRACE 2021/06/20 14:49:03 chargeCurrents: [2.277 2.294 0]
[cache ] TRACE 2021/06/20 14:49:03 activePhases: 2
[cache ] TRACE 2021/06/20 14:49:03 chargeCurrent: 0
[keba  ] TRACE 2021/06/20 14:49:03 send to 192.168.yyy.xxx report 3
[keba  ] TRACE 2021/06/20 14:49:03 recv from 192.168.yyy.xxx {
...
}

andig commented 3 years ago

Wo hast du denn etwas ein/ausgeschaltet? Bzw wo siehst Du den Fehler im Log? Welchen?

Posting zu formatieren wäre auch Klasse ;)

KanteTaete commented 3 years ago

Den Kommentar bzgl. Formatierung hatte ich schon erwartet, allerdings hatte ich auf die Schnelle nicht gefunden, wie man formatieren kann und musste weg. Nun ist das Ganze inkl. Bedienungs-Reihenfolge, Beobachtung und erwartetem Verhalten oben angepasst. Ich hoffe, das genügt den Anforderungen.

andig commented 3 years ago

OK, das ist merkwürdig.

Kannst Du selbst compilieren? Dann würde es helfen, in der loadpoint.go ab Zeile 478 mal ein paar lp.log.INFO statements einzubauen um zu verstehen was da passiert. Gerne in jedes if statement eins. Bitte auch eins in Zeile 1016 um zu schauen ob er da überhaupt rein läuft oder schon vorher aussteigt.

andig commented 3 years ago

UPDATE kannst Du Dir sparen. Du hast minCurrent: 0 konfiguriert was quatsch ist. Bitte nimm den Defaultwert.

KanteTaete commented 3 years ago

Ich hab's eben nochmals mit dem Default-Wert getestet. Nun werden die ena Kommandos gesendet. :-)

Als Du (@andig) geschrieben hast, Es geht ja bei Anderen auch, hätte ich selbst darauf kommen können, dass da etwas in der Konfiguration anders (falsch) sein könnte... Außerdem bin ich mir nicht sicher, ob ich das Abschalten bei den eingestellten langen Hysterese-Zeiten für disable|delay: 5m und guardduration: 10m überhaupt beobachten hätte können, wenn ich nur wenige Minuten Log verfügbar habe. Für den Test habe ich guardduration: 3m gesetzt. Das muss ich mir mal genauer anschauen, wenn ich wirklich im PV-Modus laden kann (bei langzeit-vollem Akku wegen HomeOffice und Netzbezug statt Einspeisung ist das schwierig :-) ).

Vielen Dank für die Hilfe!

Noch eine Frage zum Abschluss: Hätte ich den "Minimum-Wert" für mincurrent irgendwo selbst sehen können oder wäre es ggf. sinnvoll, den Wertebereich der Parameter in der Konfiguration zu hinterlegen, um solche Fälle zukünftig zu vermeiden?

evcc-io / evcc

Charging with KEBA is not stopped, if mode is set to "stop" in gui #1142