evcc-io / evcc

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

Autos nach Server-Neustart offline #17197

Open princemaxwell opened 2 days ago

princemaxwell commented 2 days ago

Describe the bug

Ich habe jetzt mehrfach festgestellt, dass meine Autos offline bleiben, nachdem ich den kompletten Debian Server (Virtuelle Maschine) neu starte oder die Synology neu starte, was ja zu einem Neustart von VMM führt. Ich sehe dann nur eine duchgestrichene Wolke neben den Fahrzeugnamen und die Daten werden nicht geladen.

Erst wenn ich auf "Hilfe benötigt?" und "Neu starten" klicke, sind nach dem Neustart die Auto wieder online und der Status sichtbar.

Zwischendurch wird auch nicht von EVCC versucht, die API vom Auto nochmal zu erreichen, das passiert erst nach dem Neustart wieder regelmäßig.

Steps to reproduce

Neustart VMM oder Debian Server

Configuration details

---

Log details

Nov 11 17:33:25 evcc systemd[1]: Stopping evcc.service - evcc...
Nov 11 17:33:25 evcc systemd[1]: evcc.service: Deactivated successfully.
Nov 11 17:33:25 evcc systemd[1]: Stopped evcc.service - evcc.
Nov 11 17:33:25 evcc systemd[1]: evcc.service: Consumed 17min 32.937s CPU time.
Nov 11 17:47:10 evcc systemd[1]: Started evcc.service - evcc.
Nov 11 17:47:23 evcc evcc[425]: [main  ] INFO 2024/11/11 17:47:23 evcc 0.131.5
Nov 11 17:47:23 evcc evcc[425]: [main  ] INFO 2024/11/11 17:47:23 using config file: /etc/evcc.yaml
Nov 11 17:47:23 evcc evcc[425]: [db    ] INFO 2024/11/11 17:47:23 using sqlite database: /var/lib/evcc/evcc.db
Nov 11 17:47:23 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:23 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="settings" -1 <nil>
Nov 11 17:47:23 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:23 SELECT sql FROM sqlite_master WHERE type IN ("table","index") AND tbl_name = "settings" AND sql IS NOT NULL order by type = "table" desc 1 <nil>
Nov 11 17:47:23 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:23 SELECT * FROM `settings` LIMIT 1 -1 <nil>
Nov 11 17:47:23 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:23 SELECT * FROM `settings` 52 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="devices" -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="device_details" -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="configs" -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT sql FROM sqlite_master WHERE type IN ("table","index") AND tbl_name = "configs" AND sql IS NOT NULL order by type = "table" desc 1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT * FROM `configs` LIMIT 1 -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="config_details" -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="config_details" -1 <nil>
Nov 11 17:47:34 evcc evcc[425]: [main  ] INFO 2024/11/11 17:47:34 listening at :7070
Nov 11 17:47:34 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:34 SELECT * FROM `configs` WHERE `configs`.`class` = 2 0 <nil>
Nov 11 17:47:35 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:35 SELECT * FROM `configs` WHERE `configs`.`class` = 1 0 <nil>
Nov 11 17:47:35 evcc evcc[425]: [db    ] TRACE 2024/11/11 17:47:35 SELECT * FROM `configs` WHERE `configs`.`class` = 3 0 <nil>
Nov 11 17:47:35 evcc evcc[425]: [nissan] TRACE 2024/11/11 17:47:35 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 17:47:35 evcc evcc[425]: [nissan] TRACE 2024/11/11 17:47:35 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 17:47:40 evcc evcc[425]: [main  ] ERROR 2024/11/11 17:47:40 creating vehicle leafs failed: cannot create vehicle type 'template': cannot create vehicle type 'nissan': login failed: Post "https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate": dial tcp: lookup prod.eu2.auth.kamereon.org: i/o timeout
Nov 11 17:47:40 evcc evcc[425]: [main  ] ERROR 2024/11/11 17:47:40 creating vehicle leafm failed: cannot create vehicle type 'template': cannot create vehicle type 'nissan': login failed: Post "https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate": dial tcp: lookup prod.eu2.auth.kamereon.org: i/o timeout
Nov 11 17:47:40 evcc evcc[425]: [lp-1  ] WARN 2024/11/11 17:47:40 poll mode '{always 1h0m0s}' may deplete your battery or lead to API misuse. USE AT YOUR OWN RISK.

HILFE BENÖTIGT? > NEU STARTEN

