search

lumapu / ahoy

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

ESP32 resets several times a day[Bug] #1354

Closed mellow5 closed 4 months ago

mellow5 commented 8 months ago

Platform

ESP32

Assembly

I did the assebly by myself

nRF24L01+ Module

nRF24L01+ plus

Antenna

circuit board

Power Stabilization

Elko (~100uF)

Connection picture

Version

0.8.52

Github Hash

455d29a

Build & Flash Method

AhoyDTU Webinstaller

Setup

Nothing was changed on the setup since 0.7.36.

Debug Serial Log output

No response

Error description

Since stable release 0.7.36 I never had a setup that did not reset several times per day. What are the most common problems for resetting? Else I'm very satisfied with the project.

How best to debug the reset?

You69Man commented 8 months ago

How best to debug the reset?

If you could provide a serial log of the last messages, this could be helpful. Either by the Webserial or via USB serial (e.g. with putty).

lumapu commented 8 months ago

for some it helped to configure the ESP from scratch - don't forget to export your configuration first!

mellow5 commented 8 months ago

Last lines from serial log before reboot tonight.

I: (#0) no communication to the inverter (night time)
I: (#1) no communication to the inverter (night time)

assert failed: tcp_update_rcv_ann_wnd IDF/components/lwip/lwip/src/core/tcp.c:951 (new_rcv_ann_wnd <= 0xffff)

Backtrace: 0x40083c71:0x3ffb2cc0 0x4008c94d:0x3ffb2ce0 0x40092c05:0x3ffb2d00 0x401262fa:0x3ffb2e30 0x401263a8:0x3ffb2e50 0x400f1cbe:0x3ffb2e70 0x40123090:0x3ffb2e90

If this does not give you any ideas, I will install from scratch.

You69Man commented 8 months ago

Hier gab es auch einen issue zu diesem Fehler: https://github.com/espressif/arduino-esp32/issues/7895

MetaChuh commented 8 months ago

i (also) have constant async watchdog reboots using 0.8.53 see usb serial log below

maybe an important note: never reboots in ap mode, always reboots in wifi mode

what i've tried:

erasing and reflashing the esp32 with both web flasher and espressive flash_download_tool_3.9.5.exe, erase & flashing bootloader, partitions, ota and firmware to their specific locations (0x1000, 0x8000, 0e000,0x10000) result: still rebooting in wifi mode

then i disabled and removed the display set ntp to local fritzbox ip result: still rebooting in wifi mode

crosschecks to exclude esp32 hardware problems:

erased the esp32 and flashed another project using web and nrf24 result: works without issues

erased the esp32 and flashed ahoy dtu 0.6.9 result: works without issues

usb serial log from 0.8.53 reboots (short snippet of the repeating endless loop):

--------------------------------
Welcome to AHOY!

point your browser to http://************ (Station)
to configure your device
--------------------------------

Wifi event: 11
Wifi event: 10
[WiFi] AP disabled
Wifi event: 11
[WiFi] mDNS established: AHOY-DTU-32-EP.local
E (34596) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (34596) task_wdt:  - async_tcp (CPU 1)
E (34596) task_wdt: Tasks currently running:
E (34596) task_wdt: CPU 0: IDLE
E (34596) task_wdt: CPU 1: IDLE
E (34596) task_wdt: Aborting.

abort() was called at PC 0x40115b3c on core 0

Backtrace: 0x40083c71:0x3ffbeccc |<-CORRUPTED

ELF file SHA256: d6fdd9617fa6c971

Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:1184
load:0x40078000,len:13232
load:0x40080400,len:3028
entry 0x400805e4
I: Initializing FS ..
I:  .. done
I: Config Version: 0
I: Settings valid: true

---------
AhoyDTU Info:
Version: 0.8.53
Github Hash: ca6ebfe

---------
AP MODE
SSID: AHOY-DTU
PWD: esp_8266
IP Address: http://192.168.4.1
---------

Wifi event: 0
Wifi event: 2
Wifi event: 10
Wifi event: 11
Wifi event: 10
connect to network '************' ...
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
scanning APs with SSID ************
Wifi event: 1
BSSID 0: 3c a6 2f 8 7e 50
try to connect to AP with BSSID: 3c a6 2f 8 7e 50
Wifi event: 5
I: connectionEvent
Wifi event: 4
I: connectionEvent

[WiFi] Connected
Wifi event: 7
I: connectionEvent

--------------------------------
Welcome to AHOY!

point your browser to http://************ (Station)
to configure your device
--------------------------------

Wifi event: 11
Wifi event: 10
[WiFi] AP disabled
E (33085) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (33085) task_wdt:  - async_tcp (CPU 1)
E (33085) task_wdt: Tasks currently running:
E (33085) task_wdt: CPU 0: IDLE
E (33085) task_wdt: CPU 1: IDLE
E (33085) task_wdt: Aborting.

abort() was called at PC 0x40115b3c on core 0

Backtrace: 0x40083c71:0x3ffbeccc |<-CORRUPTED

ELF file SHA256: d6fdd9617fa6c971

Rebooting...
ets Jul 29 2019 12:21:46
You69Man commented 8 months ago

I have been running version 0.8.53 on an ESP32 (including display and graph) for more than a day without any problems.

However I have managed to capture an unexcpected reboot now on an ESP8266 (same software version, also with display and display graph)!

This is the decoded exception output (callstack): grafik

It seems these async reboots always point to something within the TCP/IP stack, but I don't understand the details. The failure seems to be extremely sensitiv to tiny deviations in timing! That means that any change in configuration (also like display on/off settings) can make a difference.

I've built a slightly different version of the failed 0.8.53 on ESP8266 (just added some DBGPRINTLN lines to find possible reasons), but now the reboot doesn't show up again till now.

@lumapu: Do you think this could be due to too few yield() calls in the loops?

lumapu commented 8 months ago

no yield() is positive. I think the issue occurs on ESP8266 first because of its single core. An exception around TCP could be related to WiFi. Maybe we have to check our loops again. Do you know anything regarding heap fragmentation on ESP8266?

You69Man commented 8 months ago

0.8.53 derivate on ESP8266 (deviation: just some added DBGPRINTLN, running stable since several hours): heap frag: 3 heap free: 12280

If I ever come across a version with reboots, I will check heap and heap frag again!

You69Man commented 8 months ago

no yield() is positive

Yes, what I meant is, should we add some more yield(), e.g. between and inside the radio-, communication- or display loops? I don't have much experiance how many (or how often) yield() calls are necessary to fulfill the background tasks of the ESP.

mellow5 commented 8 months ago

Ich habe 0.8.56 installiert und bekomme leider weiterhin die sporadischen reboots mit der gleichen Fehlermeldung.

MetaChuh commented 8 months ago

@lumapu hi, ich hab' vor ca 4h testweise die 0.8.57 auf den gleichen test esp32 wie oben geflasht (esp32 d1 mini mit e-paper) update via ota von 0.6.9 auf 0.8.57 und augen zu

bisher kein reboot, gleiches wlan 👍

mal schauen, was passiert, sobald die ersten solar inverter offline gehen. ich polle jetzt mal zum testen alle inverter per api im 2 sekunden intervall sequenziell und geb' per edit bescheid, falls sich was Àndert.

@You69Man danke fĂŒr die saugeile mini graph fĂŒr die oled displays 🙏 hab's heute auf einer anderen esp32 mit sh1106 kurz ausprobiert 👍 wirklich zu schön um wahr zu sein 😉

thx & greetings

lumapu commented 8 months ago

sehr schön hier positives zu lesen â˜ș, ich hoffe der Sonnenuntergang hat die Stimmung nicht getrĂŒbt

MetaChuh commented 8 months ago

hi, nein gottseidank nichts getrĂŒbt durch den sonnenuntergang, erst nach zufĂ€lligem internetausfall in der nacht:

nach sonnenuntergang war alles noch ok und noch 2 batterie inverter online. uptime 12h+ trotz stakkato rekursiv api abfrage

nachts um ca 02:00h ist dann die dsl wan verbindung lÀnger ausgefallen (lokales wifi, lan und gerÀte alle vorhanden, pool.ntp.org und alles externe nicht erreichbar) kurz darauf begannen alle ahoy dtus zu rebooten (bootloop auch bei v0.6.9)

kurz nachdem die dsl leitung wieder funktionierte, hörten die reboots auf.

hab' dann in allen ahoy dtus den ntp server zum testen auf eine lokale synology nas ip gesetzt, statt pool.ntp.org oder lokale fritzbox ip.

wichtig zum thema fritzbox als lokaler ntp: habe heute getestet, wenn der in der fritzbox eingetragene ntp server nicht erreichbar ist, stellt die fritzbox KEINE eigene uhrzeit bereit, und geht in timeout, als ob man direkt pool.ntp.org angegeben hÀtte. reines sntp passthrough, also ist diese avm funktion nutzlos, und nicht als lokaler failsafe ntp zu gebrauchen.

werd' weiter (sporadisch wegen zeitmangel) testen, um mehr zu finden, womit wir mehr reboots explizit, mit wissentlichem zusammenhang, reproduzieren können.

thx & greetings

MetaChuh commented 8 months ago

hi,

heute habe ich ota auf 0.8.58 upgedated und bumm, wieder sofort boot loops.

reboots passieren wieder nur im wifi mode. wenn ich mich mit dem ahoydtu access point verbinde, passiert kein dauerreboot und alle 5 inverter sind datenmĂ€ĂŸig normal da.

aber sobald ich mich dann vom ap trenne und die ahoydtu sich wieder mit dem lokalen wifi verbindet, sofort wieder bootloops.

welche ntp server (lokal/remote) und einstellungen man macht war dabei egal und brachte keine verbesserung.

zusÀtzlich time calibration message flut in allen invertern wÀhrenddessen.

habe dann alle api html abfragen auf diese dtu abgedreht und nach ein paar minuten hat sie den bootloop dann beendet und lÀuft seitdem auch mit wieder aktivierter api abfrage, auch im 2sek abfrageintervall.

sehr seltsam, und ausser trial and error auszubrobieren, hab' ich keine ideen mehr.

console log auszug:


Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:1184
load:0x40078000,len:13192
load:0x40080400,len:3028
entry 0x400805e4
I: Initializing FS ..
I:  .. done
I: Config Version: 8
I: Settings valid: true
I: Radio Config:
SPI Frequency       = 1 Mhz
Channel         = 3 (~ 2403 MHz)
Model           = nRF24L01+
RF Data Rate        = 250 KBPS
RF Power Amplifier  = PA_LOW
RF Low Noise Amplifier  = Enabled
CRC Length      = 16 bits
Address Length      = 5 bytes
Static Payload Length   = 32 bytes
Auto Retry Delay    = 1000 microseconds
Auto Retry Attempts = 15 maximum
Packets lost on
    current channel = 0
Retry attempts made for
    last transmission   = 0
Multicast       = Allowed
Custom ACK Payload  = Disabled
Dynamic Payloads    = Enabled
Auto Acknowledgment = Enabled
Primary Mode        = RX
TX address      = 0xe7e7e7e7e7
pipe 0 (closed) bound   = 0xe7e7e7e7e7
pipe 1 ( open ) bound   = 0x6d57838701
pipe 2 (closed) bound   = 0xc3
pipe 3 (closed) bound   = 0xc4
pipe 4 (closed) bound   = 0xc5
pipe 5 (closed) bound   = 0xc6
I: DTU_SN: 8783576d

---------
AhoyDTU Info:
Version: 0.8.58
Github Hash: c3a2ad0

---------
AP MODE
SSID: AHOY-DTU
PWD: esp_8266
IP Address: http://192.168.4.1
---------

Wifi event: 0
Wifi event: 2
Wifi event: 10
Wifi event: 11
Wifi event: 10
connect to network '************' ...
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
I: added inverter HM************
scanning APs with SSID MetaWeb1230-7530
_PowerOn : 94004
_Update_Full : 4587000
_PowerOff : 139000
_PowerOn : 94004
Wifi event: 1
_Update_Full : 4407000
_PowerOff : 139000
BSSID 0: 3c a6 2f 8 7e 50
_PowerOn : 94000
_Update_Part : 732000
_Update_Part : 733000
try to connect to AP with BSSID: 3c a6 2f 8 7e 50
Wifi event: 5
I: connectionEvent
Wifi event: 4
I: connectionEvent

[WiFi] Connected
Wifi event: 7
I: connectionEvent

--------------------------------
Welcome to AHOY!

point your browser to http://10.10.10.41 (Station)
to configure your device
--------------------------------

Wifi event: 11
Wifi event: 10
Wifi event: 11
[WiFi] AP disabled
[WiFi] mDNS established: AHOY-DTU-32.local
_Update_Part : 732000
_Update_Part : 733000
_PowerOff : 139000
E (31254) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (31254) task_wdt:  - async_tcp (CPU 1)
E (31254) task_wdt: Tasks currently running:
E (31254) task_wdt: CPU 0: IDLE
E (31254) task_wdt: CPU 1: IDLE
E (31254) task_wdt: Aborting.

abort() was called at PC 0x40115cb4 on core 0

Backtrace: 0x40083c71:0x3ffbeccc |<-CORRUPTED

ELF file SHA256: 2e5e26924045a82f

Rebooting...
ets Jul 29 2019 12:21:46
lumapu commented 8 months ago

@tictrick hat hier gestern versucht nachzubessern. Evtl. kann er was dazu sagen, da er gerade tief in dem Thema drin ist. Hoffentlich liegt es nicht an meiner reduzierten Anzahl von wdt-resets.

MetaChuh commented 8 months ago

@lumapu danke dir, hab's beobachtet wegen den 7 reset points, erkenne jedoch noch keinen direkten zusammenhang, das dies auslösen kann.

ps: ist nicht wichtig, weil die produktive umgebung hier durch tests nicht verÀndert wird. reines interesse neues ohne konsequenzen und dadurch mit fun auszutesten.

glg, metachuh

lumapu commented 7 months ago

@mellow5 hat bei dir eine neuere Version Verbesserung gezeigt?

mellow5 commented 7 months ago

@mellow5 hat bei dir eine neuere Version Verbesserung gezeigt?

Nein, ich habe noch immer sporadische resets auch mit der 0.8.59.

mellow5 commented 7 months ago

Habe jetzt auf 0.8.60 hochgezogen.

lumapu commented 7 months ago

gibt es ein Update?

mellow5 commented 7 months ago

Bis auf die 63 hab ich alle Versionen probiert,ohne VerĂ€nderung. Weiterhin sporadische Reeboots. 5-7 pro Tag ungleichmĂ€ĂŸig verteilt, auch nachts.

mellow5 commented 7 months ago

Ich habe heute mal probeweise einen ESP8266 verwendet. Bekomme noch immer reboots allerdings sieht der log beim reboot etwas anders aus. V0.8.65

I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2886, s: 2813, f: 5, n: 68 | p: 2
I: last tx setup: 16ms
I: (#0) TX 27 CH75 | 15 15 80
I: (#0) RX  17ms | 17 CH23 | 95 81
I: (#0) I: (#0) Payload (4)
I: (#0) Inv loss: 0 of 13, DTU loss: 2 of 43. ACKs: 13
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2872, s: 2787, f: 7, n: 78 | p: 2
I: last tx setup: 4ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  18ms | 27 CH40 | 95 01
I: (#1) RX  72ms | 27 CH40 | 95 02
W: (#1) frame 3 missing: request retransmit (3 attempts left)
I: (#1) TX 11 CH3 | 15 F9 83
I: (#1) RX  32ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 758ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2887, s: 2814, f: 5, n: 68 | p: 2
I: last tx setup: 21ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  26ms | 27 CH23 | 95 01
I: (#0) RX  77ms | 27 CH23 | 95 02
I: (#0) RX 130ms | 27 CH23 | 95 03
I: (#0) RX 184ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2873, s: 2788, f: 7, n: 78 | p: 2
I: last tx setup: 18ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  39ms | 27 CH40 | 95 01
I: (#1) RX  72ms | 27 CH40 | 95 02
I: (#1) RX 118ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2874, s: 2789, f: 7, n: 78 | p: 2
I: last tx setup: 37ms
I: (#1) TX 27 CH3 | 15 15 80
I: (#1) RX  22ms | 17 CH40 | 95 81
I: (#1) I: (#1) Payload (4)
I: (#1) Inv loss: 0 of 12, DTU loss: 1 of 32. ACKs: 10
-----
I: com loop duration: 503ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2888, s: 2815, f: 5, n: 68 | p: 2
I: last tx setup: 9ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  32ms | 27 CH23 | 95 01
I: (#0) RX  85ms | 27 CH23 | 95 02
I: (#0) RX 138ms | 27 CH23 | 95 03
I: (#0) RX 182ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2875, s: 2790, f: 7, n: 78 | p: 2
I: last tx setup: 16ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  21ms | 27 CH40 | 95 01
I: (#1) RX  74ms | 27 CH40 | 95 02
I: (#1) RX 128ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 427ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2889, s: 2816, f: 5, n: 68 | p: 2
I: last tx setup: 9ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  40ms | 27 CH23 | 95 01
I: (#0) RX  94ms | 27 CH23 | 95 02
I: (#0) RX 148ms | 27 CH23 | 95 03
I: (#0) RX 216ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2876, s: 2791, f: 7, n: 78 | p: 2
I: last tx setup: 25ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  27ms | 27 CH40 | 95 01
I: (#1) RX  80ms | 27 CH40 | 95 02
I: (#1) RX 126ms | 23 CH23 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 461ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2890, s: 2817, f: 5, n: 68 | p: 2
I: last tx setup: 14ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  41ms | 27 CH23 | 95 01
I: (#0) RX  84ms | 27 CH23 | 95 02
I: (#0) RX 148ms | 27 CH23 | 95 03
I: (#0) RX 191ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2877, s: 2792, f: 7, n: 78 | p: 2
I: last tx setup: 23ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  39ms | 27 CH40 | 95 01
I: (#1) RX  72ms | 27 CH40 | 95 02
I: (#1) RX 125ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 434ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2891, s: 2818, f: 5, n: 68 | p: 2
I: last tx setup: 37ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  26ms | 27 CH23 | 95 01
I: (#0) RX  80ms | 27 CH23 | 95 02
I: (#0) RX 133ms | 27 CH23 | 95 03
I: (#0) RX 187ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2878, s: 2793, f: 7, n: 78 | p: 2
I: last tx setup: 9ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  50ms | 27 CH40 | 95 01
I: (#1) RX 122ms | 23 CH40 | 95 83
W: (#1) frame 2 missing: request retransmit (3 attempts left)
I: (#1) TX 11 CH3 | 15 F8 82
I: (#1) RX  29ms | 27 CH40 | 95 02
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 681ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2892, s: 2819, f: 5, n: 68 | p: 2
I: last tx setup: 16ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  20ms | 27 CH23 | 95 01
I: (#0) RX  84ms | 27 CH23 | 95 02
I: (#0) RX 119ms | 27 CH23 | 95 03
I: (#0) RX 183ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2879, s: 2794, f: 7, n: 78 | p: 2
I: last tx setup: 4ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  40ms | 27 CH40 | 95 01
I: (#1) RX  93ms | 27 CH40 | 95 02
I: (#1) RX 147ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 448ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2893, s: 2820, f: 5, n: 68 | p: 2
I: last tx setup: 22ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  16ms | 27 CH23 | 95 01
I: (#0) RX  69ms | 27 CH23 | 95 02
I: (#0) RX 123ms | 27 CH23 | 95 03
I: (#0) RX 166ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2880, s: 2795, f: 7, n: 78 | p: 2
I: last tx setup: 2ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  39ms | 27 CH40 | 95 01
I: (#1) RX  74ms | 27 CH40 | 95 02
I: (#1) RX 128ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 411ms
-----
I: (#0) Radio infos: -6 -6 -6 -6 4 | t: 2894, s: 2821, f: 5, n: 68 | p: 2
I: last tx setup: 37ms
I: (#0) TX 27 CH75 | 15 0B 80
I: (#0) RX  27ms | 27 CH23 | 95 01
I: (#0) RX  84ms | 27 CH23 | 95 02
I: (#0) RX 147ms | 27 CH23 | 95 03
I: (#0) RX 180ms | 27 CH23 | 95 84
I: (#0) I: (#0) Payload (62)
-----
I: (#1) Radio infos: 4 -6 -6 -6 -6 | t: 2881, s: 2796, f: 7, n: 78 | p: 2
I: last tx setup: 9ms
I: (#1) TX 27 CH3 | 15 0B 80
I: (#1) RX  22ms | 27 CH40 | 95 01
I: (#1) RX  75ms | 27 CH40 | 95 02
I: (#1) RX 129ms | 23 CH40 | 95 83
I: (#1) I: (#1) Payload (42)
-----
I: com loop duration: 427ms
-----

 ets Jan  8 2013,rst cause:4, boot mode:(3,7)

wdt reset
load 0x4010f000, len 3424, room 16 
tail 0
chksum 0x2e
load 0x3fff20b8, len 40, room 8 
tail 0
chksum 0x2b
csum 0x2b
v00098fe0
~ld
 nrn|ll`bbrlnBnl`rllI: Initializing FS ..
I:  .. done
I: Config Version: 9
I: Settings valid: true
I: Radio Config:
SPI Frequency       = 1 Mhz
Channel         = 76 (~ 2476 MHz)
Model           = nRF24L01+
RF Data Rate        = 250 KBPS
RF Power Amplifier  = PA_LOW
RF Low Noise Amplifier  = Enabled
CRC Length      = 16 bits
Address Length      = 5 bytes
Static Payload Length   = 32 bytes
Auto Retry Delay    = 1000 microseconds
Auto Retry Attempts = 15 maximum
Packets lost on
    current channel = 0
Retry attempts made for
    last transmission   = 3
Multicast       = Disabled
Custom ACK Payload  = Disabled
Dynamic Payloads    = Enabled
Auto Acknowledgment = Enabled
Primary Mode        = TX
TX address      = 0x0782238401
pipe 0 ( open ) bound   = 0x0782238401
pipe 1 ( open ) bound   = 0xe55f768101
pipe 2 (closed) bound   = 0xc3
pipe 3 (closed) bound   = 0xc4
pipe 4 (closed) bound   = 0xc5
pipe 5 (closed) bound   = 0xc6
I: DTU_SN: 81765fe5

---------
AhoyDTU Info:
Version: 0.8.65
Github Hash: 97d74d3

---------
AP MODE
SSID: AHOY-DTU
PWD: esp_8266
IP Address: http://192.168.4.1
---------
lumapu commented 7 months ago

also beide ESPs (8266 und 32). Im letzten log hat er 2880 Sendeloops gemacht und ist dann abgestĂŒrzt. Ist dort noch MqTT oder ein Display konfiguriert?

lumapu commented 7 months ago

@MetaChuh kannst du auch mal ohne Display versuchen, sieht nach ePaper aus. Und evtl. die neueste 0.8.65.

mellow5 commented 7 months ago

also beide ESPs (8266 und 32). Im letzten log hat er 2880 Sendeloops gemacht und ist dann abgestĂŒrzt. Ist dort noch MqTT oder ein Display konfiguriert?

Hab jetzt Mal mqtt aus geschaltet. Display hab ich nicht

MetaChuh commented 7 months ago

hi @lumapu

thx, test lĂ€uft bereits seit kurz nach deinem build (stillschweigend, statt zu frĂŒh was zu sagen, dann wieder revidierend zurĂŒck rudern, dann wieder vor und ... 😉)

ergebnisse vom dauertest (ahoy dtu 0.8.65-97d74d3) seit 2024-01-25 03:44:

test1 - dauertest mit api poll im 10s intervall:

verwendete api endpoints: api/index (ts_*, inverter, is_avail, is_producing) api/inverter/id/[0-4] api/setup (device_name)

hardware: AZ-Delivery ESP32 D1 Mini (ESP32-D0WD-V3, 2x240mhz) Generic NRF24L01+PA+LNA SMA Antenna Waveshare 1.54" E-Paper Rev 2.1 (angeschlossen und aktiviert)

settings: factory default mit e-paper display und minimalen pin anpassungen (esp32 d1 mini pin position angleichung zu esp8266 d1 mini, als drop in replacement, pin kompatibel mit der aktuellen esp8266 ahoy dtu pin belegung) kein mqtt kein cmp2300a

uptime: 1 Day, 04:42:47 (bis dahin ohne reboots)

test2 - erhöhen auf api poll 2s intervall (gleiche endpoints):

ergebnisse folgen per edit

edit:

bei 2 sekunden poll, nach wenigen minuten, bootloop wenige sekunden nach wifi connect (async, watchdog)

preset ist 8 sekunden, jedoch sobald ein bootloop losgeht, rebootet er nur 1-2 sekunden nach wifi connect

siehe: app.h #define WDT_TIMEOUT_SECONDS 8 // Watchdog Timeout 8s eingebaut seit commit Watchdog 28dbc8b von @tictrick

evtl mal WDT_TIMEOUT_SECONDS konfigurierbar machen oder in einer testversion auf 30 setzen ? edit: schon probiert, WDT_TIMEOUT_SECONDS 30 bringt mit 0.8.65 bei mir keine verbesserung.

edit: esp_task_wdt_init(WDT_TIMEOUT_SECONDS, false); brachte auch keine verbesserung

notes:

kannst du auch mal ohne Display versuchen

mit 0.8.54 minimal ohne e-paper hatte ich ebenfalls reboots bis bootloops, jedoch nur im wifi mode, nicht im ap mode 0.6.9 lief ohne bootloops, mit seltenen reboots (alle 1-14+ tage)

thx & greetings metachuh

mellow5 commented 7 months ago

Bin zurĂŒck auf ESP32 0.8.65. Seit ich mqtt ausgeschaltet habe lĂ€uft Ahoy seit nunmehr drei Tagen durch.

HM1500 HM800 kein Display call der inverter api id 0 einmal pro Sekunde call der inverter api id 1 einmal pro Sekunde call der index api einmal pro Sekunde Update aller 5 Sekunden

Ich weiß es macht keien Sinn einmal pro Sekunde die api abzufragen, aber bei alten Versionen konnte ich die daten aller Sekunde aktualisieren von Ahoy. Und ich mache RĂŒckspeiseregelung.

Bei RĂŒckspeiseregelung wie die letzten Tage können je Umrichter bis zu aller 2 Sekunden power limits per api geschickt werden.

Hat prima fuktioniert die letzten Tage. FĂŒr mich ist es ok, ich komme auch gut ohne MQTT aus.

lumapu commented 7 months ago

verstehe ich es richtig, dass alle, die hier in dem Ticket schreiben API-Polls machen?

MetaChuh commented 7 months ago

seit @mellow5 's letzter antwort glaube ich (in diesem issue) ja. @mellow5: Bin zurĂŒck auf ESP32 0.8.65. Seit ich mqtt ausgeschaltet habe lĂ€uft Ahoy seit nunmehr drei Tagen durch ... ich komme auch gut ohne MQTT aus.

ich wie immer ausschließlich api.

ps: ich komme ebenfalls derzeit mit den alten versionen produktiv gut aus und teste die neuen sowieso nur auf einer der separaten dev dtus.

der reboot bis bootloop fehler hat sich anscheinend irgendwann, zwischen v0.7.x bis jetzt eingeschlichen, jedoch zu wenig zeit zum alle builds durchzugehen und dann, sobald ich die Àlteste version finde, die in dieser umgebung rebootet, dann mir die diffs anzusehen.

lumapu commented 7 months ago

der Fehler ist aber reproduzierbar, daher kann man auch einfach den aktuellen Code quÀlen und dabei bisschen loggen. Das sollte doch zu finden sein ...

mellow5 commented 7 months ago

Nach 5 Tagen online habe ich heute Nacht auf die aktuelle DEV 0.8.69 gewechselt. Heute morgen dann wieder eine Reboot

I: (#0) Radio infos: 4 -6 -6 2 1 | t: 1572, s: 1178, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  25ms | 27 CH61 | 95 01
I: (#0) RX  79ms | 27 CH61 | 95 02
I: (#0) RX 132ms | 27 CH61 | 95 03
I: (#0) RX 175ms | 27 CH61 | 95 84
I: (#0) Payload (62)
-----
I: (#0) Radio infos: 4 -6 -6 2 1 | t: 1573, s: 1179, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 15 80
I: (#0) RX  34ms | 17 CH61 | 95 81
I: (#0) Payload (4)
I: (#0) Inv loss: 0 of 13, DTU loss: 2 of 43. ACKs: 13
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1560, s: 1068, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 0B 80
I: (#1) RX  46ms | 27 CH61 | 95 01
I: (#1) RX  85ms | 27 CH61 | 95 02
I: (#1) RX 128ms | 23 CH61 | 95 83
I: (#1) Payload (42)
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1561, s: 1069, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 15 80
I: (#1) RX  20ms | 17 CH61 | 95 81
I: (#1) Payload (4)
I: (#1) Inv loss: 1 of 12, DTU loss: 0 of 31. ACKs: 10
-----
I: com loop duration: 609ms
-----
I: (#0) Radio infos: 4 -6 -6 2 1 | t: 1574, s: 1180, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  34ms | 27 CH61 | 95 01
I: (#0) RX  77ms | 27 CH61 | 95 02
I: (#0) RX 131ms | 27 CH61 | 95 03
I: (#0) RX 184ms | 27 CH61 | 95 84
I: (#0) Payload (62)
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1562, s: 1070, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 0B 80
I: (#1) RX  36ms | 27 CH61 | 95 01
I: (#1) RX  92ms | 27 CH61 | 95 02
I: (#1) RX 135ms | 23 CH61 | 95 83
I: (#1) Payload (42)
-----
I: com loop duration: 439ms
-----
I: (#0) Radio infos: 4 -6 -6 2 1 | t: 1575, s: 1181, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  46ms | 27 CH61 | 95 01
I: (#0) RX  89ms | 27 CH61 | 95 02
I: (#0) RX 142ms | 27 CH61 | 95 03
I: (#0) RX 196ms | 27 CH61 | 95 84
I: (#0) Payload (62)
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1563, s: 1071, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 0B 80
I: (#1) RX  37ms | 27 CH61 | 95 01
I: (#1) RX  86ms | 27 CH61 | 95 02
I: (#1) RX 139ms | 23 CH61 | 95 83
I: (#1) Payload (42)
-----
I: com loop duration: 454ms
-----
I: (#0) Radio infos: 4 -6 -6 2 1 | t: 1576, s: 1182, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  23ms | 27 CH61 | 95 01
I: (#0) RX 186ms | 27 CH61 | 95 84
I: (#0) 2 frames missing -> complete retransmit
I: (#0) Radio infos: 3 -6 -6 2 1 | t: 1576, s: 1182, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  36ms | 27 CH61 | 95 01
I: (#0) RX  90ms | 27 CH61 | 95 02
I: (#0) RX 143ms | 27 CH61 | 95 03
I: (#0) RX 186ms | 27 CH61 | 95 84
I: (#0) Payload (62)
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1564, s: 1072, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 0B 80
I: (#1) RX  20ms | 27 CH61 | 95 01
I: (#1) RX  68ms | 27 CH61 | 95 02
I: (#1) RX 121ms | 23 CH61 | 95 83
I: (#1) Payload (42)
-----
I: com loop duration: 680ms
-----
I: (#0) Radio infos: 3 -6 -6 2 1 | t: 1577, s: 1183, f: 26, n: 368 | p: 2
I: (#0) TX 27 CH03, 9 ret., rx offset: 3 | 15 0B 80
I: (#0) RX  32ms | 27 CH61 | 95 01
I: (#0) RX  86ms | 27 CH61 | 95 02
I: (#0) RX 139ms | 27 CH61 | 95 03
I: (#0) RX 182ms | 27 CH61 | 95 84
I: (#0) Payload (62)
-----
I: (#1) Radio infos: 1 4 -1 1 1 | t: 1565, s: 1073, f: 6, n: 486 | p: 2
I: (#1) TX 27 CH23, 9 ret., rx offset: 3 | 15 0B 80
I: (#1) RX  31ms | 27 CH61 | 95 01
I: (#1) RX  80ms | 27 CH61 | 95 02
I: (#1) RX 143ms | 23 CH61 | 95 83
I: (#1) Payload (42)
-----
I: com loop duration: 446ms
-----

assert failed: tcp_update_rcv_ann_wnd IDF/components/lwip/lwip/src/core/tcp.c:951 (new_rcv_ann_wnd <= 0xffff)

Backtrace: 0x40083c71:0x3ffb2cc0 0x4008c94d:0x3ffb2ce0 0x40092c05:0x3ffb2d00 0x40126efe:0x3ffb2e30 0x40126fac:0x3ffb2e50 0x400f2916:0x3ffb2e70 0x40123c94:0x3ffb2e90

MQTT war weiterhin nicht aktiv.

lumapu commented 7 months ago

du hast aber weiterhin das API-Polling aktiv?

mellow5 commented 7 months ago

du hast aber weiterhin das API-Polling aktiv?

Ja

hackman6 commented 6 months ago

Gibt es hierzu inzwischen neues? Auch mit 0.8.83 habe ich stÀndig reboot mit zwei ESP32 an unterschiedlichen Standorten.

lumapu commented 6 months ago

probiere gerne unsere development builds, die sind aktuell mehr stable als die stable 😅 https://fw.ahoydtu.de/fw/dev/

MetaChuh commented 6 months ago

@hackman6

Gibt es hierzu inzwischen neues? Auch mit 0.8.83 habe ich stÀndig reboot mit zwei ESP32 an unterschiedlichen Standorten.

ja vieles, v0.8.88 rennt stabil bei mir mit heavy api polling (alle 1s) aller inverterdaten, paneldaten und systemdaten.

zusÀtzlich zu v0.8.88 oder v0.8.89 testen: stelle sicher, dass nie durch einen cron job oder anderen geplanten tasks, mehrere api abfragen gleichzeitig auf die dtu zugreifen, weil die vorherige abfrage noch nicht abgeschlossen wurde.

mellow5 commented 6 months ago

du hast aber weiterhin das API-Polling aktiv?

Ich wechsle vermutlich auf MQTT zurĂŒck, wenn es als JSON kommt.

mellow5 commented 4 months ago

Habe jetzt seit geraumer Zeit und dev Versionen MQTT wieder aktiviert. Die zufÀlligen Reboots kommen bei mir nicht mehr.

SUHAN447 commented 4 months ago

assert failed: tcp_update_rcv_ann_wnd IDF/components/lwip/lwip/src/core/tcp.c:951 (new_rcv_ann_wnd <= 0xffff)

Backtrace: 0x40083671:0x3ffb2cc0 0x4008bc95:0x3ffb2ce0 0x40091261:0x3ffb2d00 0x400f0599:0x3ffb2e30 0x400f0644:0x3ffb2e50 0x400d2db2:0x3ffb2e70 0x400ed64c:0x3ffb2e90

Hello, I have the same problem, but I still haven't found a solution. I use Platform IO TCP library AsyncHTTPSRequest_Generic The code suddenly resets at random intervals. I would be happy if anyone can help me solve it.

MetaChuh commented 4 months ago

@SUHAN447 please clarify for better understanding: which ahoydtu version are you using, in which solar setup, and how is it related to this specific issue ?

@mellow5 was your original issue solved ? if yes, please close it, to prevent hijacking of past issues wihout topic relevance.

thx & greetings, metachuh