evcc-io / evcc

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

Planned charge does not start #10625

Closed odlg closed 10 months ago

odlg commented 10 months ago

Describe the bug

A planned charge does not start.

Steps to reproduce

In Solar mode, set a target limit higher that current charge, set departure time. Setting Smart Grid price limit has no effect. Running in docker on x86_64 Linux.

Configuration details

site:
  - title: My Home  # display name for UI
    residualPower: -700
    smartCostLimit: 0.40
    meters:
      grid: my_grid # grid meter reference
      pv: # (pvs = veraltet)
        - my_pv # first pv meter reference
interval: 30s
log: debug
loadpoints:
  - title: Carport # display name for UI
    charger: my_charger # charger reference
    vehicle: my_car # reference to standard vehicle
    mode: pv # charge mode (off, now, minpv, pv)
    soc:
      poll:
        mode: charging
        interval: 60m
      estimate: true
    phases: 1
chargers:
  - name: my_charger
    type: template
    template: abb

    # RS485 via adapter (Modbus RTU)
    modbus: rs485serial
    id: 2
    device: /dev/ttyACM0 # USB-RS485 Adapter Adresse
    baudrate: 38400 # Prüfe die Geräteeinstellungen, typische Werte sind 9600, 19200, 38400, 57600, 115200
    comset: "8N1" # Kommunikationsparameter für den Adapter
meters:
  - name: my_grid
    type: template
    template: fronius-gen24
    usage: grid
    host: 10.4.6.10 # IP address or hostname
    #port: 502 # Port (optional) 
  - name: my_pv
    type: template
    template: fronius-gen24
    usage: pv
    host: 10.4.6.10 # IP address or hostname
    #port: 502 # Port (optional) 
vehicles:
  - name: my_car
    type: template
    template: bmw
    title: BMW i3 # Will be displayed in the user interface (optional)
    user: some@email # User account (e.g. email address, user id, etc.)
    password: "somePw" # Password of the user account (use single quotes in case of leading zeros)
    vin: xxxxx  # Required if you own multiple vehicles of the same brand (optional)
    capacity: 20 # Battery capacity in kWh (optional) 
    phases: 1
tariffs:
  currency: DKK
  grid:
    type: energinet # Energinet using the price in DKK
    region: dk1 # or dk2
    charges: 0.02 # optional, additional charges per kWh
    tax: # optional, additional tax (0.1 for 10%)
  feedin:
    type: energinet # Energinet using the price in DKK
    region: dk1 # or dk2
    charges: -0.05 # optional, additional charges per kWh
    tax: # optional, additional tax (0.1 for 10%)
network:
  # schema is the HTTP schema
  # setting to `https` does not enable https, it only changes the way URLs are generated
  schema: http
  # host is the hostname or IP address
  # if the host name contains a `.local` suffix, the name will be announced on MDNS
  # docker: MDNS announcements don't work. host must be set to the docker host's name.
  host: evcc.xyx
  # port is the listening port for UI and api
  # evcc will listen on all available interfaces
  port: 7070
messaging:
  events:
    start:
      title: Charge of {{.vehicleTitle}} started
      msg: Charger ${title} started charging ${vehicleTitle} in ${mode} mode
    stop:
      title: Charge of {{.vehicleTitle}} finished
      msg: Charger ${title} finished charging ${vehicleTitle} with ${chargedEnergy:%.1fk}kWh in ${chargeDuration}
    connect:
      title: "{{.vehicleTitle}} connected on Charger {{.title}}"
      msg: ${vehicleTitle} connected on Charger ${title} at ${pvPower:%.1fk}kW PV
    disconnect:
      title: "{{.vehicleTitle}} disconnected of Charger {{.title}}"
      msg: ${vehicleTitle} disconnected of Charger ${title} after ${connectedDuration}
    guest:
      title: Guest vehicle detected
      msg: Guest vehicle detected
  services:
    - type: ntfy
      uri: https://ntfy.sh/kljdslfksd
      priority: default
      tags: electric_plug,blue_car
sponsortoken: xxxxx

Log details

