Closed F-L-0 closed 2 years ago
andig
commented
2 years ago Was hat das mit SMA zu tun? Ich kanns wir schwer vorstellen aufgrund https://github.com/evcc-io/evcc/blob/1ba175bd5c49e24e97b51b68e371983d78f78b82/provider/mqtt/client.go#L66, deshalb bitte Logfile.
andig
commented
2 years ago Wenn ich es richtig verstehe, dann fällt SMA aus wenn der (unabhängigte) MQTT Server restartet wird?
@bboehmke ich kann mir keinen Reim drauf machen und es auch nicht nachstellen. Könntest Du bei Dir schauen, ob Du das Verhalten reproduzieren kannst? Vielen Dank!
F-L-0
commented
2 years ago Was hat das mit SMA zu tun? Ich kanns wir schwer vorstellen aufgrund
, deshalb bitte Logfile.
Hi Andi, das Logfile (evcc --log debug) ist oben im Issue schon dabei, brauchst du was zusätzliches, anderer Loglevel?
Im Config sind 3 SMA Geräte definiert, das EM läuft weiter (sieht man an der durchgehenden Ausgabe der Werte der 3 Phasen), die beiden Wechselrichter abzufragen funktioniert ab dem Restart des MQTT Servers nicht mehr. Der Reconnect zum mqtt Server funktioniert einwandfrei, die Kommunikation zu den Wechselrichtern bleibt gestört. Ich weiß, klingt komisch, ist aber reproduzierbar so ;-)
Wenn ich noch was tracen kann (Loglevel, tcpdump, etc ...) - sehr gerne.
bboehmke
commented
2 years ago Ich hab es jetzt mal mit einer erweiterten Demokonfiguration getestet und bei mir funktioniert zumindest das EnergyMeter weiterhin nach Verbindungsverlust mit dem MQTT broker.
Leider war/ist das Wetter nicht besonders weshalb weder Strom von der PV Anlage kommt noch wurde die Batterie heute geladen weshalb ich nicht prüfen konnte ob die Wechselrichter weiterhin funktionieren.
und einem lokalen mqtt broker via docker:
docker run --rm -it -p 1883:1883 eclipse-mosquitto mosquitto -c /mosquitto-no-auth.confAnscheinend betrifft das Problem nur die WR. Ich lausche gespannt was ihr raus findet- das ist ja mal ein wirklich fancy issue ;)
andig
commented
2 years ago @F-L-0 kann man die WR auch über Serial statt URI konfigurieren? Ändert das was?
F-L-0
commented
2 years ago Ich habe jetzt selbst auch nochmal auf einem zweiten Raspberry getestet und konnte mit identischer Config den Fehler nicht nachstellen. Was auch immer das Problem ist, es muss in meinem Setup begründet sein. Ich werde das noch weiter untersuchen, auf dem RPI der den Fehler zeigt läuft noch einiges mehr parallel das mit den Wechselrichtern spricht (SBFSpot, FHEM, ...). Wie auch immer, ich würde eure Zeit da nicht weiter beanspruchen und, falls Interesse besteht, mich damit melden was ich gefunden hab. Falls ich es nicht finde bekommt evcc halt einen eigenen RPI ;-)
bboehmke
commented
2 years ago Ah da haben wirs: Die Kommunikation mit den SMA Wechselrichtern via Speedwire funktioniert nur einmal von einem Gerät aus. Also entweder evcc oder SPFSpot.
(Hintergrund ist das beide Anwendungen auf dem gleichen UDP port lauschen -> das geht ohne weiteres nicht zweimal auf einem System)
andig
commented
2 years ago Ah da haben wirs: Die Kommunikation mit den SMA Wechselrichtern via Speedwire funktioniert nur einmal von einem Gerät aus. Also entweder evcc oder SPFSpot.
Warum das wieder vom MQTT Server abhängen sollte???
Anyway, danke für's Update und wir machen hier mal zu :)
F-L-0
commented
2 years ago Der Vollständigkeit halber noch - SBFSpot, FHEM mit dem Modul 76_SMAInverter.pm und evcc existieren schon seit Wochen erstmal friedlich nebeneinander auf einem RPI. Wenn man allerdings fhem restartet (und erst dann) wird die Speedwire-Session beim shutdown beendet, worauf auch evcc nix mehr bekommt (?). Bin nicht ganz tief im Protokoll, aber ich meine da waren Multicast-Subscriptions (netstat -g) im Spiel, beim EM auf jeden Fall, bei den Invertern wars evtl auch nur UDP. MQTT hat definitiv nix damit zu tun, da bin ich falsch abgebogen, fhem war nur in meinem setup gleichzeitig der MQTT Broker. Der Fehler tritt auch auf wenn man mqtt in evcc.yaml deaktiviert.
Ab diesem Zeitpunkt (fhem-restart) antwortet der Inverter im Log von evcc nicht mehr auf [sma ] TRACE 2021/11/04 19:42:57 login for 192.168.1.11:9522 [sma ] TRACE 2021/11/04 19:42:57 send 192.168.1.11: [proto.GroupPacketEntry, proto.SmaNet2PacketEntry]
Vorher wenn es geht steht da [sma ] TRACE 2021/11/04 19:42:52 login for 192.168.1.11:9522 [sma ] TRACE 2021/11/04 19:42:52 send 192.168.1.11: [proto.GroupPacketEntry, proto.SmaNet2PacketEntry] [sma ] TRACE 2021/11/04 19:42:52 recv 192.168.1.11: [proto.GroupPacketEntry, proto.SmaNet2PacketEntry]
Der Filedescriptor auf UDP:9522 von evcc bleibt vorhanden: evcc 15867 evcc 3u IPv4 209850044 0t0 UDP *:9522
Im tcpdump sieht man das der Wechselrichter auf den Login von evcc antwortet, das aber bei evcc nicht mehr ankommt:
20:33:13.389992 IP 192.168.1.240.9522 > 192.168.1.11.9522: UDP, length 78
0x0000: 4500 006a 8cd5 4000 4011 2962 c0a8 01f0 E..j..@.@.)b....
0x0010: c0a8 010b 2532 2532 0056 84b3 534d 4100 ....%2%2.V..SMA.
0x0020: 0004 02a0 0000 0001 003a 0010 6065 0ea0 .........:..`e..
0x0030: b500 0b4a 2e12 0001 7800 f001 a8c0 0001 ...J....x.......
0x0040: 0000 0000 f180 0c04 fdff 0700 0000 8403 ................
0x0050: 0000 7935 8461 0000 0000 b8b8 b8b8 8888 ..y5.a..........
0x0060: 8888 8888 8888 0000 0000 ..........
20:33:13.423860 IP 192.168.1.11.9522 > 192.168.1.240.9522: UDP, length 78
0x0000: 4500 006a 0000 0000 4011 f637 c0a8 010b E..j....@..7....
0x0010: c0a8 01f0 2532 2532 0056 124b 534d 4100 ....%2%2.V.KSMA.
0x0020: 0004 02a0 0000 0001 003a 0010 6065 0ed0 .........:..`e..
0x0030: 7800 f001 a8c0 0001 b500 0b4a 2e12 0001 x..........J....
0x0040: 0000 0000 f180 0d04 fdff 0700 0000 8403 ................
0x0050: 0000 7935 8461 0000 0000 b8b8 b8b8 8888 ..y5.a..........
0x0060: 8888 8888 8888 0000 0000 ..........Was evcc bei der Initialisierung anders macht das der Speedwire-Login nach evcc-restart wieder geht ist mir schleierhaft, hab mal hier gelesen und versucht zu verstehen, aber meine go-Kenntnisse tendieren gegen Null: https://gitlab.com/bboehmke/sunny/-/blob/master/connection.go
Anyway - Ich habe auf die schnelle keine Möglichkeit gefunden da was anzupassen, daher zieht evcc jetzt halt einfach auf einen anderen RPI um und gut ist :-)
bboehmke
commented
2 years ago Soweit ich weiß ist ein listen auf einem Port erstmal exklusiv und kann nur einmal pro IP gleichzeitig verwendet werden. Es gibt zwar mit SO_REUSEPORT die Option einen port mehrfach zu nutzen allerdings hab ich das bisher nie verwendet.
Was mich etwas wundert das es überhaupt möglich ist beide Anwendungen gleichzeitig zustarten. Ich hätte hier mit einer Meldung aller "port already in use" gerechnet.
Wenn ich dazu komme schaue ich da am Wochenende nochmal rein aber ich rechne nicht mit einer einfachen Lösung.
andig
commented
2 years ago Im tcpdump sieht man das der Wechselrichter auf den Login von evcc antwortet, das aber bei evcc nicht mehr ankommt:
Top Analyse 👍🏻
Wenn ich dazu komme schaue ich da am Wochenende nochmal rein aber ich rechne nicht mit einer einfachen Lösung.
Das wär Klasse.
Was mich etwas wundert das es überhaupt möglich ist beide Anwendungen gleichzeitig zustarten. Ich hätte hier mit einer Meldung aller "port already in use" gerechnet.
Ist mir auch unklar, wobei ich wenig Erfahrung mit UDP habe. Ggf. könnte man das mit einem kleinen Experiment verifizieren (2 lokale Listener).
premultiply
commented
2 years ago Die Kommunikation wird ja bei UDP auch mit dem entsprechenden ZIELport aufgebaut. Der lokale Quellport wird im Normalfall dynamisch (beliebiger freier Port) vergeben. Die Gegenstelle antwortet dann als ZIEL auf den ursprünglichen Quellport. Es gibt hier daher keine notwendigkeit für Unicast ausgerechnet mit dem lokalen Quellport 9522 zu arbeiten oder schreibt das Protokoll das zwingend so vor? 9522 ist doch eigentlich der Multicast-Listener-Port und den sollten sich aus Prinzip schon mehrere Anwendungen teilen können müssen, oder?
F-L-0
commented
2 years ago Soweit ich weiß will Speedwire zwingend udp:9522 Ich teile die Meinung das es eigentlich nicht funktionieren sollte 2 Applikationen auf dem selben Port lauschen zu lassen, die zweite sollte eine "Adress already in use" ressource exception bekommen. Grad nachgeschaut, warum auch immer, es ist durchaus bei UDP möglich das mehrere Programme auf dem selben Port lauschen, hier perl (fhem)und evcc unter Raspbian:
root@rpi4-1:~# lsof -iudp:9522
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
perl 15986 fhem 13u IPv4 209859519 0t0 UDP *:9522
evcc 16961 evcc 7u IPv4 209921525 0t0 UDP *:9522Selbst wenn es geht ist es aber glaube ich nicht gut und kann wie bei meinem Setup gesehen zu komischen Fehlerzuständen führen wenn das Programm das zuerst kommt restartet wird (bei mir wird wegen der mqtt Abhängigkeit derzeit evcc nach fhem gestartet).
Soweit ich weiß für die Wechselrichter ist die Kommunikation Unicast UDP Port 9522, während für den EnergyManager eine Multicast-Gruppe auf 239.12.255.254 Port 9522 existiert und jede Sekunde ein Update vom EM geschickt wird.
root@rpi4-1:~# netstat -g
IPv6/IPv4-Gruppenmitgliedschaften
Schnittstelle RefZäh Grupp
--------------- ------ ---------------------
eth0 2 239.12.255.254
[...]Ich weiß nicht ob es eine gute Idee ist SO_REUSEPORT überhaupt anzugehen oder stattdessen besser in der Modulbeschreibung zu dokumentieren das keine anderen Programme auf dem selben Rechner mit den SMA Komponenten kommunizieren dürfen? Schließlich bekommt die evcc sunny lib auch jeglichen Traffic des anderen Programms oder bei passendem Timing Antwortpakete die nicht zur eigenen Anfrage passen und muss programmtechnisch damit umgehen, oder? Ich habe bisher zwar auf beiden Seiten keine komischen Effekte beobachtet, aber möglich wärs.
premultiply
commented
2 years ago Soweit ich weiß will Speedwire zwingend udp:9522
Aber nur eingehend auf Seiten des WR, oder? Der Quellport des Initiators sollte beliebig sein.
andig
commented
2 years ago Ja. Die Response kommt aber immer auf 9522, nutzt dir also nix
premultiply
commented
2 years ago Aaaarg. Wer hat denn das erfunden?
andig
commented
2 years ago Naja, wie willst Du Multicast sonst machen?
premultiply
commented
2 years ago Moment! Wir sprechen hier von Unicast. Nur die Messwerte des SHM und EM werden per Multicast gesendet. Die gezielte Kommunikation zwischen SHM und WR ist Unicast.
bboehmke
commented
2 years ago Auch dort ist der Empfangsport beim Client fix 9522. Bei simplen Protokollen besonders bei embeded Geräten taucht sowas häufiger auf. (nicht schön aber simpel)
bboehmke
commented
2 years ago @F-L-0 ich hab nochmal über das Thema nachgedacht und ich denke es wäre wirklich das Sinnvollste dieses Verhalten einfach zu dokumentieren.
Mir scheint das es (zumindest in go) möglich ist das selbe multicast listen mehrfach zu machen (beim normalen UDP listen geht es nicht). Vielleicht könnte man hier versuchen noch ein zusätzlichen normalen listen auf den port zu machen aber ich weiß nicht ob das wirklich sinnvoll ist.
Ich versuche bei Gelegenheit mir mal SPFSpot genauer anzuschauen vielleicht wird da ja was anders gemacht was in der go lib nützlich wäre. In der nächsten Zeit werde ich allerdings nicht dazu kommen.
andig
commented
2 years ago Dann machen wir hier erstmal zu. Works as expected.
Describe the bug Every time mqtt server is temporary not available (eg restarted), evcc fails to update any sma component from meters section. mqtt connection is re-established once mqtt server is available (updates can be seenon broker side), but polling of sma meters (inversters) keeps failing and only recovers after evcc restart. Issue is reproducable very easy, can provide additional debug/trace logs and configs when relevant/needed.
To Reproduce Steps to reproduce the behavior:
Expected behavior Restart of mqtt server / failing of mqtt connection does not impact communication with sma inverters
Additional information: Tested also to stop/restart influxdb to check if there is the same behaviour. Here errors for writing to influx where logged as expected, but sma inverters continued to update flawlessly, the issue seems to be related to mqtt backend specifically.
EVCC details: Show output of
evcc -vShow output of
evcc dump -c configfile:Show evcc configuration file
evcc.yaml:Show evcc log output with
--log debug:restart MQTT Broker at 21:18:46: evcc --log debug [main ] INFO 2021/11/03 21:18:13 evcc 0.66 (9181925) [main ] INFO 2021/11/03 21:18:13 using config file /etc/evcc.yaml [main ] INFO 2021/11/03 21:18:13 listening at 0.0.0.0:7070 [mqtt ] INFO 2021/11/03 21:18:13 connecting evcc at localhost:1883 [mqtt ] DEBUG 2021/11/03 21:18:13 localhost:1883 connected [sma ] DEBUG 2021/11/03 21:18:14 wait for initial value [sma ] DEBUG 2021/11/03 21:18:14 wait for initial value [lp-1 ] WARN 2021/11/03 21:18:15 poll mode '{always 1h0m0s}' may deplete your battery or lead to API misuse. USE AT YOUR OWN RISK. [cache ] DEBUG 2021/11/03 21:18:15 title: Garage [cache ] DEBUG 2021/11/03 21:18:15 minCurrent: 6 [cache ] DEBUG 2021/11/03 21:18:15 maxCurrent: 16 [cache ] DEBUG 2021/11/03 21:18:15 phases: 2 [cache ] DEBUG 2021/11/03 21:18:15 activePhases: 2 [cache ] DEBUG 2021/11/03 21:18:15 hasVehicle: true [lp-1 ] INFO 2021/11/03 21:18:15 vehicle updated: unknown -> eGolf [cache ] DEBUG 2021/11/03 21:18:15 mode: pv [cache ] DEBUG 2021/11/03 21:18:15 targetSoC: 80 [cache ] DEBUG 2021/11/03 21:18:15 minSoC: 10 [cache ] DEBUG 2021/11/03 21:18:15 vehiclePresent: true [cache ] DEBUG 2021/11/03 21:18:15 vehicleTitle: eGolf [cache ] DEBUG 2021/11/03 21:18:15 vehicleCapacity: 36 [site ] INFO 2021/11/03 21:18:15 site config: [site ] INFO 2021/11/03 21:18:15 meters: grid ✓ pv ✓ battery ✓ [cache ] DEBUG 2021/11/03 21:18:15 siteTitle: Daheim [cache ] DEBUG 2021/11/03 21:18:15 gridConfigured: true [site ] INFO 2021/11/03 21:18:15 grid: power ✓ energy ✓ currents ✓ [site ] INFO 2021/11/03 21:18:15 pv 0: power ✓ energy ✓ currents ✓ [site ] INFO 2021/11/03 21:18:15 battery 0: power ✓ energy ✓ currents ✓ soc ✓ [lp-1 ] INFO 2021/11/03 21:18:15 loadpoint 1: [lp-1 ] INFO 2021/11/03 21:18:15 mode: pv [lp-1 ] INFO 2021/11/03 21:18:15 charger: power ✗ energy ✗ currents ✗ timer ✓ [lp-1 ] INFO 2021/11/03 21:18:15 meters: charge ✗ [lp-1 ] INFO 2021/11/03 21:18:15 vehicles: ✓ [lp-1 ] INFO 2021/11/03 21:18:15 car 0: range ✓ finish ✓ status ✓ climate ✓ [site ] DEBUG 2021/11/03 21:18:15 ---- [site ] DEBUG 2021/11/03 21:18:15 pv power: 0W [cache ] DEBUG 2021/11/03 21:18:15 pvConfigured: true [cache ] DEBUG 2021/11/03 21:18:15 batteryConfigured: true [cache ] DEBUG 2021/11/03 21:18:15 prioritySoC: 70 [cache ] DEBUG 2021/11/03 21:18:15 chargeConfigured: false [cache ] DEBUG 2021/11/03 21:18:15 pvPower: 0 [site ] DEBUG 2021/11/03 21:18:15 grid power: 1142W [site ] DEBUG 2021/11/03 21:18:15 battery power: 0W [cache ] DEBUG 2021/11/03 21:18:15 gridPower: 1142.2 [cache ] DEBUG 2021/11/03 21:18:15 batteryPower: 0 [site ] DEBUG 2021/11/03 21:18:15 grid currents: [2.12 1.67 2.81]A [cache ] DEBUG 2021/11/03 21:18:15 gridCurrents: [2.121 1.665 2.813] [site ] DEBUG 2021/11/03 21:18:15 battery soc 0: 23% [site ] DEBUG 2021/11/03 21:18:15 site power: 1142W [lp-1 ] DEBUG 2021/11/03 21:18:15 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:15 batterySoC: 23 [cache ] DEBUG 2021/11/03 21:18:15 mode: pv [cache ] DEBUG 2021/11/03 21:18:15 chargePower: 0 [cache ] DEBUG 2021/11/03 21:18:15 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:15 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:15 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:18:16 charger status: A [lp-1 ] INFO 2021/11/03 21:18:16 car disconnected [cache ] DEBUG 2021/11/03 21:18:16 connectedDuration: 0s [cache ] DEBUG 2021/11/03 21:18:16 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:16 connectedDuration: 292.238µs [lp-1 ] INFO 2021/11/03 21:18:16 set charge mode: pv [lp-1 ] INFO 2021/11/03 21:18:16 set target soc: 80 [cache ] DEBUG 2021/11/03 21:18:16 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:16 connected: false [cache ] DEBUG 2021/11/03 21:18:16 charging: false [cache ] DEBUG 2021/11/03 21:18:16 enabled: false [lp-1 ] DEBUG 2021/11/03 21:18:16 vehicle status: A [lp-1 ] DEBUG 2021/11/03 21:18:16 vehicle soc: 76% [lp-1 ] DEBUG 2021/11/03 21:18:16 vehicle range: 166km [cache ] DEBUG 2021/11/03 21:18:16 vehicleSoC: 76 [cache ] DEBUG 2021/11/03 21:18:16 chargeRemainingDuration: -1ns [cache ] DEBUG 2021/11/03 21:18:16 chargeRemainingEnergy: 1600 [cache ] DEBUG 2021/11/03 21:18:16 vehicleRange: 166 [lp-1 ] DEBUG 2021/11/03 21:18:16 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:16 homePower: 1142.2 [cache ] DEBUG 2021/11/03 21:18:16 chargePower: 0 [site ] DEBUG 2021/11/03 21:18:25 ---- [site ] DEBUG 2021/11/03 21:18:25 pv power: 0W [cache ] DEBUG 2021/11/03 21:18:25 pvPower: 0 [site ] DEBUG 2021/11/03 21:18:25 grid power: 1175W [site ] DEBUG 2021/11/03 21:18:25 battery power: 0W [site ] DEBUG 2021/11/03 21:18:25 grid currents: [2.26 1.66 2.81]A [site ] DEBUG 2021/11/03 21:18:25 battery soc 0: 23% [cache ] DEBUG 2021/11/03 21:18:25 gridPower: 1175.2 [cache ] DEBUG 2021/11/03 21:18:25 batteryPower: 0 [cache ] DEBUG 2021/11/03 21:18:25 gridCurrents: [2.2600000000000002 1.6640000000000001 2.8120000000000003] [cache ] DEBUG 2021/11/03 21:18:25 batterySoC: 23 [site ] DEBUG 2021/11/03 21:18:25 site power: 1175W [lp-1 ] DEBUG 2021/11/03 21:18:25 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:25 mode: pv [cache ] DEBUG 2021/11/03 21:18:25 chargePower: 0 [cache ] DEBUG 2021/11/03 21:18:25 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:26 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:26 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:18:26 charger status: A [lp-1 ] DEBUG 2021/11/03 21:18:26 next soc poll remaining time: 59m49s [cache ] DEBUG 2021/11/03 21:18:26 connected: false [cache ] DEBUG 2021/11/03 21:18:26 charging: false [cache ] DEBUG 2021/11/03 21:18:26 enabled: false [lp-1 ] DEBUG 2021/11/03 21:18:26 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:26 homePower: 1175.2 [cache ] DEBUG 2021/11/03 21:18:26 chargePower: 0 [site ] DEBUG 2021/11/03 21:18:35 ---- [site ] DEBUG 2021/11/03 21:18:35 pv power: 0W [cache ] DEBUG 2021/11/03 21:18:35 pvPower: 0 [site ] DEBUG 2021/11/03 21:18:35 grid power: 1175W [site ] DEBUG 2021/11/03 21:18:35 battery power: 0W [site ] DEBUG 2021/11/03 21:18:35 grid currents: [2.26 1.66 2.8]A [site ] DEBUG 2021/11/03 21:18:35 battery soc 0: 23% [cache ] DEBUG 2021/11/03 21:18:35 gridPower: 1174.9 [cache ] DEBUG 2021/11/03 21:18:35 batteryPower: 0 [cache ] DEBUG 2021/11/03 21:18:35 gridCurrents: [2.259 1.6620000000000001 2.801] [cache ] DEBUG 2021/11/03 21:18:35 batterySoC: 23 [site ] DEBUG 2021/11/03 21:18:35 site power: 1175W [lp-1 ] DEBUG 2021/11/03 21:18:35 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:35 mode: pv [cache ] DEBUG 2021/11/03 21:18:35 chargePower: 0 [cache ] DEBUG 2021/11/03 21:18:35 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:36 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:36 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:18:36 charger status: A [lp-1 ] DEBUG 2021/11/03 21:18:36 next soc poll remaining time: 59m39s [cache ] DEBUG 2021/11/03 21:18:36 connected: false [cache ] DEBUG 2021/11/03 21:18:36 charging: false [cache ] DEBUG 2021/11/03 21:18:36 enabled: false [lp-1 ] DEBUG 2021/11/03 21:18:36 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:36 homePower: 1174.9 [cache ] DEBUG 2021/11/03 21:18:36 chargePower: 0 [site ] DEBUG 2021/11/03 21:18:45 ---- [site ] DEBUG 2021/11/03 21:18:45 pv power: 0W [cache ] DEBUG 2021/11/03 21:18:45 pvPower: 0 [site ] DEBUG 2021/11/03 21:18:45 grid power: 1174W [site ] DEBUG 2021/11/03 21:18:45 battery power: 0W [cache ] DEBUG 2021/11/03 21:18:45 gridPower: 1173.6000000000001 [cache ] DEBUG 2021/11/03 21:18:45 batteryPower: 0 [site ] DEBUG 2021/11/03 21:18:45 grid currents: [2.26 1.66 2.8]A [site ] DEBUG 2021/11/03 21:18:45 battery soc 0: 23% [site ] DEBUG 2021/11/03 21:18:45 site power: 1174W [lp-1 ] DEBUG 2021/11/03 21:18:45 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:45 gridCurrents: [2.2560000000000002 1.659 2.8040000000000003] [cache ] DEBUG 2021/11/03 21:18:45 batterySoC: 23 [cache ] DEBUG 2021/11/03 21:18:45 mode: pv [cache ] DEBUG 2021/11/03 21:18:45 chargePower: 0 [cache ] DEBUG 2021/11/03 21:18:45 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:46 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:46 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:18:46 charger status: A [lp-1 ] DEBUG 2021/11/03 21:18:46 next soc poll remaining time: 59m29s [cache ] DEBUG 2021/11/03 21:18:46 connected: false [cache ] DEBUG 2021/11/03 21:18:46 charging: false [cache ] DEBUG 2021/11/03 21:18:46 enabled: false [lp-1 ] DEBUG 2021/11/03 21:18:46 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:46 homePower: 1173.6000000000001 [cache ] DEBUG 2021/11/03 21:18:46 chargePower: 0 [mqtt ] ERROR 2021/11/03 21:18:46 localhost:1883 connection lost: EOF [mqtt ] DEBUG 2021/11/03 21:18:48 timeout [sma ] ERROR 2021/11/03 21:18:50 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:18:50 login failed: no packet received in timeout [mqtt ] DEBUG 2021/11/03 21:18:52 timeout [mqtt ] DEBUG 2021/11/03 21:18:52 timeout [mqtt ] DEBUG 2021/11/03 21:18:52 timeout [sma ] ERROR 2021/11/03 21:18:55 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:18:55 login failed: no packet received in timeout [site ] DEBUG 2021/11/03 21:18:55 ---- [site ] ERROR 2021/11/03 21:18:56 updating pv meter 0: update timeout: 11s [site ] DEBUG 2021/11/03 21:18:56 pv power: 0W [site ] DEBUG 2021/11/03 21:18:56 grid power: 1187W [cache ] DEBUG 2021/11/03 21:18:56 pvPower: 0 [cache ] DEBUG 2021/11/03 21:18:56 gridPower: 1187.3 [site ] ERROR 2021/11/03 21:18:56 updating battery meter 0: update timeout: 12s [site ] DEBUG 2021/11/03 21:18:56 battery power: 0W [site ] DEBUG 2021/11/03 21:18:56 grid currents: [2.31 1.66 2.8]A [cache ] DEBUG 2021/11/03 21:18:56 batteryPower: 0 [cache ] DEBUG 2021/11/03 21:18:56 gridCurrents: [2.308 1.663 2.803] [site ] ERROR 2021/11/03 21:18:56 updating battery soc 0: update timeout: 12s [site ] DEBUG 2021/11/03 21:18:56 site power: 1187W [lp-1 ] DEBUG 2021/11/03 21:18:56 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:56 batterySoC: 0 [cache ] DEBUG 2021/11/03 21:18:56 mode: pv [cache ] DEBUG 2021/11/03 21:18:56 chargePower: 0 [cache ] DEBUG 2021/11/03 21:18:56 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:18:56 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:18:56 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:18:56 charger status: A [lp-1 ] DEBUG 2021/11/03 21:18:56 next soc poll remaining time: 59m19s [cache ] DEBUG 2021/11/03 21:18:56 connected: false [cache ] DEBUG 2021/11/03 21:18:56 charging: false [cache ] DEBUG 2021/11/03 21:18:56 enabled: false [lp-1 ] DEBUG 2021/11/03 21:18:56 charge power: 0W [cache ] DEBUG 2021/11/03 21:18:56 homePower: 1187.3 [cache ] DEBUG 2021/11/03 21:18:56 chargePower: 0 [mqtt ] DEBUG 2021/11/03 21:18:57 timeout [mqtt ] DEBUG 2021/11/03 21:18:57 timeout [mqtt ] DEBUG 2021/11/03 21:18:57 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [mqtt ] DEBUG 2021/11/03 21:18:58 timeout [sma ] ERROR 2021/11/03 21:19:00 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:00 login failed: no packet received in timeout [mqtt ] DEBUG 2021/11/03 21:19:02 timeout [mqtt ] DEBUG 2021/11/03 21:19:02 timeout [mqtt ] DEBUG 2021/11/03 21:19:02 timeout [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 connected [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/minSoC/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/targetSoC/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/minCurrent/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/maxCurrent/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/phases/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/site/prioritySoC/set [mqtt ] DEBUG 2021/11/03 21:19:04 localhost:1883 subscribe evcc/loadpoints/1/mode/set [sma ] ERROR 2021/11/03 21:19:05 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:05 login failed: no packet received in timeout [site ] DEBUG 2021/11/03 21:19:05 ---- [site ] ERROR 2021/11/03 21:19:06 updating pv meter 0: update timeout: 21s [site ] DEBUG 2021/11/03 21:19:06 pv power: 0W [site ] DEBUG 2021/11/03 21:19:06 grid power: 1162W [cache ] DEBUG 2021/11/03 21:19:06 pvPower: 0 [cache ] DEBUG 2021/11/03 21:19:06 gridPower: 1162.3 [site ] ERROR 2021/11/03 21:19:06 updating battery meter 0: update timeout: 22s [site ] DEBUG 2021/11/03 21:19:06 battery power: 0W [site ] DEBUG 2021/11/03 21:19:06 grid currents: [2.21 1.67 2.8]A [site ] ERROR 2021/11/03 21:19:06 updating battery soc 0: update timeout: 22s [cache ] DEBUG 2021/11/03 21:19:06 batteryPower: 0 [cache ] DEBUG 2021/11/03 21:19:06 gridCurrents: [2.205 1.669 2.801] [cache ] DEBUG 2021/11/03 21:19:06 batterySoC: 0 [site ] DEBUG 2021/11/03 21:19:06 site power: 1162W [lp-1 ] DEBUG 2021/11/03 21:19:06 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:06 mode: pv [cache ] DEBUG 2021/11/03 21:19:06 chargePower: 0 [cache ] DEBUG 2021/11/03 21:19:06 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:19:06 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:19:06 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:19:06 charger status: A [lp-1 ] DEBUG 2021/11/03 21:19:06 next soc poll remaining time: 59m9s [cache ] DEBUG 2021/11/03 21:19:06 connected: false [cache ] DEBUG 2021/11/03 21:19:06 charging: false [cache ] DEBUG 2021/11/03 21:19:06 enabled: false [lp-1 ] DEBUG 2021/11/03 21:19:06 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:06 homePower: 1162.3 [cache ] DEBUG 2021/11/03 21:19:06 chargePower: 0 [sma ] ERROR 2021/11/03 21:19:10 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:10 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:15 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:15 login failed: no packet received in timeout [site ] DEBUG 2021/11/03 21:19:15 ---- [site ] ERROR 2021/11/03 21:19:16 updating pv meter 0: update timeout: 31s [site ] DEBUG 2021/11/03 21:19:16 pv power: 0W [site ] DEBUG 2021/11/03 21:19:16 grid power: 1148W [cache ] DEBUG 2021/11/03 21:19:16 pvPower: 0 [cache ] DEBUG 2021/11/03 21:19:16 gridPower: 1148.1000000000001 [site ] ERROR 2021/11/03 21:19:16 updating battery meter 0: update timeout: 32s [site ] DEBUG 2021/11/03 21:19:16 battery power: 0W [site ] DEBUG 2021/11/03 21:19:16 grid currents: [2.15 1.66 2.8]A [cache ] DEBUG 2021/11/03 21:19:16 batteryPower: 0 [site ] ERROR 2021/11/03 21:19:16 updating battery soc 0: update timeout: 32s [site ] DEBUG 2021/11/03 21:19:16 site power: 1148W [cache ] DEBUG 2021/11/03 21:19:16 gridCurrents: [2.149 1.6640000000000001 2.803] [lp-1 ] DEBUG 2021/11/03 21:19:16 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:16 batterySoC: 0 [cache ] DEBUG 2021/11/03 21:19:16 mode: pv [cache ] DEBUG 2021/11/03 21:19:16 chargePower: 0 [cache ] DEBUG 2021/11/03 21:19:16 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:19:16 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:19:16 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:19:16 charger status: A [lp-1 ] DEBUG 2021/11/03 21:19:16 next soc poll remaining time: 58m59s [cache ] DEBUG 2021/11/03 21:19:16 connected: false [cache ] DEBUG 2021/11/03 21:19:16 charging: false [cache ] DEBUG 2021/11/03 21:19:16 enabled: false [lp-1 ] DEBUG 2021/11/03 21:19:16 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:16 homePower: 1148.1000000000001 [cache ] DEBUG 2021/11/03 21:19:16 chargePower: 0 [sma ] ERROR 2021/11/03 21:19:20 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:20 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:25 login failed: no packet received in timeout [sma ] ERROR 2021/11/03 21:19:25 login failed: no packet received in timeout [site ] DEBUG 2021/11/03 21:19:25 ---- [site ] ERROR 2021/11/03 21:19:26 updating pv meter 0: update timeout: 41s [site ] DEBUG 2021/11/03 21:19:26 pv power: 0W [site ] DEBUG 2021/11/03 21:19:26 grid power: 1157W [cache ] DEBUG 2021/11/03 21:19:26 pvPower: 0 [cache ] DEBUG 2021/11/03 21:19:26 gridPower: 1157.2 [site ] ERROR 2021/11/03 21:19:26 updating battery meter 0: update timeout: 42s [site ] DEBUG 2021/11/03 21:19:26 battery power: 0W [site ] DEBUG 2021/11/03 21:19:26 grid currents: [2.17 1.66 2.82]A [cache ] DEBUG 2021/11/03 21:19:26 batteryPower: 0 [cache ] DEBUG 2021/11/03 21:19:26 gridCurrents: [2.174 1.6640000000000001 2.817] [site ] ERROR 2021/11/03 21:19:26 updating battery soc 0: update timeout: 42s [site ] DEBUG 2021/11/03 21:19:26 site power: 1157W [lp-1 ] DEBUG 2021/11/03 21:19:26 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:26 batterySoC: 0 [cache ] DEBUG 2021/11/03 21:19:26 mode: pv [cache ] DEBUG 2021/11/03 21:19:26 chargePower: 0 [cache ] DEBUG 2021/11/03 21:19:26 chargeCurrent: 0 [cache ] DEBUG 2021/11/03 21:19:26 chargedEnergy: 0 [cache ] DEBUG 2021/11/03 21:19:26 chargeDuration: 1h1m59s [lp-1 ] DEBUG 2021/11/03 21:19:26 charger status: A [lp-1 ] DEBUG 2021/11/03 21:19:26 next soc poll remaining time: 58m49s [cache ] DEBUG 2021/11/03 21:19:26 connected: false [cache ] DEBUG 2021/11/03 21:19:26 charging: false [cache ] DEBUG 2021/11/03 21:19:26 enabled: false [lp-1 ] DEBUG 2021/11/03 21:19:26 charge power: 0W [cache ] DEBUG 2021/11/03 21:19:26 homePower: 1157.2 [cache ] DEBUG 2021/11/03 21:19:26 chargePower: 0If using Docker: Show output of
docker run andig/evcc -v:Show evcc log output with
docker logs: