search

lumapu / ahoy

Various tools, examples, and documentation for communicating with Hoymiles microinverters
https://ahoydtu.de
Other
953 stars 224 forks source link

Zeitkritikalität in der Haupt-Loop? #24

Closed dad401 closed 2 years ago

dad401 commented 2 years ago

Wie kritisch ist eigentlich die Ausführung innerhalb der Hauptschleife (Senden und Buffer lesen)?

In Tasmota gibt es Funktionsaufrufe, welche z.B. jede 50ms oder jede Sekunde durchgeführt werden. Wäre es prinzipiell ausreichend, wenn Senden und Empfangsbuffer auslesen nur jede Sekunde durchlaufen werden, oder sind hier Probleme bekannt?

lumapu commented 2 years ago

Prinzipiell keine schlechte Idee. Man könnte es mit der Senderoutine zusammen laufen lassen, oder einfach einen neuen 'ticker' anlegen. Bin um jeden Hinweis dankbar, der das System stabiler macht. Bei diesem Ansatz kann man ja gleich testen, wie stark der CircularBuffer wirklich ausgelastet ist - solange er nicht voll ist wird man auch keine Daten verlieren. Auch das Senden entspricht ja gerade eher einer Burst Anfrage, jede Sekunde wird gefragt - sehr oft kommen identische Pakete zurück, die dann aussortiert werden.

In der neuesten Version (0.3.5) habe ich einen Fix eingebaut, wenn kein MQTT eingerichtet war. Hierdurch war das System praktisch unbedienbar.

dad401 commented 2 years ago

Das ist auch eine Idee, dass ich anstatt dem Ticker gleich den "Sekundenaufruf" von Tasmota verwende. Mein POC auf Basis Deines Codes funktioniert inzwischen, aber leider habe ich auch Stabilitätsprobleme. Ich überlege diese nur auf das wichtigste zu vereinfachen - das was eben bisher auslesbar ist. Auch die Anzeige von 4 Kanälen ist in der Darstellung (Tasmotalike) genauer zu überlegen. Pro Inverter mehrere Ausgabezeilen sind auch nicht so toll. Na mal sehen... 202205 4-191317-screenshot

EDIT: Noch eine Frage: Ist die CRC-Berechnung hier "speziell"? Ich frage nur, weil ich die CRC-Funktionen umbenennen musste, da diese mit vorhandenen CRC-Funktionen kollidierten. Insbesondere crc8 und crc16 gibt es innerhalb Tasmota bereits.

lumapu commented 2 years ago

So speziell sind die beiden Funktionen nicht, prüfe einfach die Startbedingungen und die Polynome, ich denke die dürften identisch sein. CRC16 entspricht der Modbus Definition

stefan123t commented 2 years ago

Wie kritisch ist eigentlich die Ausführung innerhalb der Hauptschleife (Senden und Buffer lesen)? In Tasmota gibt es Funktionsaufrufe, welche z.B. jede 50ms oder jede Sekunde durchgeführt werden. Wäre es prinzipiell ausreichend, wenn Senden und Empfangsbuffer auslesen nur jede Sekunde durchlaufen werden, oder sind hier Probleme bekannt?

Das hängt m.E. vom nRF24L01+ ab, soweit ich die Informationen dazu gelesen habe hat der nRF einen eigenen Receive Buffer. Aber wieviele Nachrichten der enthalten kann weiß ich nicht. Prinzipiell ist der Empfang schon eine zeitkritische Angelegenheit, wir haben m.W. dafür ja sogar den IRQ mit dem Interrupt Eingang verbunden und einen kleinen Handler im Code.

Wie zeitkritisch die Senderoutine ist weiß ich nicht. Die schickt ja ihre Daten per SPI an den nRF und der sendet sie dann autark on-the-air raus.

Ob es reicht jede Sekunde den Empfangsbuffer zu lesen wage ich aber zu bezweifeln.

Beim Senden und Empfangen sollten m.E. ähnlich wie im ahoy.py Code auch die Anfragen mit den Antworten zusammenpassen. Man kann ja ggf. sogar einzelne Pakete erneut anfordern, wie Jan-Jonas gestern im Forum beschrieben hat funktioniert so ein Retransmit:

ahoy.py implementiert jetzt

  • Multi-Inverter
  • Transport-Layer und Retransmits von verlorenen Frames
  • Full Payload Decode mit Device- und Request- abhändigen Decodern
  • Dynamisches mqtt-publishen, jenachdem wieviel Phasen/Strings Hier: https://github.com/Sprinterfreak/ahoy/tree/pypackage/tools/rpi Das mit den Retransmits sieht dann so aus: 
    2022-05-05 18:46:56.432521 Transmit 27 \| 15 72 22 01 43 78 56 34 12 80 0b 00 62 73 ff 7e 00 00 00 05 00 00 00 00 59 ad e5
2022-05-05 18:46:56.525429 Received 27 bytes channel 75: 95 72 22 01 43 72 22 01 43 02 a2 0a 00 00 99 17 06 3b 06 40 08 e3 13 86 01 51 e4
2022-05-05 18:46:56.579134 Received 23 bytes channel 75: 95 72 22 01 43 72 22 01 43 83 00 00 00 0f 03 e8 00 f5 00 2a 6b f2 b4
Error while retrieving data: Frame 1 missing: Request Retransmit
2022-05-05 18:46:57.083093 Transmit 11 | 15 72 22 01 43 78 56 34 12 81 8e
2022-05-05 18:46:57.137897 Received 27 bytes channel 75: 95 72 22 01 43 72 22 01 43 01 00 01 01 3b 00 37 00 af 01 3b 00 39 00 b2 00 00 86
2022-05-05 18:46:57.641794 Payload: 00 01 01 3b 00 37 00 af 01 3b 00 39 00 b2 00 00 a2 0a 00 00 99 17 06 3b 06 40 08 e3 13 86 01 51 00 00 00 0f 03 e8 00 f5 00 2a 6b f2
2022-05-05 18:46:57.641794 Decoded: 24.5 phase0=voltage:227.5, current:1.5, power:33.7, frequency:49.98 string0=voltage:31.5, current:0.55, power:17.5, total:41.482, daily:1595 string1=voltage:31.5, current:0.57, power:17.8, total:39.191, daily:1600

Das würde natürlich einen Empfangspuffer erfordern, der die Pakete bzw. deren Payload so lange im Speicher hält, bis alle Antwort Pakete da und validiert sind. Dann kann man auch die CRC16/CRC_M über den Payload aller Pakete validieren und über zwei Pakete verteilte Werte (wie beim HM-600) gemeinsam zuordnen/bzw. mit Divisor korrekt berechnen.

Lukas (@lumapu), ich habe mal spaßeshalber die Hoymiles Seriennummer meines Wechselrichters für alle drei WR-Optionen mit unterschiedlichen Namen bzw. HM-600 und HM-800 Konfiguration eingetragen und festgestellt daß er die Daten auf dem Dashboard (/hoymiles) nur für den ersten WR ausgibt. Die anderen bleiben bei Null / 0,00.

Ist das ein Problem bereits in der Empfangsroutine, die losgelöst vom Sender nur die Antwort Adresse auswertet und es daher immer in die Resultate des 1. WR einträgt oder kommt das erst im Dashboard dazu ?

lumapu commented 2 years ago

@stefan123t Ja der Retransmit steht noch bei den Änderungswünschen. Finde wir sollten auf diesem Gebiet aber noch etwas forschen was die DTU hier genau macht. Auf meine Frage, ob jemand schon mal eine DTU gesehen hat, die einen Retransmit gefordert hat habe ich (noch) keine Antwort bekommen. Evtl. muss ich auch selbst nochmal den Thread diesbezüglich durcharbeiten.

Wenn du den gleichen Wechelrichter 3x einträgst, bleiben der 2te und 3te leer, da er in dieser Zeile immer bei ersten 'hängen' bleibt. https://github.com/grindylow/ahoy/blob/8f444cee2fa51391f41fa0759999ae1b9abd28e1/tools/esp8266/app.cpp#L150

stefan123t commented 2 years ago

Bzgl. Retransmit habe ich auch noch nichts Konkretes im Forum entdeckt. Man könnte sich ggf. auch nochmal die HackRF Mitschnitte auf den ersten beiden Seiten nochmal genauer ansehen und unter die Lupe nehmen. Oliver F. hatte vor Ostern seinen sechsfach nRF24L01 Build gezeigt aber offenbar noch keine Software dafür am Laufen. Ich habe zumindest noch keine Rückmeldung von ihm bzgl. der Frage was er denn herausbekommen hat beim Mitlauschen auf sechs Kanälen.

Aber die Ergebnisse von Jan-Jonas waren m.E. vielversprechend und nachvollziehbar. Das höchstwertige Bit in den ESB (Enhanced Shock Burst) Paketen scheint ja eine spezielle Funktion zu haben. Vom PRX (Primary Receiver = DTU bzw. unser nRF24L01+) zum PTX (Primary Transmitter bis zu 8 Endgeräte) zeigt es u.a. das letzte Paket bzw. CMD / "Kommando" an. Auf dem Weg von den PTX (hier die Wechselrichter) zum PRX (unsere DTU) zeigt es ebenfalls das letzte Paket an.

Ich habe das mal aus Jan-Jonas Beispiel Paketen extrahiert und verglichen.

Hier die Original Nachrichten aus seinem Logfile:

                                                         PA  TGT_ADDRESS  SRC_ADDRESS  PC  PAYLOAD                                          C8  EP
2022-05-03 20:28:40.145516 Transmit |                    15  72 22 01 43  78 56 34 12  80  02 00 62 71 74 58 00 00 00 05 00 00 00 00 84 6b  58  7f
2022-05-03 20:28:40.214575 Received 27 bytes channel 75: 95  72 22 01 43  72 22 01 43  01  0a 00 20 01 00 0c 08 fc 07 a3 00 0f 09 e2 00 1e  19  7f
2022-05-03 20:28:40.262608 Received 27 bytes channel 75: 95  72 22 01 43  72 22 01 43  02  06 4a 00 14 0a 55 00 14 0a c8 00 0a 09 e2 10 03  b4  7f
2022-05-03 20:28:40.304763 Received 27 bytes channel 61: 95  72 22 01 43  72 22 01 43  03  13 88 12 c0 00 14 13 ec 00 14 12 8e 00 05 14 50  fd  7f
2022-05-03 20:28:40.352869 Received 27 bytes channel 61: 95  72 22 01 43  72 22 01 43  04  00 05 20 00 00 01 30 03 02 58 09 e2 07 a3 13 9c  1c  7f
2022-05-03 20:28:40.401014 Received 27 bytes channel 61: 95  72 22 01 43  72 22 01 43  05  13 56 40 00 07 d0 00 10 50 01 00 01 13 9c 01 90  1c  7f
2022-05-03 20:28:40.443199 Received 27 bytes channel 40: 95  72 22 01 43  72 22 01 43  06  00 10 00 00 60 00 00 01 09 e2 0a 5a 02 15 80 01  cf  7f
2022-05-03 20:28:40.491307 Received 27 bytes channel 40: 95  72 22 01 43  72 22 01 43  07  00 00 08 5b 01 2c 08 b7 09 41 09 9d 01 2c 00 64  c6  7f
2022-05-03 20:28:40.533532 Received 27 bytes channel 23: 95  72 22 01 43  72 22 01 43  08  90 00 00 00 00 5f b0 00 00 00 01 f4 00 5f 70 02  3a  7f
2022-05-03 20:28:40.581560 Received 23 bytes channel 23: 95  72 22 01 43  72 22 01 43  89  00 01 27 10 a0 02 00 00 00 00             cb fe  bd  7f

Die obigen Einrückungen sind von mir um die Felder (Preamble PA, TGT_ADDRESS Ziel Addresse, SRC_ADDRESS Quell Adresse, CMD bzw. Paketzähler PC, Payload PAYLOAD, CRC8 C8 und Ende Paket EP) etwas von einander abzusetzen. Seine Pakete waren übrigens bis auf die Sendezeit in den Anforderungspaketen (Transmit) und dessen CRC8 absolut identisch. Deshalb habe ich mich auch auf eine Request/Response beschränkt.

Hier die Payload ohne die CRC8, aber die letzten zwei Byte müssten die CRC_M/CRC16 sein.

0a 00 20 01 00 0c 08 fc 07 a3 00 0f 09 e2 00 1e 
06 4a 00 14 0a 55 00 14 0a c8 00 0a 09 e2 10 03 
13 88 12 c0 00 14 13 ec 00 14 12 8e 00 05 14 50 
00 05 20 00 00 01 30 03 02 58 09 e2 07 a3 13 9c 
13 56 40 00 07 d0 00 10 50 01 00 01 13 9c 01 90 
00 10 00 00 60 00 00 01 09 e2 0a 5a 02 15 80 01 
00 00 08 5b 01 2c 08 b7 09 41 09 9d 01 2c 00 64 
90 00 00 00 00 5f b0 00 00 00 01 f4 00 5f 70 02 
00 01 27 10 a0 02 00 00 00 00             cb fe

Hier die selbe Payload als Hexfile mit vorangestelltem Offset

0000000: 0a00 2001 000c 08fc 07a3 000f 09e2 001e 
0000010: 064a 0014 0a55 0014 0ac8 000a 09e2 1003 
0000020: 1388 12c0 0014 13ec 0014 128e 0005 1450 
0000030: 0005 2000 0001 3003 0258 09e2 07a3 139c 
0000040: 1356 4000 07d0 0010 5001 0001 139c 0190 
0000050: 0010 0000 6000 0001 09e2 0a5a 0215 8001 
0000060: 0000 085b 012c 08b7 0941 099d 012c 0064 
0000070: 9000 0000 005f b000 0000 01f4 005f 7002 
0000080: 0001 2710 a002 0000 0000

Und hier die Konversion mit Hilfe von xxd von HEX zu BIN und dann die Darstellung der Payload. Ich kann hier leider keine Klartext Informationen erkennen, d.h. auch bei dieser komplizierteren Statusabfrage (es kommt ja scheinbar immer das selbe, selbst die CRC_M/CRC16 ist bei allen Beispielen identisch) scheinen die Informationen binär in Doppel / Vierbyte Werten (Words / Doublewords) vorzuliegen.

$ xxd -r hm-600.txt > hm-600.bin 

$ xxd hm-600.bin 
00000000: 0a00 2001 000c 08fc 07a3 000f 09e2 001e  .. .............
00000010: 064a 0014 0a55 0014 0ac8 000a 09e2 1003  .J...U..........
00000020: 1388 12c0 0014 13ec 0014 128e 0005 1450  ...............P
00000030: 0005 2000 0001 3003 0258 09e2 07a3 139c  .. ...0..X......
00000040: 1356 4000 07d0 0010 5001 0001 139c 0190  .V@.....P.......
00000050: 0010 0000 6000 0001 09e2 0a5a 0215 8001  ....`......Z....
00000060: 0000 085b 012c 08b7 0941 099d 012c 0064  ...[.,...A...,.d
00000070: 9000 0000 005f b000 0000 01f4 005f 7002  ....._......._p.
00000080: 0001 2710 a002 0000 0000                 ..'.......

Bzgl. der Wechselrichter, hier sollte m.E. der Inverter die Daten / Payload bekommen, für den die Routine aufgerufen wird. Aktuell wird das Radio aktiviert und dann die Daten anhand der Adresse im Rahmen einem Wechselrichter zugeordnet. Hier wäre der von Jan-Jonas in seinem bisherigen Development Branch pypackage enthaltene Rahmen sicher sinnvoll, wenn wir den auch irgendwie in der ESP8266/ESP32 API / Bibliothek mit unterbringen könnten.

Ich hoffe Du "steinigst" mich nicht =^/ , da seine Anmerkung / Formulierung im Forum vermutlich mißverständlich war. Vor allem für jemanden wie Dich der schon sehr viel Zeit und Energie in dieses Projekt gesteckt hat. Danke daher nochmal hierfür! Ich vermute er wollte nur ausdrücken, daß er die Fragen nach seltsamen Werten nicht mehr beantworten kann/will, solange Leute die aktuelle ESP Variante verwenden, die eben keine durchgängige Überprüfung der CRC8 Summen pro Paket und eine zusätzliche CRC16/CRC_M für die gesamte Payload durchgeführt hat, und die sich dann über unstimmige Werte wundern. Ich hoffe wir können das, was er da in Python vorgelegt und programmiert hat auch in C++ nachpflegen, denn es erscheint mir der richtige Weg.

Ob das mit dem Retransmit wirklich richtig / sinnvoll ist, kann ich noch nicht beurteilen. Ich würde vermutlich eher dazu neigen, die komplette Nachricht mit allen Paketen zu wiederholen und die restlichen Pakete evtl. nach einem CRC8 Fehler noch eingehenden Pakete bis zum 0x8y zu verwerfen. Aber sein Ansatz ist, wenn er funktioniert vermutlich der datensparsamere und und weniger rechenzeit-intensive Weg.

stefan123t commented 2 years ago

Auf meine Frage, ob jemand schon mal eine DTU gesehen hat, die einen Retransmit gefordert hat habe ich (noch) keine Antwort bekommen. Evtl. muss ich auch selbst nochmal den Thread diesbezüglich durcharbeiten.

Hallo Lukas, den Thread habe ich diesbezgl. nochmal durchgearbeitet und bin im Excel aus martin's (Gast) Trace Daten zwischen dem GD32 und nRF24 Chip fündig geworden. Findet sich dort z.B. in Spalte AM..AS. Die Retransmit Anfrage besteht aus

Name Value
StartOfFrame 0x7E
DataRequest 0x15
Target / InverterSerialNo 0x72220200
Source / DTUSerialNo 0x72220200
Retransmit Paket 0x81
CRC8 0x94
EndOfFrame 0x7F

NB: In der DTU wird die echte DTUSerialNo vom nRF24 selbst eingetragen, hierfür sind evtl. die ersten Init Pakete zwischen GD32 und nRF24

image

stefan123t commented 2 years ago

Hallo Lukas,

ich hatte eine Uptime von etwas über 4 Tagen an einem normalen USB-Netzteil. Das ist prima, Danke! Aber für den Update auf 0.3.8 mußte ich den ESP resetten, dabei habe ich wieder einige Verbindungsprobleme festgestellt.

Jetzt scheint der WLAN Access Point nach WIFI_TRY_CONNECT_TIME bereits nach ca. 5-10 "echten" Sekunden den Access Point aufzumachen. Ich habe den Wert bei mir jetzt auf ebenfalls 3*60 "Sekunden" erhöht. Wobei das im Originalzustand mit 30 "Sekunden" nur für 5 reconnects gereicht hat, bevor der AP aufging. Mit den 3 "Minuten" habe ich meist nach 10-15 reconnects (~50 echten Sekunden) einen WiFi Fix.

Danach kann ich zwar die Seite erreichen können, aber die Uhr bleibt standhaft über Stunden bei 1970 stehen, d.h. die main::getNtpTime() Methode wird nicht oft genug probiert ? Hier steckt auch noch ein delay(5000).

Auch scheint der MQTT Publisher sich nicht mit dem MQTT Broker erneut zu verbinden, wenn der Access Point zuerst offen war. Ich habe in app.cpp app::setup() gesehen daß dort der MQTT Broker nur beim app Start aufgesetzt wird. Kann das evtl. dazu führen daß er sich bei WiFi Verbindungsproblemen nicht erneut verbinden kann ?

Im main.cpp habe ich auch WiFi.hostByName (TIMESERVER_NAME, timeServer); gesehen, der ja eigentlich auch für eine Namensauflösung z.B. des MQTT Brokers verwendbar wäre ?

turbolift commented 2 years ago

Danach kann ich zwar die Seite erreichen können, aber die Uhr bleibt standhaft über Stunden bei 1970 stehen, d.h. die main::getNtpTime() Methode wird nicht oft genug probiert ? Hier steckt auch noch ein delay(5000). ... Auch scheint der MQTT Publisher sich nicht mit dem MQTT Broker erneut zu verbinden, wenn der Access Point zuerst offen war. Ich habe in app.cpp app::setup() gesehen daß dort der MQTT Broker nur beim app Start aufgesetzt wird. Kann das evtl. dazu führen daß er sich bei WiFi Verbindungsproblemen nicht erneut verbinden kann ?

Diese beiden Phänomene habe ich heute auch feststellen können.

lumapu commented 2 years ago

Super News! Mein ESP startet immer mal wieder neu - ich weiß noch nicht was jetzt schon wieder los ist.

Ich kann mich leider gerade nicht um solche Fehler kümmern, ich will zuerst die Gesamt-Payload zusammenfassen. Danach können wir uns wieder um Peripherie kümmern. Hast du eine Idee warum die Verbindungszeiten so krass falsch sind?

Das delay(5000) habe ich bewusst vor dem NTP Request eingebaut, damit die WiFi Verbindung schon eine gewisse Zeit besteht.

MQTT ist ein ganz eigenes Thema, da bin ich noch überhaupt nicht zufrieden - auch die 0.3.8 ändert hieran nichts. Ich würde fast behaupten ein MQTT-Broker sollte eine feste IP haben - man kann es ja mal ausprobieren was eine Namensauflösung macht.

stefan123t commented 2 years ago

https://codeutility.org/platformio-esp8266-flash-memory-has-to-be-completely-erased-after-every-crash-to-be-usable-again-stack-overflow/

Interessantes Debug Detail bzgl. den umm_malloc Problemen in den WDT Exceptions:

you can monitor the FreeHeap using:

1 | Serial.println(ESP.getFreeHeap()); -- | --

run it in the loop to observed the available memory.

stefan123t commented 2 years ago

Hi Lukas, danke für das Einbauen der Heap Size in die Serial Ausgabe. Hatte es auch mal kurz getestet, aber die Heap Größe alleine scheint es nicht zu sein.

Dennoch stürzt er immer mit irgendwelchen umm_malloc Klassen ab, diese Exception hier hatte ich gestern mit der 0.4.3 drei / viermal:

Exception 3: LoadStoreError: Processor internal physical address or data error during load or store
PC: 0x401007ed: umm_assimilate_up(umm_heap_context_t*, uint16_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 336
EXCVADDR: 0x40032401

Decoding stack results
0x40100a45: check_poison_neighbors(umm_heap_context_t*, uint16_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 71
0x40100b51: umm_free_core(umm_heap_context_t*, void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 549
0x40100e76: umm_free(void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 595
0x40100e94: umm_poison_free_fl(void*, char const*, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 152
0x4010057c: vPortFree(void*, char const*, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_heap_select.h line 85
0x40225430: mem_free at core/mem.c line 236
0x4021d371: memp_free at core/memp.c line 383
0x4021de78: tcp_free at core/tcp.c line 216
0x4021e4ff: tcp_abandon at core/tcp.c line 622
0x40100e94: umm_poison_free_fl(void*, char const*, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 152
0x4010057c: vPortFree(void*, char const*, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_heap_select.h line 85
0x4021e568: tcp_abort at core/tcp.c line 640
0x40226f7f: tcp_input at core/tcp_in.c line 497
0x401009b0: check_poison_block(umm_block*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_poison.c line 95
0x40224721: ip4_input at core/ipv4/ip4.c line 1467
0x40100e76: umm_free(void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 595
0x4021d241: ethernet_input_LWIP2 at netif/ethernet.c line 188
0x4021d040: esp2glue_ethernet_input at glue-lwip/lwip-git.c line 116
0x402455c5: ethernet_input at glue-esp/lwip-esp.c line 365
0x402455d7: ethernet_input at glue-esp/lwip-esp.c line 373
0x40100e50: umm_init() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 476
0x401000ac: app_entry_redefinable() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 325
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x4021ce73: new_linkoutput at glue-lwip/lwip-git.c line 268
0x4021d2ce: ethernet_output at netif/ethernet.c line 312
0x401009b0: check_poison_block(umm_block*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_poison.c line 95
0x40100a45: check_poison_neighbors(umm_heap_context_t*, uint16_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 71
0x40100c98: umm_malloc_core(umm_heap_context_t*, size_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 48
0x40100a45: check_poison_neighbors(umm_heap_context_t*, uint16_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 71
0x40100898: get_poisoned(void*, size_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_poison.c line 117
0x40100eb8: umm_malloc(size_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 821
0x40100f28: umm_poison_malloc(size_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_poison.c line 167
0x40100898: get_poisoned(void*, size_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_poison.c line 117
0x40100558: pvPortMalloc(size_t, char const*, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_heap_select.h line 85
0x40225409: mem_malloc at core/mem.c line 210
0x4021d31c: do_memp_malloc_pool at core/memp.c line 255
0x4021d34c: memp_malloc at core/memp.c line 355
0x4021ff7b: tcp_create_segment at core/tcp_out.c line 190
0x401002dd: millis() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 193
0x4020a0b6: ClientContext::_write_from_source(char const*, unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/libraries/ESP8266WiFi/src/include/ClientContext.h line 484
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x40100a45: check_poison_neighbors(umm_heap_context_t*, uint16_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_local.c line 71
0x40100b51: umm_free_core(umm_heap_context_t*, void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 549
0x40100e76: umm_free(void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 595
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x40202eaa: esp8266webserver::ESP8266WebServerTemplate ::send(int, char const*, Stream*, unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/WString.h line 79
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x402045f3: app::loop() at /tmp/arduino_build_855091/sketch/main.h line 71
0x40100278: millis() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 175
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x401002dd: millis() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 193
0x401002dd: millis() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 193
0x402045f6: app::loop() at /tmp/arduino_build_855091/sketch/main.h line 72
0x40100e76: umm_free(void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 595
0x401001c8: ets_post(uint8, ETSSignal, ETSParam) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 181
0x401001e9: esp_schedule() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 128
0x402113d2: loop_wrapper() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_main.cpp line 205

Ich habe noch einen Artikel What is Heap Fragmentation? über Heap Holes / Fragmentation durch std::Strings gelesen. Vorschlag dort ist immer gleich viel, aber ausreichend Memory für die Strings zu reservieren. Dann entstehen nach dem Freigeben des Speichers keine zu kleinen Löcher.

Strategy 3: Constant allocation As we saw, repeated allocations of the same size don’t cause fragmentation; so, we could keep our objects in the heap but always use the same size. For example, if we have a string that can have between 10 and 100 characters, we could always reserve 100 characters: myString.reserve(100); As curious as it sounds, allocating more memory than strictly necessary allows more efficient utilization of the RAM.

Das müsste man m.E. für die WebServer Templates umsetzen und genügend Slack für 3xWechselrichter Variablengröße (Name, Seriennummer, etc.) oder was eben alles in den Templates als Variablen vorgesehen ist, die ja ersetzt werden müssen bevor die Seite rausgeht.

Es wäre in diesem Zusammenhang auch gut noch die Fragmentierung bzw. das größte allokierbare Speichersegment in die Debug Ausgabe einzubauen:

My ESP crashes running some code. How to troubleshoot it?

Memory, memory, memory Running out of heap is the most common cause for crashes. Because the build process for the ESP leaves out exceptions (they use memory), memory allocations that fail will do so silently. A typical example is when setting or concatenating a large String. If allocation has failed internally, then the internal string copy can corrupt data, and the ESP will crash.

In addition, doing many String concatenations in sequence, e.g.: using operator+() multiple times, will cause memory fragmentation. When that happens, allocations may silently fail even though there is enough total heap available. The reason for the failure is that an allocation requires finding a single free memory block that is large enough for the size being requested. A sequence of String concatenations causes many allocations/deallocations/reallocations, which makes “holes” in the memory map. After many such operations, it can happen that all available holes are too small to comply with the requested size, even though the sum of all holes is greater than the requested size.

So why do these silent failures exist? On the one hand, there are specific interfaces that must be adhered to. For example, the String object methods don’t allow for error handling at the user application level (i.e.: no old-school error returns). On the other hand, some libraries don’t have the allocation code accessible for modification. For example, std::vector is available for use. The standard implementations rely on exceptions for error handling, which is not available for the ESP, and in any case there is no access to the underlying code.

Instrumenting the code with the OOM debug option and calls to ESP.getFreeHeap() / ESP.getHeapFragmentation() / ESP.getMaxFreeBlockSize() will help the process of finding memory issues.

stefan123t commented 2 years ago

Hallo Lukas P., Marcel, etc. ich habe nochmal zum wdt reset recherchiert. Hier ein Link zur Homepage über ESP8266 von Stefan Frings, der hat das Thema eigentlich ganz gut dokumentiert und hier noch eine Diskussion im selben Forum zu den Flash Pins, die auf einem Breadboard zu Problemen mit dem Wachhund führen:

Node MCU und WeMos D1 immer wdt reset

Hab das nochmal untersucht. Ich glaube das die IO's (CLK, SD1, SD2 usw) für den Flashspeicher die WDT's auslösen. Hier wird was Falsches eingelesen weil Störungen durch die Kontaktbahnen des Breadboards (Induktic, Kapazitiv) eingefangen werden. Die Frequenz des CLK liegt hier bei 40 Mhz.

Habt Ihr Eure Probleme auch auf einem Breadboard oder ist bei Euch der ESP8266 bereits fest verdrahtet / -lötet ? Ich werde das mit den o.g. Flash Pins bei mir mal ausprobieren wenn der Lötkolben das nächste mal heiß ist.

Alle anderen Versuche das Problem in umm_malloc bzw. dem Heap zu finden sind bisher fehlgeschlagen.

https://github.com/arduino/esp8266/tree/master/cores/esp8266/umm_malloc

@lumapu hier ist noch ein offizielles Beispiele um den Heap genauer zu monitoren, speziell:

void stats(const char* what) {
  // we could use getFreeHeap() getMaxFreeBlockSize() and getHeapFragmentation()
  // or all at once:
  uint32_t free;
  uint32_t max;
  uint8_t frag;
  ESP.getHeapStats(&free, &max, &frag);

  Serial.printf("free: %7u - max: %7u - frag: %3d%% <- ", free, max, frag);
  // %s requires a malloc that could fail, using println instead:
  Serial.println(what);
}

https://github.com/esp8266/Arduino/blob/master/libraries/esp8266/examples/HeapMetric/HeapMetric.ino

BTW, der upstream Merge des getHeapStats in die umm_malloc Bibliothek findet sich hier: https://github.com/rhempel/umm_malloc/issues/14

stefan123t commented 2 years ago

@dad401 bitte mit der v.0.5.9 überprüfen und ggf. als gelöst schließen. Danke Wir können das Thema im Rahmen des Scheduler und der Command Queue für den Plan zur v0.6.0 siehe 142 nochmal angehen, daher hier der Link zu #78.