[site  ] DEBUG 2023/11/03 09:56:06 ----
[lp-1  ] DEBUG 2023/11/03 09:56:06 charge power: 0W
[site  ] DEBUG 2023/11/03 09:56:06 pv power: 349W
[site  ] DEBUG 2023/11/03 09:56:06 grid power: 208W
[site  ] DEBUG 2023/11/03 09:56:06 grid currents: [1.68 0.939 -0.699]A
[site  ] DEBUG 2023/11/03 09:56:06 site power: -492W
[lp-1  ] DEBUG 2023/11/03 09:56:06 charge voltages: [232 231 231]V
[lp-1  ] DEBUG 2023/11/03 09:56:06 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:56:06 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:56:06 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:56:06 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:56:06 pv charge current: 2.14A = 0A + 2.14A (-492W @ 1p)
[site  ] DEBUG 2023/11/03 09:56:36 ----
[lp-1  ] DEBUG 2023/11/03 09:56:36 charge power: 0W
[site  ] DEBUG 2023/11/03 09:56:36 pv power: 341W
[site  ] DEBUG 2023/11/03 09:56:36 grid power: 220W
[site  ] DEBUG 2023/11/03 09:56:36 grid currents: [1.69 0.939 -0.693]A
[site  ] DEBUG 2023/11/03 09:56:36 site power: -480W
[lp-1  ] DEBUG 2023/11/03 09:56:36 charge voltages: [232 232 231]V
[lp-1  ] DEBUG 2023/11/03 09:56:36 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:56:36 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:56:36 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:56:36 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:56:36 pv charge current: 2.08A = 0A + 2.08A (-480W @ 1p)
[site  ] DEBUG 2023/11/03 09:57:06 ----
[lp-1  ] DEBUG 2023/11/03 09:57:06 charge power: 0W
[site  ] DEBUG 2023/11/03 09:57:06 pv power: 334W
[site  ] DEBUG 2023/11/03 09:57:06 grid power: 246W
[site  ] DEBUG 2023/11/03 09:57:06 grid currents: [1.74 0.978 -0.687]A
[site  ] DEBUG 2023/11/03 09:57:06 site power: -454W
[lp-1  ] DEBUG 2023/11/03 09:57:06 charge voltages: [232 232 231]V
[lp-1  ] DEBUG 2023/11/03 09:57:06 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:57:06 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:57:06 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:57:06 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:57:06 pv charge current: 1.98A = 0A + 1.98A (-454W @ 1p)
[site  ] DEBUG 2023/11/03 09:57:36 ----
[lp-1  ] DEBUG 2023/11/03 09:57:36 charge power: 0W
[site  ] DEBUG 2023/11/03 09:57:36 pv power: 340W
[site  ] DEBUG 2023/11/03 09:57:36 grid power: 252W
[site  ] DEBUG 2023/11/03 09:57:36 grid currents: [1.69 1 -0.721]A
[site  ] DEBUG 2023/11/03 09:57:36 site power: -448W
[lp-1  ] DEBUG 2023/11/03 09:57:36 charge voltages: [233 232 232]V
[lp-1  ] DEBUG 2023/11/03 09:57:36 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:57:36 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:57:36 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:57:36 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:57:36 pv charge current: 1.95A = 0A + 1.95A (-448W @ 1p)
[site  ] DEBUG 2023/11/03 09:58:06 ----
[lp-1  ] DEBUG 2023/11/03 09:58:06 charge power: 0W
[site  ] DEBUG 2023/11/03 09:58:06 pv power: 353W
[site  ] DEBUG 2023/11/03 09:58:06 grid power: 288W
[site  ] DEBUG 2023/11/03 09:58:06 grid currents: [1.72 1.12 -0.722]A
[site  ] DEBUG 2023/11/03 09:58:06 site power: -412W
[lp-1  ] DEBUG 2023/11/03 09:58:06 charge voltages: [233 232 232]V
[lp-1  ] DEBUG 2023/11/03 09:58:06 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:58:06 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:58:06 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:58:06 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:58:06 pv charge current: 1.79A = 0A + 1.79A (-412W @ 1p)
[site  ] DEBUG 2023/11/03 09:58:36 ----
[lp-1  ] DEBUG 2023/11/03 09:58:36 charge power: 0W
[site  ] DEBUG 2023/11/03 09:58:36 pv power: 359W
[site  ] DEBUG 2023/11/03 09:58:36 grid power: 175W
[site  ] DEBUG 2023/11/03 09:58:36 grid currents: [1.66 0.938 -0.694]A
[site  ] DEBUG 2023/11/03 09:58:36 site power: -525W
[lp-1  ] DEBUG 2023/11/03 09:58:36 charge voltages: [233 232 232]V
[lp-1  ] DEBUG 2023/11/03 09:58:36 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:58:36 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:58:36 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:58:36 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:58:36 pv charge current: 2.28A = 0A + 2.28A (-525W @ 1p)
[site  ] DEBUG 2023/11/03 09:59:06 ----
[lp-1  ] DEBUG 2023/11/03 09:59:06 charge power: 0W
[site  ] DEBUG 2023/11/03 09:59:06 pv power: 365W
[site  ] DEBUG 2023/11/03 09:59:06 grid power: 229W
[site  ] DEBUG 2023/11/03 09:59:06 grid currents: [1.71 1.03 -0.681]A
[site  ] DEBUG 2023/11/03 09:59:06 site power: -471W
[lp-1  ] DEBUG 2023/11/03 09:59:06 charge voltages: [233 232 232]V
[lp-1  ] DEBUG 2023/11/03 09:59:06 detected connected phases: 3p
[lp-1  ] DEBUG 2023/11/03 09:59:06 charge currents: [0 0 0]A
[lp-1  ] DEBUG 2023/11/03 09:59:06 charger status: B
[lp-1  ] DEBUG 2023/11/03 09:59:06 plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)
[lp-1  ] DEBUG 2023/11/03 09:59:06 pv charge current: 2.05A = 0A + 2.05A (-471W @ 1p)

