Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Loosing WiFi connection after X minutes #15

Closed
andreas5232 opened this issue Apr 28, 2022 · 48 comments
Closed

Loosing WiFi connection after X minutes #15

andreas5232 opened this issue Apr 28, 2022 · 48 comments
Labels
bug Something isn't working fixed dev fixed

Comments

@andreas5232
Copy link
Contributor

Most important: You guys rock! :-)

I'm trying to run ahoy on a NodeMCU board with NRF attached.

Everything is working fine at first. Data is read from HM-600 and displayed correctly on the web interface. But after roundabout 10 minutes the system seems to loose its wifi connection. The web interface is no longer available and the device can't be pinged. The LED on the board keeps blinking in the same interval as before the break down. After a reboot/reset of the board everything is fine again for a few minutes.

I'm not sure if I'll be able to debug this on my own and if it does affect other setups too, so I opened this issue.

Keep up the great work!

Cheers
Andreas

@lumapu
Copy link
Owner

lumapu commented Apr 28, 2022

Hey Andreas,
I faced the same behaviour. Once it happend while my serial console was connected and I were able to check the exception.
I read somewhere that there should be no delay(xxx) in ESP code (while WiFi connection is established)

For me I commented two lines in app.cpp
https://github.com/grindylow/ahoy/blob/1e7a8ea8696b4ab503208b20ccfc18f42d34a992/tools/esp8266/app.cpp#L167
and
https://github.com/grindylow/ahoy/blob/1e7a8ea8696b4ab503208b20ccfc18f42d34a992/tools/esp8266/app.cpp#L187

Since then I have an uptime of more than 2 hours . I will commit this change if it does not interrupt any more in the next hours.

@andreas5232
Copy link
Contributor Author

Hey lumapu,

I've just flashed my NodeMCU with your potential fix.
Guess what? It's running since 30min without any interruptions or necessary reboots. So I'd consider it as a working fix.

Thanks for your support and all your efforts with this project!

@lumapu
Copy link
Owner

lumapu commented Apr 28, 2022

I took the rest of the day testing .. the ESP chrashed no more. Wait for more responses before closing this issue

@stefan123t
Copy link
Collaborator

stefan123t commented Apr 29, 2022

@lumapu, yes this is correct the WiFi is running on the same core in the ESP8266. The ESP32 has two cores, hence the WiFi stack is running on one CPU core while most of the user program runs on the other. You have this concept also on the nRF52832/52840 where the BLE stack runs on one core and the user program on the other.

Hence you have to feed the watchdog every now and then. You can purposefully feed it using the yield() call method. Though I think you already committed that somewhere.

I have also seen that you implemented three tickers , which should be useful to order things in main/app that occur after specific periods, e.g. every 10 seconds or every 5 minutes. I tend to use old school C:

if (millis() >= timer) 
   {
       timer = millis()+10000; 
       do the needful
}; 

as a kind of pseudo scheduler to prevent running some code more often than necessary.

@lumapu
Copy link
Owner

lumapu commented Apr 29, 2022

@stefan123t, thank you for your comment - very interesting topic.
Does 'specific period' have a lower limit of time? For now two tickers which have an interval of 1s (uptime and send command), second has an interval of 10s (mqtt send).
I understand your old school C example. I' ll check the docs about tickers again.

For the uptime I think the ticker is more precisely because of a fired interrupt (I don't know it exactly but this is my idea how it works)

@stefan123t
Copy link
Collaborator

@lumapu naturally the sky is the limit. Here we have to take the runtime of our individual co-routines into account. hence if they take more than several seconds to complete their tasks that will be the lower limit "sometimes". While if these long running sub routines are not scheduled at the moment, then the loop can complete quite fast, i.e. several times per second. The timers are based on milliseconds as a default so this is the numeric minimum =^D.

Regarding the interrupts I am not sure how well they behave as we also have a hardware interrupt for reading the nRF24L01+ and the WiFi is also kicking in via an interrupt. As mentioned this is probably more of an issue on ESP8266 which is why ESP32 having two cores is usually considered more stable.

You may also add Debug Level HTTP_SERVER or similar CORE+...+MDNS and use Debug Port Serial to enable the information from the ESP8266WebServer module. I have seen some request being queued on the network / router which seem to be worked by the WebServer after it comes up. Should we also reconsider when to enable and load the individual "webpages" in the WebServer ? Currently it starts the WebServer even before the WiFi connection is up and running.

@stefan123t
Copy link
Collaborator

Early knowledge gained from issues on the esp8266 project by igrr (Ivan Grokhotkov) and others making the same mistakes before us. I have just re-read that and it looks like we have to call yield() or delay() every now and then to feed the watch dog to prevent it from starvation. ❤️ & 🥩 for 🐕

esp8266/Arduino#34
https://randomnerdtutorials.com/interrupts-timers-esp8266-arduino-ide-nodemcu/

Oh BTW I have been diving deep into the rabbit hole some months ago with a thread called Embed with Elliot on Hackaday. Not sure I understood everything but I assume he got us covered with interrupts the good, the bad and the ugly:

https://hackaday.com/2015/09/18/embed-with-elliot-interrupts-the-good/
https://hackaday.com/2015/09/25/embed-with-elliot-interrupts-the-bad/
https://hackaday.com/2015/10/02/embed-with-elliot-interrupts-the-ugly/

OT-Bonus:
https://hackaday.com/2015/09/04/embed-with-elliot-practical-state-machines/
https://majenko.co.uk/blog/our-blog-1/the-evils-of-arduino-strings-32

@lumapu
Copy link
Owner

lumapu commented May 1, 2022

I just published a version which uses the 'old-school-c' timer as you described before. Testing it over the day had the same result as the ticker variant - we will see if the uptime can grow to more than a day with that implementation.

@stefan123t
Copy link
Collaborator

stefan123t commented May 2, 2022

Mist noch während ich den Kommentar im Forum abgesetzt habe, hat sich der ESP wohl unbemerkt von mir verabschiedet.
Werde jetzt doch mal die 0.3.3 kompilieren und testen...

Version war 0.2.11:

Serial Output - Click to expand!
18:20:27.473 -> http-server loop: conn=1 avail=0 status=wait-read
18:20:27.473 -> check_poison_block is called for free block 0x3fff2208
18:20:27.473 -> Fatal exception 3(LoadStoreErrorCause):
18:20:27.473 -> epc1=0x401007ed, epc2=0x00000000, epc3=0x00000000, excvaddr=0x400322d9, depc=0x00000000
18:20:27.473 -> 
18:20:27.473 -> --------------- CUT HERE FOR EXCEPTION DECODER ---------------
18:20:27.506 -> 
18:20:27.506 -> Exception (3):
18:20:27.506 -> epc1=0x401007ed epc2=0x00000000 epc3=0x00000000 excvaddr=0x400322d9 depc=0x00000000
18:20:27.506 -> 
18:20:27.506 -> >>>stack>>>
18:20:27.506 -> 
18:20:27.506 -> ctx: sys
18:20:27.506 -> sp: 3fffec10 end: 3fffffb0 offset: 0190
18:20:27.506 -> 3fffeda0:  3ffeff58 00000004 3fff2208 40100a45  
18:20:27.506 -> 3fffedb0:  00000456 00000456 3ffe85dc 40100b51  
18:20:27.506 -> 3fffedc0:  00000456 00000456 3ffe85dc 3fff2214  
18:20:27.539 -> 3fffedd0:  00000000 00000020 3fff220c 40100e76  
18:20:27.539 -> 3fffede0:  00000000 00000000 00000000 40100e94  
18:20:27.539 -> 3fffedf0:  00000111 3ffe85dc 3fff3d90 4010057c  
18:20:27.539 -> 3fffee00:  00000111 00000000 3fff3a70 40224d90  
18:20:27.539 -> 3fffee10:  00000763 00000763 3ffe85dc 4021ccd1  
18:20:27.539 -> 3fffee20:  00000763 00000763 3ffe85dc 4021d7d8  
18:20:27.539 -> 3fffee30:  3fff2214 00000020 3fff3a74 4021de5f  
18:20:27.539 -> 3fffee40:  3fff2214 00000000 00000000 40100e94  
18:20:27.572 -> 3fffee50:  000063aa f5e2ab9f 00000000 4010057c  
18:20:27.572 -> 3fffee60:  3fff2214 3ffeff08 00000006 3ffeff04  
18:20:27.572 -> 3fffee70:  3fff2214 3ffeff08 00000005 4021dec8  
18:20:27.572 -> 3fffee80:  3fff2214 3ffeff08 00000005 402268df  
18:20:27.572 -> 3fffee90:  00000000 00000000 4bc6a7f0 00000000  
18:20:27.572 -> 3fffeea0:  00000019 00000000 3fff3338 401009b0  
18:20:27.572 -> 3fffeeb0:  00000000 00000000 3fff32f8 3ffefab8  
18:20:27.606 -> 3fffeec0:  3ffefd38 3fff3a9a 3fff3a7c 40224081  
18:20:27.606 -> 3fffeed0:  00000014 3ffefab8 3ffe85dc 3fff1e0c  
18:20:27.606 -> 3fffeee0:  00000000 00000020 3fff32fc 40100e76  
18:20:27.606 -> 3fffeef0:  3fffdc80 3fff03a4 3fff3304 3fff1e0c  
18:20:27.606 -> 3fffef00:  3ffefab8 00000008 3fff3a7c 4021cba1  
18:20:27.606 -> 3fffef10:  3fffdc80 3fff03a4 3fff3304 4021c9a0  
18:20:27.606 -> 3fffef20:  40244f29 3fff03a4 3fff3304 40244f3b  
18:20:27.639 -> 3fffef30:  3fff3a8c 3fff3a7c 00000000 3ffe85d8  
18:20:27.639 -> 3fffef40:  4024198b 00000000 3fff3304 40246213  
18:20:27.639 -> 3fffef50:  40000f49 3fffdab0 3fffdab0 40000f49  
18:20:27.639 -> 3fffef60:  40000e19 00058a85 00000000 00000005  
18:20:27.639 -> 3fffef70:  3fffefc0 aa55aa55 000000ed 40105881  
18:20:27.639 -> 3fffef80:  40105887 00000000 00000005 40100e50  
18:20:27.639 -> 3fffef90:  4010000d 646f623c 00058a85 401000ac  
18:20:27.672 -> 3fffefa0:  40236910 3fffef3c 402368c9 3ffffe48  
18:20:27.672 -> 3fffefb0:  3fffffc0 00000000 00000000 feefeffe  
18:20:27.672 -> 3fffefc0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.672 -> 3fffefd0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.672 -> 3fffefe0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.672 -> 3fffeff0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.672 -> 3ffff000:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.672 -> 3ffff010:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff020:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff030:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff040:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff050:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff060:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff070:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.705 -> 3ffff080:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff090:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.738 -> 3ffff0f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff100:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff110:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff120:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff130:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff140:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff150:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.771 -> 3ffff160:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff170:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff180:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff190:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff1a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff1b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff1c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.805 -> 3ffff1d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff1e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff1f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff200:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff210:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff220:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff230:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.838 -> 3ffff240:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff250:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff260:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff270:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff280:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff290:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff2a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.871 -> 3ffff2b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff2c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff2d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff2e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff2f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff300:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff310:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff320:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.904 -> 3ffff330:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff340:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff350:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff360:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff370:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff380:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.937 -> 3ffff390:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff3f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff400:  feefeffe feefeffe feefeffe feefeffe  
18:20:27.970 -> 3ffff410:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff420:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff430:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff440:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff450:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff460:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff470:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.003 -> 3ffff480:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff490:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.036 -> 3ffff4f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff500:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff510:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff520:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff530:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff540:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff550:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.070 -> 3ffff560:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff570:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff580:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff590:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff5a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff5b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff5c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff5d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.105 -> 3ffff5e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff5f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff600:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff610:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff620:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff630:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff640:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.137 -> 3ffff650:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff660:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff670:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff680:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff690:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff6a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff6b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.170 -> 3ffff6c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff6d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff6e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff6f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff700:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff710:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff720:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.203 -> 3ffff730:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff740:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff750:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff760:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff770:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff780:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff790:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.236 -> 3ffff7a0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff7b0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff7c0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff7d0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff7e0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff7f0:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff800:  feefeffe feefeffe feefeffe feefeffe  
18:20:28.270 -> 3ffff810:  feefeffe 00000000 feefeffe 0000002b  
18:20:28.270 -> 3ffff820:  000000b0 00000001 401056cd 3ffedec8  
18:20:28.303 -> 3ffff830:  3ffede50 feefeffe feefeffe feefeffe  
18:20:28.303 -> 3ffff840:  feefeffe 00000000 0000000f 000000c9  
18:20:28.303 -> 3ffff850:  00000069 00000001 401056cd 3ffedec8  
18:20:28.303 -> 3ffff860:  3ffede50 00000000 0000000f 40101430  
18:20:28.303 -> 3ffff870:  40100348 00000001 0000000f 40101430  
18:20:28.303 -> 3ffff880:  401052b2 3ffedec8 000000ff 40100378  
18:20:28.303 -> 3ffff890:  40100348 40104b1d 3ffedec8 4020ad19  
18:20:28.336 -> 3ffff8a0:  00000069 00000001 3fff0b4c 4020ad84  
18:20:28.336 -> 3ffff8b0:  401051b5 3ffedec8 3ffed3a8 00040000  
18:20:28.336 -> 3ffff8c0:  23002200 00000000 3fff0b4c 000000c6  
18:20:28.336 -> 3ffff8d0:  000000b0 00000001 401056cd 3ffedec8  
18:20:28.336 -> 3ffff8e0:  3ffede50 00000001 3fff12bc 402019fc  
18:20:28.336 -> 3ffff8f0:  01fede50 00000000 0000007f 0000002d  
18:20:28.336 -> 3ffff900:  00000069 00000001 401056cd 3ffedec8  
18:20:28.336 -> 3ffff910:  3ffede50 40104b1d 3ffedec8 40201b18  
18:20:28.369 -> 3ffff920:  4000d989 00000030 0000001f ffffffff  
18:20:28.369 -> 3ffff930:  401052b2 3ffedec8 3ffed470 00040000  
18:20:28.369 -> 3ffff940:  23002200 40104c01 3ffedec8 3fffc278  
18:20:28.369 -> 3ffff950:  4010542e 00080000 00000002 00000000  
18:20:28.369 -> 3ffff960:  401053c9 3ffedec8 00000008 00040000  
18:20:28.369 -> 3ffff970:  50592200 00000000 0000007f 00000002  
18:20:28.369 -> 3ffff980:  40105485 00080000 00000002 3fffc278  
18:20:28.402 -> 3ffff990:  4010375a 3fffc200 00000022 3ffed448  
18:20:28.402 -> 3ffff9a0:  000005e0 00000000 40104585 3ffede80  
18:20:28.402 -> 3ffff9b0:  0000003c 00000000 0000000a 000000ff  
18:20:28.402 -> 3ffff9c0:  0000001c 00000001 401056cd 3ffede80  
18:20:28.402 -> 3ffff9d0:  3ffede50 00000000 00000000 000000ae  
18:20:28.402 -> 3ffff9e0:  000000cf 00000001 401056cd 3ffedec8  
18:20:28.402 -> 3ffff9f0:  00000002 00000000 0000000a 00000000  
18:20:28.436 -> 3ffffa00:  00000002 00000000 40242aeb 00000000  
18:20:28.436 -> 3ffffa10:  ffffffff 00000000 3ffe9e51 00000000  
18:20:28.436 -> 3ffffa20:  40242b3a 00000000 0000000f 40101430  
18:20:28.436 -> 3ffffa30:  40100348 00000001 0000000f 40101430  
18:20:28.436 -> 3ffffa40:  40100348 3fff0b4c 000000ff 40100378  
18:20:28.436 -> 3ffffa50:  40100348 00000000 3fff0b4c 00000046  
18:20:28.436 -> 3ffffa60:  0000005c 00000001 401056cd 3ffedec8  
18:20:28.469 -> 3ffffa70:  3ffede50 000000ff 3fff0b4c 4020aec1  
18:20:28.469 -> 3ffffa80:  3fff0b3c 3fff0b4c 3fff0b4c 4020b052  
18:20:28.469 -> 3ffffa90:  401052b2 3ffedec8 3ffffab3 4020b499  
18:20:28.469 -> 3ffffaa0:  4021a47c 40104b1d 3ffedec8 402019fc  
18:20:28.469 -> 3ffffab0:  01000003 00000000 3ffedec8 000000ca  
18:20:28.469 -> 3ffffac0:  00000064 00000001 401056cd 3ffedec8  
18:20:28.469 -> 3ffffad0:  3ffede50 00000001 00000000 40201b18  
18:20:28.469 -> 3ffffae0:  4010542e 00080000 00000002 40100122  
18:20:28.502 -> 3ffffaf0:  401052b2 3ffedec8 3fff2770 401004e4  
18:20:28.502 -> 3ffffb00:  c0038034 40104c01 3ffedec8 40100a45  
18:20:28.502 -> 3ffffb10:  3ffefab8 2c9f0300 4000050c 3fffc278  
18:20:28.502 -> 3ffffb20:  401053c9 3ffedec8 00000008 00040000  
18:20:28.502 -> 3ffffb30:  53002200 00000030 00000000 ffffffff  
18:20:28.502 -> 3ffffb40:  40105485 00080000 00000002 3ffe9478  
18:20:28.502 -> 3ffffb50:  4010375a 3ffffcf0 00000008 3ffffd40  
18:20:28.535 -> 3ffffb60:  00000000 00000000 3ffffcd3 3ffe9478  
18:20:28.535 -> 3ffffb70:  3ffe9475 2c9f0300 4000050c 3fffc278  
18:20:28.535 -> 3ffffb80:  00000000 00000000 0000000a 00000000  
18:20:28.535 -> 3ffffb90:  00000000 00000000 0000000a 00000000  
18:20:28.535 -> 3ffffba0:  4021a724 40250030 0000000a 40250030  
18:20:28.535 -> 3ffffbb0:  00000000 a0000000 00000000 0000001c  
18:20:28.535 -> 3ffffbc0:  00000000 00000000 00000000 3ffe8368  
18:20:28.568 -> 3ffffbd0:  00000000 00000000 3ffffd40 4021a540  
18:20:28.568 -> 3ffffbe0:  00000005 00000000 00000020 401001c8  
18:20:28.568 -> 3ffffbf0:  40102919 401048da 00000005 401024e8  
18:20:28.568 -> 3ffffc00:  3ffe9d05 4010577f 3ffed740 4021a540  
18:20:28.568 -> 3ffffc10:  40103073 3ffed740 00000009 00000000  
18:20:28.568 -> 3ffffc20:  00000000 07026cc2 3ffee024 40103250  
18:20:28.568 -> 3ffffc30:  3ffea598 00000000 00000000 40215ee4  
18:20:28.568 -> 3ffffc40:  00000000 07026cc2 4010370a 00000100  
18:20:28.601 -> 3ffffc50:  3ffea598 7fffffff 23002200 00000001  
18:20:28.601 -> 3ffffc60:  00000001 00004a88 00000001 00000000  
18:20:28.601 -> 3ffffc70:  3ffea598 00000000 0000007f 07026cc2  
18:20:28.601 -> 3ffffc80:  3ffea5b0 2c9f0300 4000050c 3fffc278  
18:20:28.601 -> 3ffffc90:  4010342c 3fffc200 00000022 00000000  
18:20:28.601 -> 3ffffca0:  40212050 00000030 00000010 ffffffff  
18:20:28.601 -> 3ffffcb0:  40212050 0000007f 6000001c 3ffffe22  
18:20:28.635 -> 3ffffcc0:  4020d68c 3ffffe22 00000001 3ffffd40  
18:20:28.635 -> 3ffffcd0:  00000032 00000000 3ffffcd3 00000000  
18:20:28.635 -> 3ffffce0:  00000065 0000007e fffffffc 00000030  
18:20:28.635 -> 3ffffcf0:  3ffffe70 3ffffe40 00000014 00000030  
18:20:28.635 -> 3ffffd00:  3ffffe70 3ffffe40 00000008 3ffe8368  
18:20:28.635 -> 3ffffd10:  00000009 00000001 00000022 00000000  
18:20:28.635 -> 3ffffd20:  40212841 00000030 00000010 3ffef524  
18:20:28.668 -> 3ffffd30:  3ffffe40 3ffe8368 00000040 40217bdd  
18:20:28.668 -> 3ffffd40:  3ffffe22 40104674 0000000d ffff0208  
18:20:28.668 -> 3ffffd50:  3ffffdf0 0000003f 00000000 00000000  
18:20:28.668 -> 3ffffd60:  3fff0468 00000000 3ffef524 00000030  
18:20:28.668 -> 3ffffd70:  40210c2f 2c9f0300 4000050c 3fffc278  
18:20:28.668 -> 3ffffd80:  4010342c 3fffc200 00000022 fffffffe  
18:20:28.668 -> 3ffffd90:  402083fe 00000030 00000010 ffffffff  
18:20:28.701 -> 3ffffda0:  00000000 00000032 3ffffe21 40212124  
18:20:28.701 -> 3ffffdb0:  3ffffe22 00000008 3fff0444 40217c19  
18:20:28.701 -> 3ffffdc0:  3ffffe70 3ffffe40 00000008 3ffef524  
18:20:28.701 -> 3ffffdd0:  3ffffe40 00000008 3ffffdf0 4020d698  
18:20:28.701 -> 3ffffde0:  40203e4b 00000030 00000010 4020e6c4  
18:20:28.701 -> 3ffffdf0:  70747468 7265732d 20726576 706f6f6c  
18:20:28.701 -> 3ffffe00:  6f63203a 313d6e6e 61766120 303d6c69  
18:20:28.701 -> 3ffffe10:  61747320 3d737574 74696177 6165722d  
18:20:28.734 -> 3ffffe20:  00000a64 733d1187 3ffef300 00000030  
18:20:28.734 -> 3ffffe30:  00000000 00000000 00000001 401001c8  
18:20:28.734 -> 3ffffe40:  007a1200 733d179f 00000000 3fff0468  
18:20:28.734 -> 3ffffe50:  00000001 3ffef524 40210c2f 3fffefa0  
18:20:28.734 -> 3ffffe60:  0001cb5e 40250004 3ffffe70 40210c74 <
18:20:28.734 -> 3ffffe70:  00000001 3fff0994 3fff0994 4020958a  
18:20:28.734 -> 3ffffe80:  00000001 3fff0468 3fff0444 40208341  
18:20:28.767 -> 3ffffe90:  40213d10 00000000 00001388 402019c3  
18:20:28.767 -> 3ffffea0:  00000000 00000000 3fff42f4 00000000  
18:20:28.767 -> 3ffffeb0:  00000000 0000001b 3ffef524 3ffef340  
18:20:28.767 -> 3ffffec0:  3fffdad0 00000000 3ffef340 402084aa  
18:20:28.767 -> 3ffffed0:  3fffdad0 3fff133c 3ffef688 40203e3f  
18:20:28.767 -> 3ffffee0:  00000000 3fffdad0 3ffef69c 00000030  
18:20:28.767 -> 3ffffef0:  00000000 00000031 00000000 00000030  
18:20:28.767 -> 3fffff00:  00796144 3fff006c 3ffef69c 00000030  
18:20:28.801 -> 3fffff10:  00000000 00000031 00000000 00000000  
18:20:28.801 -> 3fffff20:  c2203030 00000000 00000000 001a001f  
18:20:28.801 -> 3fffff30:  00000000 00000000 0011001f 00000000  
18:20:28.801 -> 3fffff40:  312e3532 c2203030 000000b0 0000075b  
18:20:28.801 -> 3fffff50:  3fff1364 3fff1365 00000068 00000034  
18:20:28.801 -> 3fffff60:  007a1200 733d19cf 3fff0f00 0000001d  
18:20:28.801 -> 3fffff70:  00000000 3fff10d1 3fff1375 3fff1364  
18:20:28.834 -> 3fffff80:  00000000 00000000 00000001 3ffef69c  
18:20:28.834 -> 3fffff90:  3fffdad0 00000000 3ffef688 40204b00  
18:20:28.834 -> 3fffffa0:  feefeffe feefeffe 3ffef688 40210cbc  
18:20:28.834 -> <<<stack<<<
18:20:28.834 -> 
18:20:28.834 -> --------------- CUT HERE FOR EXCEPTION DECODER ---------------
18:20:28.867 -> 
18:20:28.867 ->  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
18:20:28.867 -> 
18:20:28.867 -> load 0x4010f000, len 3460, room 16 
18:20:28.867 -> tail 4
18:20:28.867 -> chksum 0xcc
18:20:28.867 -> load 0x3fff20b8, len 40, room 4 
18:20:28.867 -> tail 4
18:20:28.867 -> chksum 0xc9
18:20:28.867 -> csum 0xc9
18:20:28.867 -> v00058a90
18:20:28.867 -> ~ld
18:20:28.933 -> 
18:20:28.933 -> SDK:2.2.2-dev(38a443e)/Core:3.0.2=30002000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-48-g7421258/BearSSL:6105635
18:20:28.933 -> Serial console started
18:20:28.933 -> starting WebServer
18:20:28.933 -> fpm close 1 
18:20:28.933 -> mode : sta(2c:3a:e8:42:9d:f0)
18:20:28.933 -> add if0
18:20:31.785 -> scandone
The ESP Exception Decoded - Click to expand!
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: 0x400322d9

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
0x40224d90: tcp_oos_insert_segment at core/tcp_in.c line 1063
0x4021ccd1: dns_send at core/dns.c line 792
0x4021de5f: tcp_close_shutdown at core/tcp.c line 364
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
0x4021dec8: tcp_close_shutdown at core/tcp.c line 257
0x402268df: pbuf_skip_const at core/pbuf.c line 1159
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
0x40224081: autoip_start at core/ipv4/autoip.c line 261
0x40100e76: umm_free(void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/umm_malloc/umm_malloc.cpp line 595
0x4021cba1: sys_check_timeouts at core/timeouts.c line 369
0x4021c9a0: memp_free at core/memp.c line 383
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
0x40101430: _stopPWM(uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_waveform_pwm.cpp line 264
0x40100348: delayMicroseconds(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 209
0x40101430: _stopPWM(uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_waveform_pwm.cpp line 264
0x40100378: __digitalWrite(uint8_t, uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring_digital.cpp line 87
0x40100348: delayMicroseconds(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 209
0x4020ad19: RF24::read_payload(void*, unsigned char) at /home/user/Arduino/libraries/RF24/RF24.cpp line 428
0x4020ad84: RF24::get_status() at /home/user/Arduino/libraries/RF24/RF24.cpp line 461
0x402019fc: calcYieldDayCh0 (Inverter *, uint8_t) at /tmp/arduino_build_778324/sketch/hmInverter.h line 191
0x40201b18: esp8266webserver::ESP8266WebServerTemplate ::on(Uri const&, std::function ) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/libraries/ESP8266WebServer/src/ESP8266WebServer-impl.h line 236
0x40101430: _stopPWM(uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_waveform_pwm.cpp line 264
0x40100348: delayMicroseconds(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 209
0x40101430: _stopPWM(uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_waveform_pwm.cpp line 264
0x40100348: delayMicroseconds(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 209
0x40100378: __digitalWrite(uint8_t, uint8_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring_digital.cpp line 87
0x40100348: delayMicroseconds(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_wiring.cpp line 209
0x4020aec1: RF24::RF24(unsigned short, unsigned short, unsigned int) at /home/user/Arduino/libraries/RF24/RF24.cpp line 527
0x4020b052: RF24::stopListening() at /home/user/.arduino15/packages/esp8266/tools/xtensa-lx106-elf-gcc/3.0.4-gcc10.3-1757bed/xtensa-lx106-elf/include/sys/pgmspace.h line 100
0x4020b499: RF24::enableDynamicPayloads() at /home/user/Arduino/libraries/RF24/RF24.cpp line 1528
0x4021a47c: _svfprintf_r at /workdir/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 566
0x402019fc: calcYieldDayCh0 (Inverter *, uint8_t) at /tmp/arduino_build_778324/sketch/hmInverter.h line 191
0x40201b18: esp8266webserver::ESP8266WebServerTemplate ::on(Uri const&, std::function ) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/libraries/ESP8266WebServer/src/ESP8266WebServer-impl.h line 236
0x40100122: handleIntr() at /home/user/git/HM-600 DTU/ahoy-lumapu-main/tools/esp8266/esp8266.ino line 32
0x401004e4: interrupt_handler(void*, void*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/interrupts.h line 29
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
0x4021a724: _vprintf_r at /workdir/repo/newlib/newlib/libc/stdio/vprintf.c line 50
0x4021a540: _svfprintf_r at /workdir/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 602
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
0x4021a540: _svfprintf_r at /workdir/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 602
0x40215ee4: _scanf_float at /workdir/repo/newlib/newlib/libc/stdio/nano-vfscanf_float.c line 231
0x40212050: uart_init(int, int, int, int, int, size_t, bool) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/uart.cpp line 661
0x40212050: uart_init(int, int, int, int, int, size_t, bool) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/uart.cpp line 661
0x4020d68c: dhcps_stop() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/LwipDhcpServer-NonOS.cpp line 61
0x40212841: experimental::_SPICommand(uint32_t, uint32_t, uint32_t, uint32_t, uint32_t*, uint32_t, uint32_t, uint32_t) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_spi_utils.cpp line 77
0x40217bdd: memmem_P at /workdir/repo/newlib/newlib/libc/sys/xtensa/string_pgmspace.c line 208
0x40210c2f: dtostrf(double, signed char, unsigned char, char*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_noniso.cpp line 88
0x402083fe: Main::setupAp(char const*, char const*) at /tmp/arduino_build_778324/sketch/main.cpp line 105
0x40212124: uart_init(int, int, int, int, int, size_t, bool) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/uart.cpp line 693
0x40217c19: strncpy_P at /workdir/repo/newlib/newlib/libc/sys/xtensa/string_pgmspace.c line 241
0x4020d698: dhcps_stop() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/LwipDhcpServer-NonOS.cpp line 61
0x40203e4b: app::loop() at /tmp/arduino_build_778324/sketch/hmInverter.h line 111
0x4020e6c4: Print::print(unsigned long, int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/Print.cpp line 153
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
0x40210c2f: dtostrf(double, signed char, unsigned char, char*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_noniso.cpp line 88
0x40210c74: dtostrf(double, signed char, unsigned char, char*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_noniso.cpp line 99
0x4020958a: WiFiClient::status() at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/libraries/ESP8266WiFi/src/WiFiClient.cpp line 335
0x40208341: Main::setupStation(unsigned int) at /tmp/arduino_build_778324/sketch/main.cpp line 134
0x402019c3: calcYieldDayCh0 (Inverter *, uint8_t) at /tmp/arduino_build_778324/sketch/hmInverter.h line 188
0x402084aa: Main::setupAp(char const*, char const*) at /tmp/arduino_build_778324/sketch/main.cpp line 110
0x40203e3f: app::loop() at /tmp/arduino_build_778324/sketch/hmInverter.h line 111
0x40204b00: S2Stream::peekConsume(unsigned int) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/StreamString.h line 183
0x40210cbc: dtostrf(double, signed char, unsigned char, char*) at /home/user/.arduino15/packages/esp8266/hardware/esp8266/3.0.2/cores/esp8266/core_esp8266_noniso.cpp line 107

@lumapu
Copy link
Owner

lumapu commented May 2, 2022

Version 0.3.3 läuft bei mir seit 23:05h ohne Absturz, das Upgrade lohnt sich bestimmt. Die Uhr geht auch nur ein dreiviertel Minute nach - das passt von der Genauigkeit, man kann ja alle 24h einen NTP Update einbauen.

@andreas5232
Copy link
Contributor Author

Ich habe auch erfolgreich die 0.3.3 über Nacht laufen lassen und jetzt eine Uptime von über 24h. Aus meiner Sicht ist es damit stabil. Das NTP Update einmal am Tag wäre natürlich noch eine feine Sache.

@rosch99
Copy link

rosch99 commented May 3, 2022

Ich habe ebenfalls die 0.3.3 auf einem Wemos D1 mini der momentan direkt neben dem AccessPoint liegt und bekomme nur sehr selten Verbindung. Ich habe das Gefühl die WIFI-Verbindung war in den Versionen vor 0.3 schon mal deutlich stabiler.
Nach einem Power OFF/ON funktioniert die Verbindung inkl. MQTT für 15-30min, anschliessend nur mehr eine (1) MQTT Verbindung ziemlich genau jede Stunde. Die Webseite ist nicht mehr erreichbar bis zum nächsten Power OFF/ON.
Ich werde es aber zur Sicherheit in den nächsten Tagen noch mal mit neuer Hardware probieren.

@lumapu
Copy link
Owner

lumapu commented May 3, 2022

Den MQTT Fehler sehe ich bei mir auch, das zwickt sich mit der Systemstabilität da es mit dem delay auf MQTT Seite besser funktioniert hat. Interessant ist hier dieser Issue von der MQTT Lib:
knolleary/pubsubclient#182

@stefan123t
Copy link
Collaborator

Ich habe ihn auch mutmaßlich längere Zeit am Laufen. Nur hat er wegen Empfangsproblemen die Verbindung zum WLAN eingestellt, so daß ich nicht weiß ob er durchgelaufen ist oder einen Reset hatte ... Im Serial Monitor sehe ich nur die Nachrichten alle paar Sekunden.
Also zusätzlich zum NTP Update min. ein/mehrmals am Tag sollte das Programm m.E. auch versuchen die konfigurierte WLAN Verbindung alle 10 Minuten wieder zu aktivieren.

@stefan123t
Copy link
Collaborator

Der ESP startet auch zwei unterschiedliche WebServer Konfigurationen je nachdem ob er im Setup Modus einen AccessPoint aufmacht oder im WLAN Modus auch das Dashboard und die Statistiken, etc. als URLs anbietet.

Evtl. kann man in Zukunft die beiden Oberflächen vereinheitlichen und den Reconnect mit dem WLAN alle X Minuten einstellen oder per Serial Command forcieren?

@lumapu
Copy link
Owner

lumapu commented May 4, 2022

Gestern habe ich schon mit Version 0.3.5 eine Implementierung veröffentlicht, die immer wieder versucht mit dem WLAN zu verbinden und in der Zwischenzeit für 3 Minuten den Access Point öffnet.
Heute habe ich mit Version 0.3.6 nochmals hier 'geschraubt' und es gibt jetzt zusätzlich noch einen Access Point only Modus - ist noch nicht ausgiebig getestet, aber ein paar schnelle Klicks haben bei mir funktioniert.

@rosch99
Copy link

rosch99 commented May 5, 2022

ahoy_esp8266
Anbei ein screenshot (Grafana) mit einem Vergleich HM1200 und einer ShellyPM am selben AC-Anschluss.
Angezeigt werden die letzten beidenTage, gestern mit der Firmware 0.3.5 und heute mit 0.3.6.
MIr ist aufgefallen, dass beim restart des WIFI manchmal die MQTT Verbindung nicht neu connected wird,
das scheint hier dann ebenfalls als "offline" auf.

@stefan123t
Copy link
Collaborator

Hallo Lukas, ich habe die 0.3.6 gestern morgen kompiliert und deployed. Er startet jetzt mit dem AP obwohl er offenbar auch eine WLAN Verbindung bekommt. Also er scanned die Netzwerke und findet auch den WLAN Access Point des Routers, vermutlich klappt es nicht beim ersten Versuch, denn er macht dann gleich den eigenen AP auf und startet den 3x60=180 Sekunden Countdown. Danach passiert meist das Selbe, d.h. es dauert mehrere 180 Sekunden Intervalle bevor es mal beim ersten Versuch gelingt eine Verbindung mit dem Router aufzubauen.

Ich hätte erwartet, daß er 30 Sekunden lang versucht eine Routerverbindung aufzubauen und erst dann für 180 Sekunden einen lokalen AP aufmacht und offenhält.

Interessant fand ich die join und leave Meldungen im AP Modus. Damit könnte man auch die Clients die sich am AP angemeldet haben zählen/bemerken und ggf. den Ticker steuern, der aktuell alle 3 Minuten (3x60s) den AP beendet. Wenn der AP also in den 180 Sekunden keinen join sieht, dann kann er den auch wieder zumachen. Andernfalls ist man ja mutmaßlich am Konfigurieren und er sollte den offenlassen. Wenn er im AP Modus ein leave sieht (oder ein zugehöriger Zähler verkleinert wurde) dann kann er ja nochmal 3 Minuten Zeit geben bevor er den AP wieder zu macht. Evtl. kann man auch Aufrufe des WebServers im AP Modus zum Triggern dieser 3 Minuten Grace Period verwenden ?

Ggf. alle 15 Minuten dann nochmal die Verbindung mit dem Router für 30 Sekunden versuchen, damit wir auch Daten hochladen können ...

@stefan123t
Copy link
Collaborator

Den MQTT Fehler sehe ich bei mir auch, das zwickt sich mit der Systemstabilität da es mit dem delay auf MQTT Seite besser funktioniert hat. Interessant ist hier dieser Issue von der MQTT Lib: knolleary/pubsubclient#182

Hi Lukas,
I have checked the linked MQTT / PubSubClient issue for having subscribed two topics at the same time.
This is what thijsdebont added lately:

First, the delay(1000); in loop() is bad practice. It blocks everything for a long time.
Second, the char pointers 'payload' and 'topic' are used as both a global variable for publishing ánd in the mqtt callback.
The globals should be given another name, since it is likely it gets partially overwritten.
Then the length of the global topic and topic2 variables. 150 is way too much.
Set it something that actually matches the max topic length.

I do not know if it really is matching our WDT resets as in both my StackTrace (click it to open) above and the one supplied for 0.2.9 by @dad401 there is this umm_init on the top of the stack which is for memory handling.
Probably we should revisit our use of String class in the ESP8166WebServerTemplates.
Maybe there is a smarter way to do things there, which does not involve creating copies of the Templates in memory before sending out ?
This would affect the umm Memory Management less and therefor could prevent WDT resets too.
Also note that I do not have MQTT active and therefor you do not see the PubSubClient on my stack.

But given we removed the delay(500); from our loop the bad practice (that thijsdebont mentioned too) should be gone.
The now longer stable runtimes of several hours / days speak volumes!

@lumapu
Copy link
Owner

lumapu commented May 6, 2022

Hallo stefan123t,

das mit dem join und leave klingt sehr gut, werde ich mir anschauen. Macht durchaus Sinn, den AP aktiv zu lassen wenn ein Client angemeldet ist. Aufrufe - aber dann nur auf der Setup-Seite, denn dafür war der AP Modus ja mal gedacht.

Was ich auch noch gerne hätte, wäre eine Liste der in der Nähe verfügbaren WLANs.

@lumapu
Copy link
Owner

lumapu commented May 6, 2022

My uptime was nearly 46h but then I got an interrupt. I don't know the issue because of lacking uart logging. The good point is the the ESP automatically reconnected and has a new uptime of more than 9h. (Version 0.3.6)
I will think about your notice to check how the memory is orgnized / used and where pointers are used. Let us improve all the points we get and the uptime will increase from days to weeks - someday I have to build a second device for not interrupting my long term test.

@stefan123t
Copy link
Collaborator

stefan123t commented May 7, 2022

Wegen der Liste der WLANs in der Umgebung (auch praktisch zur Vorbelegung der Auswahl auf der Setup Seite !) kannst Du Dir gerne mal die wifi.h aus dem tools/NRF24_SendRcv ansehen.
Da war das bereits drin um m.W. die Top5 erreichbaren WiFi APs anzuzeigen.

Könnten wir die UART Ausgabe auch irgendwie per remote logging (WLAN) ausgeben/schicken ?
Manchmal wäre es auch schön bei der Taube auf dem Dach mitzulesen und nicht nur den Spatz in der Hand zu debuggen =^D

Vielleicht kann man das ja per WebSerial oder WebSocket verwirklichen.
Schau Dir doch bitte mal https://randomnerdtutorials.com/esp8266-nodemcu-webserial-library/ an, wie schwierig es wäre das auszutauschen ?
Die Bibliothek verwendet auch ESPAsyncWebServer und ESPAsyncTCP, vielleicht bekommen wir ja damit sogar das WDT / Reset Problem in den Griff ?

@rosch99
Copy link

rosch99 commented May 12, 2022

Die Stabilität hat sich mit der 0.3.8 bei mir verbessert, trotzdem muss ich den ESP mehrmals am Tag stromlos machen und neu starten, da er irgendwo "hängenbleibt".

@lumapu
Copy link
Owner

lumapu commented May 12, 2022

Bei mir - versorgt von einem USB Netzteil - bootet er einfach neu und ist erreichbar wie zuvor. An den 3.3V habe ich einen Elko und habe das RF24 Modul auf HIGH stehen.

@stefan123t
Copy link
Collaborator

stefan123t commented May 17, 2022

Habe gerade die 0.4.3 bei mir installiert und bekomme folgendes Logfile.

Dabei fällt auf:

  1. das Programm macht 5 WiFi scan bzw. Connect Versuche mit dem Router
  2. dann werden die Serien Nummern meiner (immer noch drei, aber uninteressant für dieses Issue) Wechselrichter Konfigurationen aktiviert
  3. das hmRadio Modul wird initialisiert
  4. der Access Point wird gestartet, obwohl die 30 Sekunden noch nicht vorbei sind (siehe unten lineare vs. WiFi Modul-Zeit)
  5. das Programm versucht weitere 5 WiFi scans bzw. Connect Versuche mit dem Router
  6. Access Point steht, der 180 Sekunden Ticker wird gestartet, es finden vorerst keine weiteren WiFi scans bzw. Connect Versuche mit dem Router statt.
  7. Erst nach 180 Sekunden werden die WiFi scans fortgesetzt
  8. wieder nach 5 WiFi scans wird der AP gestartet
  9. Nach weiteren 180 Sekunden wird der AP geschlossen
  10. Diesmal klappt die WiFi Verbindung beim ersten scan.
  11. Nach 10 Minuten klappt die ap_probe_send nicht und die WiFi Verbindung wird wieder geschlossen
  12. das Programm verbleibt nun 30 Sekunden im WiFi scan modus und schafft dabei 13 Verbindungsversuche
  13. wdt reset das Programm startet neu
  14. WiFi Verbindung klappt auf Anhieb
  15. hmRadio Modul wird initialisiert
  16. dennoch wird der AP aufgemacht
  17. nach 180 Sekunden wieder geschlossen
  18. das Programm versucht es 25 Sekunden lang schafft aber nur 2 (!) Versuche ?
  19. AP wird wieder aufgemacht und nach 180 Sekunden geschlossen
  20. interessant ist hier die Zeit mit den AP will be closed in XXX seconds vergeht linear. Davor aber wenn der AP aufgemacht wird bleibt die Zeit irgendwie fast 20 Sekunden (von Active for: 180 seconds bis zum ersten AP will be closed in XXX seconds) stehen ?
  21. Danach wieder WiFi scan mit Verbindung beim ersten Versuch
  22. regelmäßige und erfolgreiche Verbindung ap_probe_send_start
Serial Monitor Log - Click to expand!
22:29:30.733 -> SDK:2.2.2-dev(38a443e)/Core:3.0.2=30002000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-48-g7421258/BearSSL:6105635
22:29:30.733 -> fpm close 1 
22:29:30.733 -> mode : sta(2c:3a:e8:12:34:56)
22:29:30.733 -> add if0
22:29:32.748 -> connect to network 'YOUR_WIFI_SSID' ...
22:29:32.847 -> ........scandone
22:29:33.579 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:33.646 -> .reconnect
22:29:33.746 -> ......................
22:29:35.939 -> ......scandone
22:29:36.505 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:36.539 -> .reconnect
22:29:36.638 -> .............................scandone
22:29:39.464 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:39.531 -> .reconnect
22:29:39.630 -> ............................scandone
22:29:42.389 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:42.455 -> .reconnect
22:29:42.555 -> ............................scandone
22:29:45.346 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:45.346 -> .reconnect
22:29:45.446 -> ....scandone
22:29:45.845 -> .
22:29:46.841 -> SERIAL: 11 41
22:29:46.841 -> add inverter: HM-600, SN: 114173123456
22:29:46.841 -> SERIAL: 11 41
22:29:46.841 -> add inverter: HM-700, SN: 114173123456
22:29:46.841 -> SERIAL: 11 41
22:29:46.841 -> add inverter: HM-800, SN: 114173123456
22:29:46.874 -> RF24 Amp Pwr: RF24_PA_LOW
22:29:46.874 -> Radio Config:
22:29:46.874 -> SPI Frequency		= 1 Mhz
22:29:46.874 -> Channel			= 3 (~ 2403 MHz)
22:29:46.874 -> RF Data Rate		= 250 KBPS
22:29:46.874 -> RF Power Amplifier	= PA_LOW
22:29:46.874 -> RF Low Noise Amplifier	= Enabled
22:29:46.874 -> CRC Length		= Disabled
22:29:46.874 -> Address Length		= 5 bytes
22:29:46.874 -> Static Payload Length	= 32 bytes
22:29:46.874 -> Auto Retry Delay	= 250 microseconds
22:29:46.874 -> Auto Retry Attempts	= 0 maximum
22:29:46.874 -> Packets lost on
22:29:46.908 ->     current channel	= 0
22:29:46.908 -> Retry attempts made for
22:29:46.908 ->     last transmission	= 15
22:29:46.908 -> Multicast		= Disabled
22:29:46.908 -> Custom ACK Payload	= Disabled
22:29:46.908 -> Dynamic Payloads	= Disabled
22:29:46.908 -> Auto Acknowledgment	= Disabled
22:29:46.908 -> Primary Mode		= RX
22:29:46.908 -> TX address		= 0xdeadbeef01
22:29:46.908 -> pipe 0 (closed) bound	= 0xdeadbeef01
22:29:46.908 -> pipe 1 ( open ) bound	= 0x1234567801
22:29:46.908 -> pipe 2 (closed) bound	= 0xc3
22:29:46.908 -> pipe 3 (closed) bound	= 0xc4
22:29:46.908 -> pipe 4 (closed) bound	= 0xc5
22:29:47.063 -> pipe 5 (closed) bound	= 0xc6
22:29:47.063 -> 
22:29:47.063 -> 
22:29:47.063 -> ----------------------------------------
22:29:47.063 -> Welcome to AHOY!
22:29:47.063 -> 
22:29:47.063 -> point your browser to http://(IP unset)
22:29:47.063 -> to configure your device
22:29:47.063 -> ----------------------------------------
22:29:47.063 -> 
22:29:48.932 -> connect to network 'YOUR_WIFI_SSID' ...
22:29:49.032 -> ........scandone
22:29:49.763 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:49.829 -> .reconnect
22:29:49.928 -> ......................
22:29:52.154 -> ......scandone
22:29:52.719 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:52.760 -> .reconnect
22:29:52.864 -> .............................scandone
22:29:55.643 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:55.726 -> .reconnect
22:29:55.842 -> ............................scandone
22:29:58.599 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:29:58.641 -> .reconnect
22:29:58.731 -> ............................scandone
22:30:01.555 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:30:01.555 -> .reconnect
22:30:01.655 -> ....scandone
22:30:02.053 -> .
22:30:03.048 -> 
22:30:03.048 -> ---------
22:30:03.048 -> AP MODE
22:30:03.048 -> SSDI: AHOY-DTU
22:30:03.048 -> PWD: esp_8266
22:30:03.048 -> Active for: 180 seconds
22:30:03.048 -> ---------
22:30:03.048 -> 
22:30:03.048 -> DBG: 196275
22:30:03.048 -> del if0
22:30:03.048 -> usl
22:30:03.048 -> mode : softAP(2e:3a:e8:12:34:56)
22:30:03.048 -> add if1
22:30:03.048 -> dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
22:30:03.087 -> bcn 100
22:30:03.944 -> bcn 0
22:30:03.944 -> del if1
22:30:03.944 -> usl
22:30:03.944 -> add if1
22:30:03.944 -> dhcp server start:(ip:192.168.1.1,mask:255.255.255.0,gw:192.168.1.1)
22:30:03.944 -> bcn 100
22:30:04.077 -> AP will be closed in 162 seconds
22:30:14.076 -> AP will be closed in 152 seconds
22:30:24.074 -> AP will be closed in 142 seconds
22:30:34.173 -> AP will be closed in 132 seconds
22:30:44.171 -> AP will be closed in 122 seconds
22:30:54.166 -> AP will be closed in 112 seconds
22:31:04.292 -> AP will be closed in 102 seconds
22:31:14.289 -> AP will be closed in 92 seconds
22:31:24.288 -> AP will be closed in 82 seconds
22:31:34.389 -> AP will be closed in 72 seconds
22:31:44.420 -> AP will be closed in 62 seconds
22:31:54.419 -> AP will be closed in 52 seconds
22:32:04.514 -> AP will be closed in 42 seconds
22:32:14.508 -> AP will be closed in 32 seconds
22:32:24.532 -> AP will be closed in 22 seconds
22:32:34.618 -> AP will be closed in 12 seconds
22:32:44.636 -> AP will be closed in 2 seconds
22:32:46.924 -> bcn 0
22:32:46.924 -> del if1
22:32:46.924 -> usl
22:32:46.924 -> mode : sta(2c:3a:e8:12:34:56)
22:32:46.924 -> add if0
22:32:48.949 -> connect to network 'YOUR_WIFI_SSID' ...
22:32:49.048 -> ........scandone
22:32:49.778 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:32:49.845 -> .reconnect
22:32:49.944 -> ......................
22:32:52.135 -> ......scandone
22:32:52.732 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:32:52.732 -> .reconnect
22:32:52.832 -> .............................scandone
22:32:55.654 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:32:55.753 -> .reconnect
22:32:55.853 -> ............................scandone
22:32:58.606 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:32:58.640 -> .reconnect
22:32:58.739 -> ............................scandone
22:33:01.527 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:33:01.560 -> .reconnect
22:33:01.660 -> ....scandone
22:33:02.058 -> .
22:33:03.053 -> 
22:33:03.053 -> ---------
22:33:03.053 -> AP MODE
22:33:03.053 -> SSDI: AHOY-DTU
22:33:03.053 -> PWD: esp_8266
22:33:03.053 -> Active for: 180 seconds
22:33:03.053 -> ---------
22:33:03.053 -> 
22:33:03.053 -> DBG: 376275
22:33:03.053 -> del if0
22:33:03.053 -> usl
22:33:03.053 -> mode : softAP(2e:3a:e8:12:34:56)
22:33:03.053 -> add if1
22:33:03.053 -> dhcp server start:(ip:192.168.1.1,mask:255.255.255.0,gw:192.168.1.1)
22:33:03.053 -> bcn 100
22:33:03.086 -> AP will be closed in 163 seconds
22:33:13.078 -> AP will be closed in 153 seconds
22:33:23.068 -> AP will be closed in 143 seconds
22:33:33.056 -> AP will be closed in 133 seconds
22:33:43.079 -> AP will be closed in 123 seconds
22:33:53.068 -> AP will be closed in 113 seconds
22:34:03.058 -> AP will be closed in 103 seconds
22:34:13.078 -> AP will be closed in 93 seconds
22:34:23.067 -> AP will be closed in 83 seconds
22:34:33.087 -> AP will be closed in 73 seconds
22:34:43.076 -> AP will be closed in 63 seconds
22:34:53.065 -> AP will be closed in 53 seconds
22:35:03.155 -> AP will be closed in 43 seconds
22:35:13.143 -> AP will be closed in 33 seconds
22:35:23.166 -> AP will be closed in 23 seconds
22:35:33.255 -> AP will be closed in 13 seconds
22:35:43.276 -> AP will be closed in 3 seconds
22:35:46.927 -> bcn 0
22:35:46.927 -> del if1
22:35:46.927 -> usl
22:35:46.927 -> mode : sta(2c:3a:e8:12:34:56)
22:35:46.927 -> add if0
22:35:48.951 -> connect to network 'YOUR_WIFI_SSID' ...
22:35:49.051 -> ........scandone
22:35:50.677 -> state: 0 -> 2 (b0)
22:35:50.677 -> .state: 2 -> 3 (0)
22:35:50.711 -> state: 3 -> 5 (10)
22:35:50.711 -> add 0
22:35:50.711 -> aid 1
22:35:50.711 -> cnt 
22:35:50.744 -> 
22:35:50.744 -> connected with YOUR_WIFI_SSID, channel 1
22:35:50.744 -> dhcp client start...
22:35:50.777 -> ....................ip:192.168.178.11,mask:255.255.255.0,gw:192.168.178.1
22:35:52.768 -> ..
22:36:00.702 -> pm open,type:2 0
22:36:17.428 -> bcn_timout,ap_probe_send_start
22:38:02.978 -> bcn_timout,ap_probe_send_start
22:38:19.669 -> bcn_timout,ap_probe_send_start
22:38:40.386 -> bcn_timout,ap_probe_send_start
22:41:24.535 -> bcn_timout,ap_probe_send_start
22:41:53.643 -> bcn_timout,ap_probe_send_start
22:42:28.257 -> bcn_timout,ap_probe_send_start
22:42:38.182 -> bcn_timout,ap_probe_send_start
22:43:51.357 -> bcn_timout,ap_probe_send_start
22:44:05.095 -> bcn_timout,ap_probe_send_start
22:44:24.871 -> bcn_timout,ap_probe_send_start
22:44:38.911 -> bcn_timout,ap_probe_send_start
22:44:53.247 -> bcn_timout,ap_probe_send_start
22:45:08.814 -> bcn_timout,ap_probe_send_start
22:45:55.272 -> bcn_timout,ap_probe_send_start
22:46:09.008 -> bcn_timout,ap_probe_send_start
22:46:24.076 -> bcn_timout,ap_probe_send_start
22:46:55.002 -> bcn_timout,ap_probe_send_start
22:47:13.814 -> bcn_timout,ap_probe_send_start
22:47:24.500 -> bcn_timout,ap_probe_send_start
22:47:26.991 -> ap_probe_send over, rest wifi status to disassoc
22:47:26.991 -> state: 5 -> 0 (1)
22:47:26.991 -> rm 0
22:47:26.991 -> pm close 7
22:47:29.945 -> scandone
22:47:29.945 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:30.045 -> reconnect
22:47:32.996 -> scandone
22:47:32.996 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:33.096 -> reconnect
22:47:36.015 -> scandone
22:47:36.015 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:36.115 -> reconnect
22:47:38.967 -> scandone
22:47:38.967 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:39.067 -> reconnect
22:47:42.120 -> scandone
22:47:42.120 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:42.219 -> reconnect
22:47:45.107 -> scandone
22:47:45.107 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:45.207 -> reconnect
22:47:48.127 -> scandone
22:47:48.127 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:48.226 -> reconnect
22:47:51.114 -> scandone
22:47:51.114 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:51.213 -> reconnect
22:47:54.166 -> scandone
22:47:54.166 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:54.265 -> reconnect
22:47:57.085 -> scandone
22:47:57.085 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:47:57.185 -> reconnect
22:48:00.171 -> scandone
22:48:00.171 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:48:00.270 -> reconnect
22:48:03.124 -> scandone
22:48:03.124 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:48:03.223 -> reconnect
22:48:06.142 -> scandone
22:48:06.142 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:48:06.242 -> reconnect
22:48:09.095 -> scandone
22:48:09.095 -> state: 0 -> 2 (b0)
22:48:10.090 -> state: 2 -> 0 (2)
22:48:10.090 -> reconnect
22:48:18.916 -> 
22:48:18.916 ->  ets Jan  8 2013,rst cause:4, boot mode:(3,6)
22:48:18.916 -> 
22:48:18.916 -> wdt reset
22:48:18.916 -> load 0x4010f000, len 3460, room 16 
22:48:18.949 -> tail 4
22:48:18.949 -> chksum 0xcc
22:48:18.949 -> load 0x3fff20b8, len 40, room 4 
22:48:18.949 -> tail 4
22:48:18.949 -> chksum 0xc9
22:48:18.949 -> csum 0xc9
22:48:18.949 -> v00059810
22:48:18.949 -> ~ld
22:48:19.016 -> 
22:48:19.016 -> SDK:2.2.2-dev(38a443e)/Core:3.0.2=30002000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-48-g7421258/BearSSL:6105635
22:48:19.016 -> fpm close 1 
22:48:19.016 -> mode : sta(2c:3a:e8:12:34:56)
22:48:19.016 -> add if0
22:48:21.007 -> connect to network 'YOUR_WIFI_SSID' ...
22:48:21.106 -> ........scandone
22:48:22.733 -> state: 0 -> 2 (b0)
22:48:22.733 -> .state: 2 -> 3 (0)
22:48:22.766 -> state: 3 -> 5 (10)
22:48:22.766 -> add 0
22:48:22.766 -> aid 1
22:48:22.766 -> cnt 
22:48:22.799 -> 
22:48:22.799 -> connected with YOUR_WIFI_SSID, channel 1
22:48:22.799 -> dhcp client start...
22:48:22.832 -> ......................
22:48:25.055 -> ..............................................................................pm open,type:2 0
22:48:32.850 -> .....................state: 5 -> 0 (0)
22:48:34.874 -> rm 0
22:48:34.874 -> pm close 7
22:48:34.941 -> .
22:48:35.935 -> SERIAL: 11 41
22:48:35.935 -> add inverter: HM-600, SN: 114173123456
22:48:35.969 -> SERIAL: 11 41
22:48:35.969 -> add inverter: HM-700, SN: 114173123456
22:48:35.969 -> SERIAL: 11 41
22:48:35.969 -> add inverter: HM-800, SN: 114173123456
22:48:35.969 -> RF24 Amp Pwr: RF24_PA_LOW
22:48:35.969 -> Radio Config:
22:48:35.969 -> SPI Frequency		= 1 Mhz
22:48:35.969 -> Channel			= 3 (~ 2403 MHz)
22:48:35.969 -> RF Data Rate		= 250 KBPS
22:48:35.969 -> RF Power Amplifier	= PA_LOW
22:48:35.969 -> RF Low Noise Amplifier	= Enabled
22:48:35.969 -> CRC Length		= Disabled
22:48:35.969 -> Address Length		= 5 bytes
22:48:36.002 -> Static Payload Length	= 32 bytes
22:48:36.002 -> Auto Retry Delay	= 250 microseconds
22:48:36.002 -> Auto Retry Attempts	= 0 maximum
22:48:36.002 -> Packets lost on
22:48:36.002 ->     current channel	= 0
22:48:36.002 -> Retry attempts made for
22:48:36.002 ->     last transmission	= 15
22:48:36.002 -> Multicast		= Disabled
22:48:36.002 -> Custom ACK Payload	= Disabled
22:48:36.002 -> Dynamic Payloads	= Disabled
22:48:36.002 -> Auto Acknowledgment	= Disabled
22:48:36.002 -> Primary Mode		= RX
22:48:36.002 -> TX address		= 0xdeadbeef01
22:48:36.002 -> pipe 0 (closed) bound	= 0xdeadbeef01
22:48:36.035 -> pipe 1 ( open ) bound	= 0x1234567801
22:48:36.035 -> pipe 2 (closed) bound	= 0xc3
22:48:36.035 -> pipe 3 (closed) bound	= 0xc4
22:48:36.035 -> pipe 4 (closed) bound	= 0xc5
22:48:36.035 -> pipe 5 (closed) bound	= 0xc6
22:48:36.035 -> 
22:48:36.035 -> 
22:48:36.035 -> ----------------------------------------
22:48:36.035 -> Welcome to AHOY!
22:48:36.035 -> 
22:48:36.035 -> point your browser to http://(IP unset)
22:48:36.035 -> to configure your device
22:48:36.035 -> ----------------------------------------
22:48:36.035 -> 
22:48:38.058 -> connect to network 'YOUR_WIFI_SSID' ...
22:48:38.158 -> ........scandone
22:48:39.783 -> state: 0 -> 2 (b0)
22:48:39.783 -> .state: 2 -> 3 (0)
22:48:39.783 -> state: 3 -> 5 (10)
22:48:39.783 -> add 0
22:48:39.783 -> aid 1
22:48:39.783 -> cnt 
22:48:39.816 -> 
22:48:39.816 -> connected with YOUR_WIFI_SSID, channel 1
22:48:39.816 -> dhcp client start...
22:48:39.883 -> ......................
22:48:42.073 -> ..............................................................................pm open,type:2 0
22:48:49.869 -> .....................state: 5 -> 0 (0)
22:48:51.861 -> rm 0
22:48:51.861 -> pm close 7
22:48:51.960 -> .
22:48:52.989 -> 
22:48:52.989 -> ---------
22:48:52.989 -> AP MODE
22:48:52.989 -> SSDI: AHOY-DTU
22:48:52.989 -> PWD: esp_8266
22:48:52.989 -> Active for: 180 seconds
22:48:52.989 -> ---------
22:48:52.989 -> 
22:48:52.989 -> DBG: 197101
22:48:52.989 -> del if0
22:48:52.989 -> usl
22:48:52.989 -> mode : softAP(2e:3a:e8:12:34:56)
22:48:52.989 -> add if1
22:48:52.989 -> dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
22:48:52.989 -> bcn 100
22:48:53.885 -> bcn 0
22:48:53.885 -> del if1
22:48:53.885 -> usl
22:48:53.885 -> add if1
22:48:53.885 -> dhcp server start:(ip:192.168.1.1,mask:255.255.255.0,gw:192.168.1.1)
22:48:53.885 -> bcn 100
22:48:53.985 -> AP will be closed in 162 seconds
22:49:04.009 -> AP will be closed in 152 seconds
22:49:13.999 -> AP will be closed in 142 seconds
22:49:24.121 -> AP will be closed in 131 seconds
22:49:34.110 -> AP will be closed in 121 seconds
22:49:44.096 -> AP will be closed in 111 seconds
22:49:54.213 -> AP will be closed in 101 seconds
22:50:04.233 -> AP will be closed in 91 seconds
22:50:14.225 -> AP will be closed in 81 seconds
22:50:24.348 -> AP will be closed in 71 seconds
22:50:34.336 -> AP will be closed in 61 seconds
22:50:44.325 -> AP will be closed in 51 seconds
22:50:54.446 -> AP will be closed in 41 seconds
22:51:04.466 -> AP will be closed in 31 seconds
22:51:14.450 -> AP will be closed in 21 seconds
22:51:24.570 -> AP will be closed in 11 seconds
22:51:34.559 -> AP will be closed in 1 seconds
22:51:36.052 -> bcn 0
22:51:36.052 -> del if1
22:51:36.052 -> usl
22:51:36.052 -> mode : sta(2c:3a:e8:12:34:56)
22:51:36.052 -> add if0
22:51:38.043 -> connect to network 'YOUR_WIFI_SSID' ...
22:51:38.143 -> ........scandone
22:51:38.872 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:51:38.939 -> .reconnect
22:51:39.038 -> ......................
22:51:41.261 -> ......scandone
22:51:42.721 -> state: 0 -> 2 (b0)
22:51:42.721 -> ..........state: 2 -> 0 (2)
22:51:43.717 -> reconnect
22:51:43.717 -> .............................scandone
22:51:46.537 -> no YOUR_WIFI_SSID found, reconnect after 1s
22:51:46.604 -> .reconnect
22:51:46.703 -> ............................scandone
22:51:49.490 -> state: 0 -> 2 (b0)
22:51:49.523 -> ..........state: 2 -> 0 (2)
22:51:50.486 -> reconnect
22:51:50.519 -> ...............scandone
22:51:52.013 -> .
22:51:53.009 -> 
22:51:53.009 -> ---------
22:51:53.009 -> AP MODE
22:51:53.009 -> SSDI: AHOY-DTU
22:51:53.009 -> PWD: esp_8266
22:51:53.009 -> Active for: 180 seconds
22:51:53.042 -> ---------
22:51:53.042 -> 
22:51:53.042 -> DBG: 377101
22:51:53.042 -> del if0
22:51:53.042 -> usl
22:51:53.042 -> mode : softAP(2e:3a:e8:12:34:56)
22:51:53.042 -> add if1
22:51:53.042 -> dhcp server start:(ip:192.168.1.1,mask:255.255.255.0,gw:192.168.1.1)
22:51:53.042 -> bcn 100
22:51:53.042 -> AP will be closed in 163 seconds
22:52:03.025 -> AP will be closed in 153 seconds
22:52:13.044 -> AP will be closed in 143 seconds
22:52:23.034 -> AP will be closed in 133 seconds
22:52:33.053 -> AP will be closed in 123 seconds
22:52:43.039 -> AP will be closed in 113 seconds
22:52:53.026 -> AP will be closed in 103 seconds
22:53:03.047 -> AP will be closed in 93 seconds
22:53:13.033 -> AP will be closed in 82 seconds
22:53:23.053 -> AP will be closed in 72 seconds
22:53:33.039 -> AP will be closed in 62 seconds
22:53:43.062 -> AP will be closed in 52 seconds
22:53:53.052 -> AP will be closed in 42 seconds
22:54:03.041 -> AP will be closed in 32 seconds
22:54:13.064 -> AP will be closed in 22 seconds
22:54:23.055 -> AP will be closed in 12 seconds
22:54:33.044 -> AP will be closed in 2 seconds
22:54:36.032 -> bcn 0
22:54:36.032 -> del if1
22:54:36.032 -> usl
22:54:36.032 -> mode : sta(2c:3a:e8:12:34:56)
22:54:36.032 -> add if0
22:54:38.056 -> connect to network 'YOUR_WIFI_SSID' ...
22:54:38.156 -> ........scandone
22:54:39.782 -> state: 0 -> 2 (b0)
22:54:39.782 -> .state: 2 -> 3 (0)
22:54:39.782 -> state: 3 -> 5 (10)
22:54:39.782 -> add 0
22:54:39.782 -> aid 1
22:54:39.782 -> cnt 
22:54:39.815 -> 
22:54:39.815 -> connected with YOUR_WIFI_SSID, channel 1
22:54:39.848 -> dhcp client start...
22:54:39.881 -> ....................ip:192.168.178.11,mask:255.255.255.0,gw:192.168.178.1
22:54:41.873 -> ..
22:54:49.807 -> pm open,type:2 0
22:57:36.390 -> bcn_timout,ap_probe_send_start
22:57:58.527 -> bcn_timout,ap_probe_send_start
22:58:16.847 -> bcn_timout,ap_probe_send_start
22:58:31.218 -> bcn_timout,ap_probe_send_start
23:01:46.959 -> bcn_timout,ap_probe_send_start
23:02:03.184 -> bcn_timout,ap_probe_send_start
23:03:19.971 -> bcn_timout,ap_probe_send_start
23:03:32.287 -> bcn_timout,ap_probe_send_start
23:03:59.397 -> bcn_timout,ap_probe_send_start
23:04:15.063 -> bcn_timout,ap_probe_send_start
23:04:36.799 -> bcn_timout,ap_probe_send_start
23:04:47.317 -> bcn_timout,ap_probe_send_start
23:05:02.882 -> bcn_timout,ap_probe_send_start
23:05:17.754 -> bcn_timout,ap_probe_send_start
23:05:36.870 -> bcn_timout,ap_probe_send_start
23:05:48.154 -> bcn_timout,ap_probe_send_start
23:06:46.803 -> bcn_timout,ap_probe_send_start
23:07:03.227 -> bcn_timout,ap_probe_send_start
23:07:18.359 -> bcn_timout,ap_probe_send_start
23:07:33.720 -> bcn_timout,ap_probe_send_start
23:07:51.543 -> bcn_timout,ap_probe_send_start
23:08:07.744 -> bcn_timout,ap_probe_send_start
23:08:35.293 -> bcn_timout,ap_probe_send_start
23:08:48.801 -> bcn_timout,ap_probe_send_start
23:09:04.765 -> bcn_timout,ap_probe_send_start
23:09:22.057 -> bcn_timout,ap_probe_send_start
23:09:39.250 -> bcn_timout,ap_probe_send_start
23:10:31.779 -> bcn_timout,ap_probe_send_start

@stefan123t
Copy link
Collaborator

@lumapu sollen wir analog zu AP will be closed in XXX seconds auch eine Meldung für STA will be scanned for XXX seconds einführen, dann kann man die beiden Ticker dafür parallel beobachten und ggf. Überschneidungen einfacher feststellen ?
Eventuell wäre das auch für die anderen Ticker (MQTT, etc.) sinnvoll und beim Debuggen hilfreich.

@stefan123t
Copy link
Collaborator

Hallo Lukas,

während ich das Problem mit den WiFi connections näher analysiert und oben beschrieben habe, hat sich der nächste wdt reset ereignet.

23:26:42.840 -> bcn_timout,ap_probe_send_start
23:26:42.840 -> mac 985
23:26:50.042 -> 
23:26:50.042 ->  ets Jan  8 2013,rst cause:4, boot mode:(3,6)
23:26:50.042 -> 
23:26:50.042 -> wdt reset
23:26:50.042 -> load 0x4010f000, len 3460, room 16 
23:26:50.075 -> tail 4
23:26:50.075 -> chksum 0xcc
23:26:50.075 -> load 0x3fff20b8, len 40, room 4 
23:26:50.075 -> tail 4
23:26:50.075 -> chksum 0xc9
23:26:50.075 -> csum 0xc9
23:26:50.075 -> v00059810
23:26:50.075 -> ~ld
23:26:50.141 -> 
23:26:50.141 -> SDK:2.2.2-dev(38a443e)/Core:3.0.2=30002000/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-48-g7421258/BearSSL:6105635
23:26:50.141 -> fpm close 1 
23:26:50.141 -> mode : sta(2c:3a:e8:12:34:56)
23:26:50.141 -> add if0

Kannst Du mal meine SDK Angaben vergleichen ?

SDK:2.2.2-dev(38a443e)
Core:3.0.2=30002000
lwIP:STABLE-2_1_2_RELEASE
glue:1.2-48-g7421258
BearSSL:6105635

@stefan123t
Copy link
Collaborator

stefan123t commented May 17, 2022

The boot messages and modes are explained in the board overview:
https://arduino-esp8266.readthedocs.io/en/latest/boards.html#boot-messages-and-modes
Decoding stack trace is possible with
https://github.com/esp8266/Arduino/blob/master/doc/Troubleshooting/stack_dump.rst

Found this old issue / thread about wdt reset and wrong Pin number assignments should be using e.g. D4, etc. instead of 2 and using some capacitors on external pins
github.com/esp8266/Arduino/issues/1809

rst cause:4, boot mode:(3,6) often happens when you define the pins incorrectly. For example, I was using a Wemos D1 Mini and specified constants to define pins 6 and 7, whereas I should have put in D6 and D7. EDIT: oops, noted above this has already been mentioned.

Works after changing PROGMEM const int l=7,r=6,f=5,b=4,h=3; to PROGMEM const int l=D4,r=D3,f=D2,b=D1,h=D0;

Reason(in my case):
pins RST(reset), EN(enable) and VCC were facing fluctuations in power supplied irrespective of the constant power supply. This was causing a rst of no. 4, i.e. Hardware WDT reset.

Solution:
Add a 47uF capacitor at each of the pin mentioned wrt GND.

@stefan123t
Copy link
Collaborator

Join und Leave messages werden jetzt (positiv getestet in 0.4.13) berücksichtigt.

Dies führt dazu, daß man mit dem AP verbunden der Timer alle 10 Sekunden wieder auf den ursprünglichen Wert 3*60 bzw. 180 Sekunden zurückgesetzt wird. M.E. genügt hier ggf. auch ein Default von 60 Sekunden, wenn man sich vom AP abmeldet muß man sonst 3 Minuten warten, bis er sich wieder mit dem Router verbindet, aber das kann ich ja in der config.h setzen.

@stefan123t
Copy link
Collaborator

Ich habe aktuell die starke Vermutung dass der MQTT PubSubClient nicht im non-blocking Modus arbeitet.
Vor allem bei meiner schlechten WiFi Verbindung vom DG in den Keller zum Router setzt die immer wieder aus.
Ich habe gesehen, daß dann der MQTT Client länger erfolglos versucht einen Connect aufzubauen, da vermutlich die WiFi Verbindung weg ist. Zumindest gibt es m.W. keine Prüfung des WiFi Status vor dem MQTT Connect / Submit, dort könnte man ja eine Fehlermeldung auf der Serial Monitor Console ausgeben.

Den anderen Punkt mit den Interrupt Handler Routinen, wie in #53 mit dem Hinweis auf dev 1153 angesprochen, kann ich mir aber auch noch als Ursache vorstellen. Muß ich mal mit meiner reichhaltigen Sammlung an Stack Traces und Exceptions vergleichen...
Wie funktioniert denn die RF24 Bibliothek unter Python, dort wird ja m.W. aktuell noch keine IRQ Leitung an den Raspberry Pi angeschlossen. D.h. der kann gar keinen Interrupt auslösen und liefert dennoch valide Daten.

Ach ja einen Patch / PR #63 für die index.html Seite, damit diese auch das mSendInterval in showIndex berücksichtigt habe ich gepusht. Dieser enthält auch viele Debug Meldungen und Settings in der config.h.

Habe auch noch einige Debug Meldungen eingebaut um der Ursache für die Abbrüche irgendwie auf die Schliche zu kommen:
Offenbar ist er aktuell dabei den WR zu erreichen, was wegen der Uhrzeit (Nacht) natürlich unmöglich ist.
Nach einem erfolgreichen MQTT Connect hat er auch nochmal das setTime Paket (0x80 0x0B) an den WR gesendet, wartet aber nach wie vor tapfer auf das letzte Paket (0x83), obwohl der WR auch die anderen vorherigen Pakete (0x01 & 0x02) natürlich nicht geschickt hat.
Offenbar gibt es also im Payload Decoder noch keine Abbruchbedingung, daß er nach so-und-so-vielen Fehlversuchen eines Retransmits einfach die ganze Payload verwirft und sich wieder um andere Dinge kümmert ?

@stefan123t
Copy link
Collaborator

@lumapu danke für den e7d0e4a das sollte m.E. sowohl den o.g. Interrupt Handler stark vereinfacht und optimiert, als auch das Problem mit dem MQTT Connect gelöst haben.

@lumapu
Copy link
Owner

lumapu commented Jun 2, 2022 via email

@stefan123t
Copy link
Collaborator

HI @lumapu,
habe die 0.4.14 jetzt seit 20:00 Uhr am laufen. Hier mal die Punkte die mir aufgefallen sind:

  • er fängt an den WR anzusprechen mit unix epoch 0 bzw. 1970-0-0, obwohl die Uhr (NTP) noch nicht gesetzt ist.
  • irgendwie hat er Probleme die Fragmente / Pakete zu zählen. Er mängelt sowohl am Anfang als auch Nachts das fehlende letzte Paket an, aber nicht die Pakete 0x01, 0x02. etc.
20:09:15.982 -> DBG: 47094
20:09:16.844 -> Free heap: 0xa360
20:09:16.844 -> Inverter #0 no Payload received!
20:09:16.895 -> Requesting Inverter SN 114112345678
20:09:16.895 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 00 00 00 00 00 00 00 05 00 00 00 00 CA 6D 07 
20:09:16.895 -> AP will be closed in 12 seconds
20:09:19.898 -> Error while retrieving data: last frame missing: Request Retransmit
20:09:19.898 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 00 00 00 00 00 00 00 05 00 00 00 00 CA 6D 07 
20:09:24.448 -> Error while retrieving data: last frame missing: Request Retransmit
20:09:24.448 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 00 00 00 00 00 00 00 05 00 00 00 00 CA 6D 07 
20:09:26.904 -> AP will be closed in 2 seconds
20:09:28.962 -> Error while retrieving data: last frame missing: Request Retransmit
20:09:28.962 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 00 00 00 00 00 00 00 05 00 00 00 00 CA 6D 07 
  • er empfängt aktuell ein, zwei / drei und teilweise bis zu vier (!) 0x01, 0x02 oder 0x83 Pakete auf eine Anfrage mit 0x80 0x0b.
  • nach jeder vollständig empfangenen Payload schreibt er die Ergebnisse ordentlich per MQTT.
  • Retransmit funktioniert:
20:23:52.007 -> Free heap: 0xa5f0
20:23:52.007 -> Requesting Inverter SN 114112345678
20:23:52.007 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 62 99 1A CD 00 00 00 05 00 00 00 00 33 EE 51 
20:23:52.073 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 02 57 56 00 00 53 57 07 CA 07 48 08 F5 13 8A 00 92 E6 
20:23:52.073 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 02 57 56 00 00 53 57 07 CA 07 48 08 F5 13 8A 00 92 E6 
20:23:52.106 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 02 57 56 00 00 53 57 07 CA 07 48 08 F5 13 8A 00 92 E6 
20:23:52.106 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 02 57 56 00 00 53 57 07 CA 07 48 08 F5 13 8A 00 92 E6 
20:23:52.139 -> Received 23 bytes channel 75: 95 12 34 56 78 12 34 56 78 83 00 00 00 06 03 E8 00 EF 02 A6 CB D1 AA 
20:23:52.139 -> Received 23 bytes channel 75: 95 12 34 56 78 12 34 56 78 83 00 00 00 06 03 E8 00 EF 02 A6 CB D1 AA 
20:23:52.172 -> Received 23 bytes channel 75: 95 12 34 56 78 12 34 56 78 83 00 00 00 06 03 E8 00 EF 02 A6 CB D1 AA 
20:23:55.027 -> Error while retrieving data: Frame 1 missing: Request Retransmit
20:23:55.027 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 81 AF 
20:23:55.060 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 01 00 01 01 36 00 19 00 4D 01 36 00 19 00 4D 00 00 95 
20:23:55.094 -> Received 27 bytes channel 75: 95 12 34 56 78 12 34 56 78 01 00 01 01 36 00 19 00 4D 01 36 00 19 00 4D 00 00 95 
20:23:56.555 -> Payload (42): 00 01 01 36 00 19 00 4D 01 36 00 19 00 4D 00 00 57 56 00 00 53 57 07 CA 07 48 08 F5 13 8A 00 92 00 00 00 06 03 E8 00 EF 02 A6 
20:26:12.957 -> HM-600/ch1/U_DC: 31.000 V
20:26:12.957 -> HM-600/ch1/I_DC: 0.250 A
20:26:12.957 -> HM-600/ch1/P_DC: 7.700 W
20:26:12.957 -> HM-600/ch1/YieldDay: 1994.000 
20:26:12.957 -> HM-600/ch1/YieldTotal: 22.358 kW
20:26:12.957 -> HM-600/ch1/Irradiation: 2.053 %
20:26:12.957 -> HM-600/ch2/U_DC: 31.000 V
20:26:12.990 -> HM-600/ch2/I_DC: 0.250 A
20:26:12.990 -> HM-600/ch2/P_DC: 7.700 W
20:26:12.990 -> HM-600/ch2/YieldDay: 1864.000 
20:26:12.990 -> HM-600/ch2/YieldTotal: 21.335 kW
20:26:12.990 -> HM-600/ch2/Irradiation: 2.053 %
20:26:12.990 -> HM-600/ch0/U_AC: 229.300 V
20:26:12.990 -> HM-600/ch0/I_AC: 0.060 A
20:26:12.990 -> HM-600/ch0/P_AC: 14.600 W
20:26:12.990 -> HM-600/ch0/Freq: 50.020 Hz
20:26:12.990 -> HM-600/ch0/Temp: 23.900 °
20:26:12.990 -> HM-600/ch0/YieldDay: 3858.000 
20:26:12.990 -> HM-600/ch0/YieldTotal: 43.693 kW
20:26:12.990 -> HM-600/ch0/P_DC: 15.400 W
20:26:13.023 -> HM-600/ch0/Effiency: 94.805 %
  • er versucht es auch nach Sonnenuntergang tapfer weiter, dafür scheint hier jetzt der WebServer nicht mehr erreichbar.
  • wahrscheinlich ist er hauptsächlich mit dem Radio TX/RX Code beschäftigt und kommt da nicht mehr raus.
  • der Sonnenauf-/untergangs Code von Hubi (/tools/NRF24_SendRcv/Sonne.h) ist noch nicht portiert.
23:16:22.836 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
23:16:24.362 -> Error while retrieving data: last frame missing: Request Retransmit
23:16:24.362 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
23:16:25.889 -> Error while retrieving data: last frame missing: Request Retransmit
23:16:25.889 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
23:16:34.019 -> Free heap: 0xa770
23:16:34.019 -> Inverter #0 no Payload received!
23:16:34.019 -> Requesting Inverter SN 114112345678
23:16:34.019 -> Transmit 27 | 15 12 34 56 78 78 56 34 12 80 0B 00 62 99 37 A4 00 00 00 05 00 00 00 00 F1 BC 85 
23:16:37.040 -> Error while retrieving data: last frame missing: Request Retransmit
23:16:37.040 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
23:16:38.566 -> Error while retrieving data: last frame missing: Request Retransmit
23:16:38.566 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
...
23:17:39.995 -> Free heap: 0xa770
23:17:39.995 -> Inverter #0 no Payload received!
23:17:39.995 -> Requesting Inverter SN 114112345678

Ich versuche es morgen im Laufe des Tages nochmal mit einem längeren Test.

@stefan123t
Copy link
Collaborator

stefan123t commented Jun 3, 2022

Mein ESP8266 lief jetzt mit der 0.4.15 seit 14:38 Stunden ohne WDT Reset, das ist doch schon mal was!
Und der Reset (ohne Exception) gerade eben war wieder in der o.g. Transmit/Receive Endlos-Schleife nach Sonnenuntergang:

22:16:19.456 -> Error while retrieving data: last frame missing: Request Retransmit
22:16:19.456 -> Transmit 11 | 15 12 34 56 78 78 56 34 12 83 AD 
22:16:29.086 -> 
22:16:29.086 ->  ets Jan  8 2013,rst cause:4, boot mode:(3,6)
22:16:29.086 -> 
22:16:29.086 -> wdt reset
22:16:29.086 -> load 0x4010f000, len 3460, room 16 
22:16:29.167 -> tail 4
22:16:29.167 -> chksum 0xcc
22:16:29.167 -> load 0x3fff20b8, len 40, room 4 
22:16:29.167 -> tail 4
22:16:29.167 -> chksum 0xc9
22:16:29.167 -> csum 0xc9
22:16:29.167 -> v0005a5d0
22:16:29.167 -> ~ld
22:16:29.167 -> Main::Main
22:16:29.167 -> app::app():Main
22:16:29.167 -> hmRadio.h : HmRadio():mNrf24(CE_PIN: 2, CS_PIN: 15, SPI_SPEED: 1000000)
22:16:29.167 -> app::setup
22:16:29.167 -> Main::setup
22:16:29.167 -> Main::getConfig
22:16:29.312 -> main.h:checkEEpCrc
22:16:29.312 -> main.h:buildEEpCrc
22:16:29.312 -> main.h:checkEEpCrc
22:16:29.312 -> main.h:buildEEpCrc
22:16:29.312 -> Main::setupStation
22:16:31.202 -> connect to network 'YOUR_SSID' ...

Andererseits sehe ich wie gesagt einige der Antwort-Pakete bis zu 4 Mal (siehe oben)
Entweder der Code ist jetzt dank optimiertem Interrupt Handler so schnell, dass er mehrere Responses des WR auf dem selben Kanal empfängt, oder es existiert evtl. doch noch eine Race Condition im Interrupt Handler ?

Von den HackRF Aufnahmen meine ich keine Mehrfach Pakete vom Wechselrichter gesehen zu haben.
Das könnte ja evtl. einer der Spezialisten mit der entsprechenden Funkhardware nachprüfen.

@lumapu
Copy link
Owner

lumapu commented Jun 3, 2022

In #53 diskutieren wir im Prinzip das gleiche Thema, ich denke es liegt an dem setRetries der NRF24 Lib.

@stefan123t
Copy link
Collaborator

stefan123t commented Jun 5, 2022

Hallo Lukas,

ich dachte in #53 geht es um die fehlenden Pakete (mW bei HM-1000/1200/1500 fünf statt vier Pakete für den HM-600/700/800).

  1. WiFi Verbindung bzw. WebServer Routine stalled wenn die Payload Routine (zB Nachts) hängt

Hier in #15 und #52 geht es um was anderes nämlich dass die WiFi Verbindung teilweise nicht mehr verfügbar und der ESP nicht mehr erreichbar ist. Das liegt mE daran dass er aus der Schleife die die drei/vier/fünf Pakete für eine Payload zusammenbekommen soll nicht mehr rauskommt.
Aktuell ist die RC Routine vor allen anderen priorisiert. Es sollte also dafür gesorgt werden, dass nach einem Empfangszyklus (nach dem TX-Zyklus) auch die anderen „Threads“ abgearbeitet werden. Sonst kommt es zwar ncht mehr zum WDT Reset mehr, da der ESP ja nicht mehr im Interrupt Handler feststeckt, aber die anderen Funktionen wie WiFi, NTP, MQTT, etc können bei Nacht eben auch nicht mehr ausgeführt werden.
Der Reset gestern war vermutlich durch irgendwelche TCP Pakete die nicht abgerufen wurden hervorgerufen. Ich habe nämlich mehrfach erfolglos versucht per HTTP den ESP zu erreichen. Ping ging noch aber der WebServer war nicht zu einer Antwort fähig.
Heute Nacht lief er durch, war bloss nicht zu erreichen (WebServer) und seit heute mirgen 5:15 Uhr geht das wieder. Er empfängt nämlich wieder Daten vom Wechselrichter und kann somit nach der TX und RX Routine auch die Requests beantworten. Uptime ist jetzt bei 1 Tag und 3:40h ohne Reset / WDT ! Das ist bei mir neuer Rekord!

  1. setRetries fordert bis zu 16 mal (15 retries) die Antworten vom WR an. Die Antworten kommen dadurch auch mehrfach in der RX Routine an.

Das Problem mit den Paketen gehört dann evtl doch in das andere Issue #53 (?) aber jetzt habe ich die Logs hier schon oberhalb eingestellt.

Das erklärt zumindest warum ich manche Pakete mehrfach sehe:

mNrf24.setRetries(3, 15);
// 3*250us and 15 loops -> 11.25ms
void setRetries (uint8_t delay, uint8_t count)
  Set the number and delay of retries upon failed submit

void setRetries (uint8_t delay, uint8_t count)
Set the number and delay of retries upon failed submit

Es sind also immer 15 Versuche, von denen bei mir mindestens 1-4 Requests aktuell vom WR empfangen und auch beantwortet werden bzw. deren Antwort ich auch empfange.

Wenn man wie bei mir zuviele Antworten bekommt, kann man den retry_count evtl. ja wieder sukzessive -1 bis auf min. 1 erniedrigen.
Vielleicht sollte man den Wert für diesen retry_count aber auch sukzessive um +1 anheben, bis man wieder Antworten empfängt oder die max 15 retry_count erreicht sind.

@lumapu
Copy link
Owner

lumapu commented Jun 6, 2022

Ich denke wir sollten es so lassen wie es ist. Ich habe während der Entwicklung der gesamten Payload gesehen, dass es sehr stark schwankt. Manche frames kommen 1x und andere 4x. Komisch ist, dass man tatsächlich maximal 4 sieht, das sollten wir noch erklären können. Meine erste Vermutung ist, das das Intervall zwischen den Retries zu kurz ist und der WR gar nicht so schnell antworten kann.

@stefan123t
Copy link
Collaborator

Hallo Lukas (@lumapu)
ja, den 2. Punkt können wir mE aufschieben bzw. unbeachtet lassen.

Aber wie sieht es mit dem 1. Punkt aus ?
Wir sollten mE:

  • für die Pakete der Reihenfolge nach Retransmits anfordern, nicht mit dem letzten Paket beginnen.
  • wenn N Retransmit Anfragen (N = ca. 3-5 ?) fehlgeschlagen sind sollte die komplette Payload abgebrochen und verworfen werden und der nächste WR abgefragt werden, bzw. auch mal Zeit für die WebServer, MQTT und/oder NTP Tasks je nach Bedarf, Priorität und Notwendigkeit eingeplant werden.
  • Am Besten könnte man auch nach einem TX/RX Fenster, das ja naturgemäß sehr zeitkritisch ist und direkt auf den TX folgen muss, eine Zeitscheibe für die anderen og Tasks (WebServer, MQTT, NTP) einplanen. Dann erst erfolgt die Retransmit Anfrage und das horchen auf Antworten für diese RX Pakete.
    Bis entweder N Retransmits für eines der Pakete 1..M erfolglos waren oder die Payload komplett ist. Auch das Dekodieren der Payload kann wieder nach einer kleinen Lunstpause für WebServer, etc erfolgen da ja die Daten im Pufferspeicher des ESP (CircularBuffer) bereits abgelegt sind.

@stefan123t
Copy link
Collaborator

Ach ja, wie Jan-Jonas bereits angemerkt hat sind 3 Retransmits eines Paketes 3 TX Versuche mit je 15 Retries, also 3x16=48 Pakete on-air. Die Zeiten können wir evtl. berechnen bzw. auf den HackRF Screenshots im Forum ablesen. Dort sind auch 15 Retries zu erkennen, daher ist das vermutlich in Ordnung und wir können doppelte Antwortpakete einfach silently ignorieren.

@AsZork
Copy link

AsZork commented Jun 30, 2022

AHoy-ESP V0.4.19
Uptime: 3 Tage, 02:07:02
Time: 2022-06-30 10:41:10 (Akt. Ortszeit 13:45 also ca 1 Stunde pro Tag verloren)

Ich aktualisiere die Werte von meinen 2 Wechselrichtern nur alle 30 Sekunden.
(Durch diese Ändrung konnte ich diese lange Laufzeit erreichen) T

Alle anderen Eckdaten sind eigentlich nicht förderlich.
-CS=D8 CE=D3 IRQ=D4
-mqtt aktiv mit 60 Sekunden
-Wemos D1 V3 und nrf-Modul mit externer Antenne ohne Abschirmung.
-Entfernung WLAN 5 Meter durch 2 Außenmauern.
-Entfernung Wechselrichter 3 M, bzw 15 m durch eine Außenmauer.
-Netzteil altes Handy-Netzteil mit 250mA.
-Kein Kondensator verbaut.

@stefan123t
Copy link
Collaborator

+1 für einen täglichen NTP Refresh Job.

@lumapu
Copy link
Owner

lumapu commented Jul 10, 2022

habe immer noch mehrere Reboots am Tag, daher hat mich die fehlerhafte Zeit noch nie gestört.
Wie wollen wir das Triggern? Mit einem zusätzlichen Timeout, der alle 24h triggert?
+1 bin aber trotzdem für dieses Feature

@stefan123t
Copy link
Collaborator

@lumapu Ja timeout zum NTP time refreshen finde ich gut.
Mal sehen wieviele Stunden wir mit einem Timer hinbekommen.
Es wäre bestimmt auch nicht verkehrt das alle 6 Stunden zu aktualisieren, wenn sonst die millis mehrmals überlaufen, müssten wir den Überlauf sonst auch noch zählen.
Machst Du einen extra Feature Request auf ?

@lumapu
Copy link
Owner

lumapu commented Jul 11, 2022

nein, ich glaube dass ist eine kleine Sache, dann schließen wir diesen alten Issue - wir haben noch genug andere issues, die sich um die Stabilität kümmern

@stefan123t
Copy link
Collaborator

@lumapu, hier ist halt die meiste Dokumentation zum Thema WDT resets und vor allem auch zu den evtl. geplanten State Machine vorhanden, oder haben wir das anderweitig (z.B. #78) hinreichend beschrieben ?
@andreas5232 sind die WiFi Verbindungsabbrüche bei Dir jetzt behoben, wenn ja seit welcher Version ?

@stefan123t
Copy link
Collaborator

Lukas wie machen wir das in Zukunft wenn auch noch Device Control Commands (Active Power Limit) und weitere Device Info Commands (AlarmData und AlarmUpdate) dazukommen. Wir müssen uns etwas zum Schedulen überlegen. Sollten wir da so wie Thomas B arbeiten mit den EVERY_* Timer Makros ?
Auch blicke ich nicht ganz durch bei den Aufgaben von main.cpp, app.cpp und esp8266.cpp. Das sollten wir mal refaktorisieren.
Ist es u.a. nötig dass alle WebSeiten showXxx Handler über app.cpp und main.cpp verteilt sind. Es ist vielleicht sogar egal ob der WebServer nur einmal läuft aber sowohl über STA als auch AP mode WiFi Stack erreichbar ist.
Wenn man die Debug Meldungen in der platformio.ini aktiviert dann sieht man dass er zwei Interfaces if0 und if1 aufmacht.
Anscheinend kann er die sogar parallel offen haben/lassen.

@stefan123t
Copy link
Collaborator

@andreas5232 bitte mit der v0.5.9 überprüfen und ggf. als gelöst schließen. Danke
Das größere Thema mit dem Scheduler und einer Command Queue sollte im Rahmen von #78 gelöst werden.

@andreas5232
Copy link
Contributor Author

Sorry, dass ich hier zwischenzeitlich ausgestiegen bin und auf das letzte Mention nicht reagiert habe.
Vielen vielen Dank für eure tolle Arbeit! 👍
Aus meiner Sicht ist das Issue gelöst.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working fixed dev fixed
Projects
None yet
Development

No branches or pull requests

5 participants