Nov 11 20:46:29 evcc systemd[1]: evcc.service: Deactivated successfully.
Nov 11 20:46:29 evcc systemd[1]: evcc.service: Consumed 2min 4.647s CPU time.
Nov 11 20:46:39 evcc systemd[1]: evcc.service: Scheduled restart job, restart counter is at 1.
Nov 11 20:46:39 evcc systemd[1]: Stopped evcc.service - evcc.
Nov 11 20:46:39 evcc systemd[1]: evcc.service: Consumed 2min 4.647s CPU time.
Nov 11 20:46:39 evcc systemd[1]: Started evcc.service - evcc.
Nov 11 20:46:39 evcc evcc[637]: [main  ] INFO 2024/11/11 20:46:39 evcc 0.131.5
Nov 11 20:46:39 evcc evcc[637]: [main  ] INFO 2024/11/11 20:46:39 using config file: /etc/evcc.yaml
Nov 11 20:46:39 evcc evcc[637]: [db    ] INFO 2024/11/11 20:46:39 using sqlite database: /var/lib/evcc/evcc.db
Nov 11 20:46:39 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:39 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="settings" -1 <nil>
Nov 11 20:46:39 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:39 SELECT sql FROM sqlite_master WHERE type IN ("table","index") AND tbl_name = "settings" AND sql IS NOT NULL order by type = "table" desc 1 <nil>
Nov 11 20:46:39 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:39 SELECT * FROM `settings` LIMIT 1 -1 <nil>
Nov 11 20:46:39 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:39 SELECT * FROM `settings` 52 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="devices" -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="device_details" -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="configs" -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT sql FROM sqlite_master WHERE type IN ("table","index") AND tbl_name = "configs" AND sql IS NOT NULL order by type = "table" desc 1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT * FROM `configs` LIMIT 1 -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="config_details" -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT count(*) FROM sqlite_master WHERE type='table' AND name="config_details" -1 <nil>
Nov 11 20:46:41 evcc evcc[637]: [main  ] INFO 2024/11/11 20:46:41 listening at :7070
Nov 11 20:46:41 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:41 SELECT * FROM `configs` WHERE `configs`.`class` = 2 0 <nil>
Nov 11 20:46:42 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:42 SELECT * FROM `configs` WHERE `configs`.`class` = 1 0 <nil>
Nov 11 20:46:42 evcc evcc[637]: [db    ] TRACE 2024/11/11 20:46:42 SELECT * FROM `configs` WHERE `configs`.`class` = 3 0 <nil>
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":""}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":""}]}]}
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":""}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":""}]}]}
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":"***"}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":"***"}]}]}
Nov 11 20:46:42 evcc evcc[637]: --
Nov 11 20:46:42 evcc evcc[637]: {"code":401,"reason":"Unauthorized","message":"Session has timed out","detail":{"errorCode":"110"}}
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":"***"}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":"..."}]}]}
Nov 11 20:46:42 evcc evcc[637]: --
Nov 11 20:46:42 evcc evcc[637]: {"code":401,"reason":"Unauthorized","message":"Session has timed out","detail":{"errorCode":"110"}}
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":"***"}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":"..."}]}]}
Nov 11 20:46:42 evcc evcc[637]: --
Nov 11 20:46:42 evcc evcc[637]: {"code":401,"reason":"Unauthorized","message":"Session has timed out","detail":{"errorCode":"110"}}
Nov 11 20:46:42 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:42 POST https://prod.eu2.auth.kamereon.org/kauth/json/realms/root/realms/a-ncb-prod/authenticate
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":"***"}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":"..."}]}]}
Nov 11 20:46:43 evcc evcc[637]: --
Nov 11 20:46:43 evcc evcc[637]: {"tokenId":"...","successUrl":"/kauth/console","realm":"/a-ncb-prod"}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://prod.eu2.auth.kamereon.org/kauth/oauth2/a-ncb-prod/authorize?client_id=a-ncb-nc-android-prod&nonce=sdfdsfez&redirect_uri=org.kamereon.service.nci%3A%2Foauth2redirect&response_type=code&scope=openid+profile+vehicles
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 {"authId":"...","template":"","stage":"LDAP1","header":"Sign in","callbacks":[{"type":"NameCallback","output":[{"name":"prompt","value":"User Name:"}],"input":[{"name":"IDToken1","value":"***"}]},{"type":"PasswordCallback","output":[{"name":"prompt","value":"Password:"}],"input":[{"name":"IDToken2","value":"***"}]}]}
Nov 11 20:46:43 evcc evcc[637]: --
Nov 11 20:46:43 evcc evcc[637]: {"tokenId":"...","successUrl":"/kauth/console","realm":"/a-ncb-prod"}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://prod.eu2.auth.kamereon.org/kauth/oauth2/a-ncb-prod/authorize?client_id=a-ncb-nc-android-prod&nonce=sdfdsfez&redirect_uri=org.kamereon.service.nci%3A%2Foauth2redirect&response_type=code&scope=openid+profile+vehicles
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 POST https://prod.eu2.auth.kamereon.org/kauth/oauth2/a-ncb-prod/access_token
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 POST https://prod.eu2.auth.kamereon.org/kauth/oauth2/a-ncb-prod/access_token
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 client_id=a-ncb-nc-android-prod&client_secret=...&grant_type=authorization_code&redirect_uri=org.kamereon.service.nci%3A%2Foauth2redirect
Nov 11 20:46:43 evcc evcc[637]: --
Nov 11 20:46:43 evcc evcc[637]: {"access_token":"...","refresh_token":"...","scope":"openid profile vehicles","id_token":"...","token_type":"Bearer","expires_in":21599,"nonce":"sdfdsfez"}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://alliance-platform-usersadapter-prod.apps.eu2.kamereon.io/user-adapter/v1/users/current
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 client_id=a-ncb-nc-android-prod&client_secret=...&code=...&grant_type=authorization_code&redirect_uri=org.kamereon.service.nci%3A%2Foauth2redirect
Nov 11 20:46:43 evcc evcc[637]: --
Nov 11 20:46:43 evcc evcc[637]: {"access_token":"...","token_type":"Bearer","expires_in":21599,"nonce":"sdfdsfez"}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://alliance-platform-usersadapter-prod.apps.eu2.kamereon.io/user-adapter/v1/users/current
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 {"userId":"..."}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://nci-bff-web-prod.apps.eu2.kamereon.io/bff-web/v5/users/.../cars
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 {"userId":"..."}
Nov 11 20:46:43 evcc evcc[637]: [nissan] TRACE 2024/11/11 20:46:43 GET https://nci-bff-web-prod.apps.eu2.kamereon.io/bff-web/v5/users/.../cars
...
Nov 11 20:46:44 evcc evcc[637]: [lp-1  ] WARN 2024/11/11 20:46:44 poll mode '{always 1h0m0s}' may deplete your battery or lead to API misuse. USE AT YOUR OWN RISK.