What type of operating system are you running?

Docker container

Version

0.121.5

andig commented 10 months ago

Please share the full log. There is something odd with the start timestamps:

plan: charge 0s (required: 1h16m5s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-03 10:00:00 +0100 CET (power: 3680W, avg cost: NaN)

We need to find out where/why the start timestamp goes wrong.

odlg commented 10 months ago

Here is the full log evcc.log

andig commented 10 months ago

Im Log wird leider nicht klar, wo die komische Startzeit her kommt. Es scheint, als hätte der Planner einen Plan ohne Inhalt gemacht- da würde auch zu den NaN Kosten passen. Warum das passiert ist leider absolut nicht erkennbar. Falls Du das Szenario reproduzieren kannst würde ich mich über Beschreibung freuen. As-is gibts leider nix was wir tun könnten :/

odlg commented 10 months ago

@andig I have not been able to not reproduce this. How do I debug this to actually make it work? I have tried to mount /etc/localtime from the docker host, also mounting /usr/share/zoneinfo/Europe/Berlin to match the TZ env. It does not change anything.

andig commented 10 months ago

It does not change anything.

Change what?

How do I debug this to actually make it work?

Now you got me confused. To make what work? Are you saying Planner never works for you? That would be enough of a reproducer! In that case- please add steps to reproduce.

odlg commented 10 months ago

Planner never worked for me. The steps to reproduce:

  1. Run above config in docker.
  2. Car needs to be connected.
  3. Set Smart Grid Charging price so low that it is not charging due to cheap prices.
  4. Set a planned time to reach target charging state.
  5. Now it logs what is seen above.
odlg commented 10 months ago

@andig I just tried to run 0.122.0 directly on the host OS (so not in Docker) and it has the same issue with Planner not working. It is also logging the weird LMT timezone.

andig commented 10 months ago

Mhhm. I cant repro. Are you able to see that in the demo instance or using the demo.yaml config? I need something to attach the debugger to…

odlg commented 10 months ago

@andig demo.yaml does not reproduce the issue. That logs just fine charge plans. [lp-1 ] DEBUG 2023/11/05 20:07:07 plan: charge 2h52m52s (required: 3h36m49s) starting at 2023-11-05 20:07:08 +0100 CET until 2023-11-05 23:00:00 +0100 CET (power: 3680W, avg cost: 206.976)

odlg commented 10 months ago

@andig Using demo.yaml with tariffs from my config above triggers the issue. [lp-1 ] DEBUG 2023/11/05 20:21:39 plan: charge 0s (required: 3h41m36s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-05 23:00:00 +0100 CET (power: 3680W, avg cost: NaN)

andig commented 10 months ago

Please provide exact steps. Which loadpoint, vehicle, limit etc. Still cant repro.

odlg commented 10 months ago

@andig Using evcc.yaml and no evcc.db file I did these steps: Set a charge plan for 'blauer e-Golf' to a few hours from now. Immediately it logs [lp-1 ] DEBUG 2023/11/05 21:29:20 plan: charge 0s (required: 3h39m12s) starting at 0001-01-01 00:53:28 +0053 LMT until 2023-11-05 23:00:00 +0100 CET (power: 3680W, avg cost: NaN)

andig commented 10 months ago

Could you please try 0.122.0? It has some additional logging I think. Doing as you describe (and deleting evcc.db) I get:

go run main.go -c cmd/demo.yaml
[main  ] INFO 2023/11/06 20:17:53 using config file: cmd/demo.yaml
...
[lp-1  ] DEBUG 2023/11/06 20:18:12 set target time: 2023-11-06 23:00:00 +0100 CET
...
[lp-1  ] DEBUG 2023/11/06 20:18:18 plan: charge 2h41m42s (required: 3h38m24s) starting at 2023-11-06 20:18:18 +0100 CET until 2023-11-06 23:00:00 +0100 CET (power: 3680W, avg cost: 172.000)

Are you able to repro with the demo.yaml? Unfortunately I can't use your yaml sind the devices are different :(

odlg commented 10 months ago

With the orignal demo.yaml i do not reproduce the issue. With https://github.com/evcc-io/evcc/files/13260725/evcc.yaml.txt I do reproduce the issue - it is demo.yaml with energinet tariffs

andig commented 10 months ago

Great find, thank you! It turns out, that Energinet violates a core (and sane) assumption of the planner

// rates are by default sorted by date, oldest to newest
last := rates[len(rates)-1].End

since it's API returns time slots in reverse order (why would anybody do this?). PR ensures all tariffs are sorted in ascending order now, just to be safe.

odlg commented 10 months ago

I have rebuilt the Docker image, it looks good - now I hope my car is charged tomorrow :-)