ahoy icon indicating copy to clipboard operation
ahoy copied to clipboard

[Bug] Viele Reboot mit ESP32 im laufe des Tages 0.8.113

Open blueline13 opened this issue 10 months ago • 49 comments

Platform

ESP32

Assembly

I did the assebly by myself

nRF24L01+ Module

nRF24L01+ plus

Antenna

circuit board

Power Stabilization

Elko (~100uF)

Connection picture

  • [ ] I will attach/upload an Image of my wiring

Version

0.8.113

Github Hash

177420f

Build & Flash Method

AhoyDTU Webinstaller

Setup

  • ESP 32
  • NRF
  • CMT
  • MQTT
  • API
  • KEIN DISPLAY
  • Limit Regelung

Debug Serial Log output

Siehe Logfile am Ende

Error description

Immer wieder Reboots während die Inverter aktiv sind. Während der Nacht läuft die DTU durch. Das einzige was noch aufgefallen ist, wenn der Zeit Intervall in dem die DTU die Daten sendet. Steht er auf 10 Sekunden ist das deutlich weniger als wenn der Intervall auf 5 Sekunden steht. Ich habe mal die Teile der Reboot aus dem Serial log rausgeschnippelt und hoffe das es hilft. Wenn ihr noch etwas braucht was ich gerade vergessen habe, reiche ich es gerne nach. ESP32-Reboot.log

blueline13 avatar Apr 26 '24 18:04 blueline13

Hi. Ich hatte das Problem bei früheren Versionen auch schonmal. Es lag bei mir ganz banal an der Stromversorgung. Ich hatte die DTU seinerzeit am USB-Anschluss meines Monitors angeschlossen. Nachdem ich der DTU ein eigenes Netzteil spendiert hatte (einfacher Samsung-Stecker fürs Handy) läuft alles problemlos. LG

SnakeGER avatar Apr 26 '24 21:04 SnakeGER

@SnakeGER Danke für den Hinweis und ja das Netzteil und USB-Kabel ist eine üble Fehlerquelle! Das kenne ich nur zu gut vom ESP Zoo der hier bei mir so vor sich hin werkelt.

Doch in diesem Fall ist das sicher nicht die Ursache, da es mit anderen Version ohne Restarts läuft. Zudem gab es in der letzten Zeit mehrere Berichte mit ESP32 und Neustarts. Wenn du dir das Log anschaust wirst du sehen das der kleine Waldi(Watchdog) zugeschlagen hat und wenn auf einmal die Uptime nicht mehr zig Tage(bis zum nächsten FW update) ist sondern nur Stunden, dann liegt es mit extrem hoher Wahrscheinlichkeit an der FW. Damit die Entwickler hier nicht nur die Aussage bekommen "geht nicht" sonder auch gleich ein paar Daten zum schauen ist das Serial Log dabei.

Du hast aber Recht man kann nicht oft genug auf "miese" Netzteile und USB Kabel hinweisen!

blueline13 avatar Apr 27 '24 04:04 blueline13

danke für's Log, das ist wahr je mehr Hinweise um so einfacher lässt sich auf die Ursache schließen.

Du schreibst Limit Regelung, kann ich hierzu noch Details erfahren?

  • über MqTT oder API
  • interval (limit als auch Abfrage)
  • wie viele Inverter sind im Spiel
  • ist die Kommunikation sonst stabil
  • ist das Verhalten ohne Regelung identisch

lumapu avatar Apr 27 '24 09:04 lumapu