What type of operating system are you running?

Linux

Nightly build

Version

evcc version 0.131.5

andig commented 1 day ago

Ich sehe dann nur eine duchgestrichene Wolke neben den Fahrzeugnamen und die Daten werden nicht geladen.

"Offline" und "Fahrzeug konnte nicht initialisiert" werden sind zwei komplett unterschiedliche Dinge. Warum das Nissan API sich bei Neustart weigert die Session neu aufzubauen und damit das evcc Fahrzeug nicht initialisiert werden kann ist unklar. Leider ist das alles reverse-engineertes Zeug.

princemaxwell commented 1 day ago

@andig Könnte man im Nissan Template nicht etwas einbauen, dass bei fehlgeschlagener Initialisierung ein wenig später nochmal ein Versuch gestartet wird?

Nach dem Server Neustart klappt es ja immer auf Anhieb, vielleicht ist es bei einem Wiederholungsversuch auch so!?

andig commented 1 day ago

Ich habe jetzt mehrfach festgestellt, dass meine Autos offline bleiben, nachdem ich den kompletten Debian Server (Virtuelle Maschine) neu starte oder die Synology neu starte, was ja zu einem Neustart von VMM führt

Das ergibt keinen Sinn. Ein Neustart von Container oder evcc ist ein Neustart.

Fehlerhafte Geräte später wieder zu starten ist ein Thema das allgemein im Backlog ist.

An-Wi commented 1 day ago

@princemaxwell Wenn ich das Log richtig lese, hast du einen Nissan Leaf und nutzt vermutlich das ursprüngliche Nissan-Template von evcc. Deinen Fehler kenne ich, da ich ihn auch immer wieder mal hatte, aber seit einiger Zeit gar nicht mehr. Für meinen Ariya nutze ich allerdings nun das speziell dafür angepasste Nissan-Template, wobei ich das hier nicht als Ursache vermuten würde, denn der Login-Part ist identisch in beiden Templates. Meinen Beobachtungen nach hat die Nissan-API zu bestimmten Tageszeiten „diverse“ Problemchen. Meistens waren das bei mir aber veraltete Timestamps trotz aktueller Daten… Was ich empfehlen kann, wenn dein Neustart automatisiert erfolgt, die Uhrzeit zu variieren. Bei mir startet der evcc-Server 1x pro Woche montags 21 Uhr. Auffällig problematisch waren bei mit Zeiten zw. 17-19 Uhr sowie 22-1 Uhr.

princemaxwell commented 1 day ago

@An-Wi

Vielen Dank für die ausführlichen Infos. Automatische Neustarts hab ich nicht, meist nur wenn für Synology mal durch ein Update neu startet und dann auch VMM betroffen ist.

Ich beobachte Mal die Zeiten, vermutlich sind die Server einfach nur das Problem.

Das angepasste Template gilt nur für den Ariya, daher passt meine config zur Doku. Für Leaf alles wie gehabt.