Ja na klar hier die Infos.

  • NUR das Limit selber wird über die API geschrieben.
  • Alles was lesend ist, hole ich vom MQTT des ioBroker. Keine extra API Anfrage an die DTU.
  • Wenn ich Limits über die API schreibe, dann ist der kürzeste Intervall 20 Sekunden. Warte auf das ACK von der DTU und dann nochmal so grob 12 Sekunden bis die Inverter das grob ausgeregelt haben.
  • Sonst würde ich sagen das es nicht hakt, habe öfter ein Auge auf das WEB-Log und da kommen die Werte brav in dem Intervall an den man zum Lesen vorgibt. Auch die Weboberfläche verzögert nichts. Reagiert immer Flott.
  • Ich habe bei einem Intervall von 10 Sekunden(unter Settings/Inverter der Wert) so grob 4-5 Neustarts pro Tag. Bei derzeit 5 Sekunden ist es grob das doppelte, unten ein Überlick der Uptime der DTU vom iobroker, das du dir ein Bild davon machen kannst. Da gibt es auch keine fest Rhythmus in dem die DTU neu startet.
  • Ich habe 4 Inverter 1xTSUN M1600(NRF), 2x HMS2000 und 1xHMS1000.
  • Wenn die Abweichung vom Inverter größer ist dann werden mal alle 4 Inverter geschrieben über die API, bei kleinen Abweichungen ist es auch mal nur 1 Inverter.
  • Mhhhh beim letzten Punkt .... die Limit Regelung ist immer aktiv solange Strom produziert. Ohne Regelung habe ich nicht getestet. Ist ein BKW mit 6,5kW😇 ich kann aber Morgen früh mal die Regelung abschalten, die DTU ist immer so zwischen 6-8 Uhr neu gestartet. Reiche ich dann morgen Vormittag nach.

Was ich sonst noch im Log so sehen konnte, das der Reset der DTU nicht wirklich direkt etwas mit den Limits zu hat. Die DTU startet auch neu wenn mehrere Minuten kein Limit geschrieben wurde. Wenn es hilft kann ich Morgen auch nochmal den ganzen Tag das log laufen lassen, mit abgeschalteter Regelung. Das ist mein Ersatz ESP mit dem ich diese Test fahre und der normal produktive ESP läuft noch mit der 0.8.46, weil es da kein Limit Probleme gibt. Ich kann aber auch noch ein openDTU Fusion Board benutzen wenn es hilft. Wollte aber mal wieder eine aktuelle Version testen. Vielleicht dazu noch das andere Ticket #1412 wo das merkwürdige Verhalten bei der Limit Regelung beschrieben ist. mit der aktuellen Version.

Ich hoffe das ich alle deine Fragen beantwortet habe, sonst frage gerne weiter. grafik

blueline13 avatar Apr 27 '24 14:04 blueline13

danke für deine ausführliche Antwort, die hilft sehr weiter. Wenn du ein Log liefern kannst wäre es noch besser, allerdings vermute ich, das auch hier nur die Waldis zu sehen sind. Nach dem ersten oder zweiten reboot kannst du getrost wieder mit der Limitierung weitermachen. Ich hoffe den Fehler dann auch im Code identifizieren zu können, kann mir aber vorstellen dass der komplex sein wird.

lumapu avatar Apr 27 '24 18:04 lumapu

Nur eine Sicherheitsfrage vorweg, welche Haken soll ich für das Serial Log anhaken?

blueline13 avatar Apr 27 '24 18:04 blueline13

serial Debug reicht aus. wichtiger sind die Meldungen vom ESP selbst

lumapu avatar Apr 27 '24 19:04 lumapu

@lumapu Ich würde dir gerne ein Log geben aber die DTU rennt seit heute Morgen bis 13 Uhr in eins durch ohne einen Reset. Habe meine Regelung nun wieder aktiv. Scheint wohl wirklich an der Limit Regelung zu liegen. Mal sehen wie lange die jetzt läuft bis sie einen restart macht. Kaum nach dem die Regelung aktiv ist hat die DTU einen Neustart hingelegt. Soll ich die DTU noch ein paar Neustarts machen lassen und dir heute Abend das ganze Log von heute hochladen?

Wenn ich noch weitere Dinge testen soll, lass es mich wissen.

blueline13 avatar Apr 28 '24 11:04 blueline13

Jetzt müssen wir verstehen was die Regelung ändert, ich denke erst nach einer Änderung sind weitere Tests hilfreich. Die Details stehen glaube ich oben schon alle, falls ich noch eine Info brauche, melde ich mich

lumapu avatar Apr 28 '24 13:04 lumapu

kannst du den Wertebereich nennen, den deine Regelung ausgibt - ich will ausschließen, dass evtl. negative Werte gesendet werden.

lumapu avatar Apr 29 '24 19:04 lumapu

die negativen Werte können es nicht sein, das wird bei der Übernahme der Daten nicht ermöglicht und würde wenn nur den Wechselrichter stören

lumapu avatar Apr 29 '24 21:04 lumapu

bitte nochmal mit der 0.8.117 testen. Auch die 0.8.116 ist möglich, diese läuft bei mir jetzt schon 3 Tage und 15h

lumapu avatar May 08 '24 22:05 lumapu

Moin, die 116 lief seit dem Erscheinungsdatum und das Problem war noch vorhanden. Die 117 läuft und mal schauen was passiert.

blueline13 avatar May 09 '24 05:05 blueline13

Status 0.8.117: Leider kann ich nichts positives berichten. Habe noch immer mehrere Neustarts am Tag. Braucht ihr noch etwas, kann ich noch etwas testen?

blueline13 avatar May 10 '24 16:05 blueline13

Kannst du bitte prüfen, ob die 0.8.118 Besserung zeigt? Ich habe die Webserver Lib im Verdacht und habe gesehen, dass es eine neue Version gibt - diese wird jetzt verwendet. Interasant wäre, ob die Reboots vor allem dann passieren, wenn die Regelung aktiv ist und du gleichzeitig auf den Webserver per Browser zugreifst.

Gleichzeitig habe ich Ende April bei mir einen Fehler gesehen, der auch mit dem Webserver zu tun hat. Den Issue habe ich gerade angelegt und verlinke ihn hier zur Referenz: https://github.com/esphome/ESPAsyncWebServer/issues/28

lumapu avatar May 10 '24 23:05 lumapu

Moin, die 118 läuft. Ich habe fast immer ein zusätzliches Webbrowser Fenster auf die default Webseite offen. Das habe ich gerade geschlossen. Aber ich habe nie wirklich etwas darüber gemacht, eher als Faulheit um nicht jedes mal den Link einzugeben.

Wenn ich mich recht entsinne dann hat das Arbeiten auf der Weboberfläche keinen wirklichen Einfluss auf die Reboots. Ich würde aus den Beobachtung eher sagen das mit der Häufigkeit zu tun hat wie oft Limits geschrieben werden.

Zudem ist mir dabei etwas aufgefallen was sich eher komisch ausnimmt aber mit der 118 deutlich besser darstellt. Die letzten Tage war es mit einer extremen Häufigkeit das immer, meistens beim letzten Inverter, das Limit beim ersten schreiben überhaupt nicht angenommen wurde oder kein ACK kam. Meistens kam es dann beim zweiten-nten Versuch unverzüglich. Die neue Lib scheint wirklich an der Stelle etwas gebracht zu haben oder meine Inverter hatten ihre zicken Tage 😉 Wenn ich mir dein ESPHome Link anschaue, dann kann ich HEUTE ausschließen das ich einen zweiten Client habe der auf die DTU zugreift. Mal schauen was heute am Ende des Tages zu sehen ist. Eins was auch gestern aufgefallen ist, es hatte einen unterscheide gemacht in welchen zeitlichem Abstand die Limit geschrieben wurden. Ich hatte bis gestern Mittag eine Verzögerung von grob 100ms nach jedem Schreiben eingebaut. Aber das war irgendwie auch das Problem als ich es dann ohne Verzögerung geschrieben(nur die Laufzeiten im ioBroker zwischen 4-10ms) hatte lief es etwas runder und die Limits wurde etwas besser angenommen. Aber kein Vergleich zu heute, heute läuft es richtig guuut was die Schwuppigkeit beim Limit schreiben angeht! 😃

blueline13 avatar May 11 '24 09:05 blueline13

Das freut mich zu hören, wenn es weiterhin auftritt könntest du mich noch mit deinem Script versorgen, sodass ich es versuchen kann bei mir nachzustellen. Das zusätzliche Browserfenster macht schon was aus, da es ja nach Ansicht (Index oder live) im Hintergrund die Daten aktualisiert und damit die API aufruft.

lumapu avatar May 11 '24 10:05 lumapu

Leider zeigt die 118 noch immer Reboots. Ich kann aber definitiv sagen das es mit der Häufigkeit beim Schreiben von Limit zusammenhängt. Einmal Bewölkung und das andere mal Lasten im Haus.

Na klar bekommst du das Script! Ich gehe mal davon aus das dir der Teil ausreicht wo die DTU angesprochen wird?

Der Teil liegt in einer Funktion die mit einem Limit in Watt gefüttert wird. Dann füge ich noch mal schnell ein paar Kommentare für das bessere Verständnis ein :wink: Das ganze ist in Blockly. Aber bitte um etwas Nachsicht, da es noch nicht wirklich fertig ist, da die DTU sich ja auch noch etwas verändert. Ballast raus und Übersicht rein kommen dann später 😇

blueline13 avatar May 11 '24 13:05 blueline13

@blueline13 Wie oft und mit welchen Abstand schreibst Du die Limits? Ich schreibe alle 60 Sekunden, wenn nötig, das Limit. Komme so auf eine maximale Tageseinspeisung von knapp 10% vom Ertrag.

dtuuser avatar May 11 '24 14:05 dtuuser

@dtuuser Ich glaube ich treibe die DTU & Inverter an ihre Grenzen wenn viel gereglt werden muss. Es gibt einen 5 Sekunde intervall in dem die Lestungsabweichung geprüft wird, wenn keine Limits geschrieben werden. Ist die Abweichung grüßer als -40 oder +10 Watt Bezug, wird als nächstes gerpüft ob das neue Limit pro Inverter mehr als 0.2% vom vorherigen % Wert abweicht um unnöiges Schreiben von Limits zu vermeiden. Wird ein Limit auf einen WR geschrieben wird geprüft ob das Limit auch akzeptiert wurde und danach werden Pausen eingefügt zwischen 8-15 Sekunden, die die Inverter für einen stabilen Betrieb brauchen um sich nicht abzuschalten wenn mal ein paar Limits hintereinander kommen. Im kürzesten Intervall können derzeit alle 10 Sekunden Limits kommen. Aber da der Webserver in der DTU derzeit etwas hakt, könnten vielleicht die Intervalle auch noch kürzer sein. Mal sehen was geht wenn alles schnurrt :joy:

Ich galube das 6,5kWp BKW 😇 kann bis zu 55 kWh pro Tag liefern und ich komme bei mir auf eine Einspeisung dabei von grob 0,5-1kW pro Tag. Wobei nicht auf 0 sondern auf 20Watt Einspesung gereglt wird. Achja und dann wird auch noch demnächst die Temperatur der Inverter mit geprüft und werden dann auch dynamisch runter geregelt. Denn über 60°C im Inverter kann nicht gut sein für seine Elektronik auch wenn die gesamten Bauteile für den erweiterten Temperaturbeireich gewählt wurden. Die Inverter sollen ja schön lange halten 😉

blueline13 avatar May 11 '24 15:05 blueline13

@lumapu So ich habe das Script nun etwas besser kommentiert und ich hoffe ich habe nichts wichtiges übersehen. Sicher ist da mehr drin als nötig aber wie immer ist es "historisch gewachsen" 😂 und nimmt an vielen Stellen noch Rücksicht auf alte Versionen oder wo es mal rumpelte bei der Regelung. Auch sind noch Teile drin die nicht für das reinen Regeln zuständig sind sonder eher für das ganze drumherum das ich sonst noch benötige. Wenn du trotzdem noch was wissen möchtest, werde ich gerne versuche das besser zu beschreiben warum ich das mache. Sonst kann ich es auch versuchen weiter zu entschlacken. Lasse mich mal überraschen ob die Kommentare so reichen. Ich konnte bei mir keine Export Datei schreiben und habe es über die Zwischenablage kopiert. Limit Script.txt

blueline13 avatar May 11 '24 15:05 blueline13

@blueline13 Oha. Vielen Dank für die vielen Infos. Ich prüfe alle 10 Sekunden den Stromzähler und regel dann runter oder rauf. Aber das nächste Limit setze ich erst nach frühestens 60 Sekunden. Mit der Temperatur habe ich noch garnicht auf der Liste. Aber irgendwie logisch. Heute hatte ich ein Max von 57,2 Grad. Bei einem Limit am WR von 20Watt, bekomme ich manchmal 40 Volt von den Solarzellen. Das kann ja auch nicht gut sein, oder?

dtuuser avatar May 11 '24 17:05 dtuuser

@dtuuser Die 40 Volt sind für die Hoymiles Inverter keine Problem, da verkraften die bis zu 60 Volt und da ist noch genug Luft. Hohe Temperaturen erzeugt eine künstlicher Alterung der Bauteile und das macht Geräten viel mehr zu schaffen. Ich habe auch einen Inverter der abgesetzt an einer kühlen Wand in der Garage hängt. Der war unter Vollast auch über 70°C "warm" geworden 🙈 Also ein Lüfter spendiert und dann war sein Maximalwert nur 45°C. Die 45°C sind für mich OK wo ich weiß der wird lange laufen. Ich glaube wir rutschen hier aber gerade ein wenig ab vom Hauptthema.

blueline13 avatar May 11 '24 18:05 blueline13

ab der 0.8.122 gibt es eine neue Möglichkeit den Fehlern auf die schliche zu kommen. Der ESP 32 hat jetzt unter /system einen Button um Coredumps herunterzuladen. Das schöne: man braucht keinen PC per USB verbinden und kann den Dump auch viel später noch laden. Der ESP speichert in seinem Dateisystem beim Absturz seinen Stacktrace. Die geladene Datei ist erst mal unleserlich, mit der zugehörigen elf Datei kann man daraus jedoch rekonstruieren wo der ESP hängengeblieben ist.

Falls ihr so einen Dump für mich habt könnt ihr mir diesen gerne zur Verfügung stellen (Discord oder per Mail [email protected]).

Bitte nur Coredumps senden, wenn der ESP mit der Version 0.8.122 oder neuer abgestürzt ist.

lumapu avatar May 25 '24 21:05 lumapu

@lumapu Hallo, ich habe jetzt einige Reboots und einmal Stromlos hinter mir. Doch bei mir gibt es nur eine geschweifte Klammer als Download. grafik

blueline13 avatar May 26 '24 08:05 blueline13

das ist eigenartig, dann kann er bei dir nicht auf die Partition zugreifen. Welchen ESP und welche Installationsmethode hast du verwendet?

lumapu avatar May 26 '24 09:05 lumapu

Ich habe einen normalen ESP32 und die letzten Versionen sind immer per OTA installiert worden. Ich glaube davor war das mit eurem Webinstaller und Erase gewesen.

Soll ich den mal auf eine bestimmte Weg neu flaschen und wenn ja kann ich dann ein Backup einspielen oder am besten alles neu einrichten?

blueline13 avatar May 26 '24 09:05 blueline13

im Prinzip hat du alles so gemacht wie ich auch. Daher wundert es mich, dass es bei dir nicht funktioniert. Hast du einen zweiten ESP? Ich könnte in der nächsten Version eine Fehlermeldung zwischen den geschweiften Klammern ausgeben.

lumapu avatar May 26 '24 10:05 lumapu

Im Moment läuft die Test-DTU. Dann habe ich noch eine zweite wo noch die 0.8.46 drauf ist und ich kann auch noch einen openDTU Fuison Board dienen.

Am schnellsten geht es wenn ich mal eben meine zweite ESP32 DTU neu flashe..... melde mich nach dem nächsten Reboot 😄

blueline13 avatar May 26 '24 10:05 blueline13

@lumapu Habe dir gerade zwei coredumps per Mail geschickt.

Bei der zweiten DTU habe ich euren neuen Webinstaller genommen und gleich die 0.8.122 genommen. Da stand der Dump sofort zur Verfügung.

blueline13 avatar May 26 '24 15:05 blueline13