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

getting bootloop after updating to ESP_Easy_mega-20190716_normal_ESP8266_4M.bin #2513

Closed
umbm opened this issue Jul 16, 2019 · 15 comments

Comments

@umbm
Copy link

commented Jul 16, 2019

After updating to ESP_Easy_mega-20190716_normal_ESP8266_4M.bin I got bootloop restarting the updated device.

Testet at 2 ESP8266-12f-modules, both used with ESP_Easy_mega-20190630_normal_ESP8266_4M.bin before without problems

@jimmys01

This comment has been minimized.

Copy link
Contributor

commented Jul 16, 2019

My log

55 : INIT : Free RAM:33712
56 : INIT : Warm boot #6 Last Task: Const Interval timer, id: 3 - Restart Reason: Hardware Watchdog
58 : FS : Mounting...
83 : FS : Mount successful, used 75802 bytes of 957314
90 : CRC : No program memory checksum found. Check output of crc2.py
101 : CRC : SecuritySettings CRC ...OK
207 : INIT : Free RAM:30536
209 : INIT : I2C
209 : INIT : SPI not enabled
223 : INFO : Plugins: 47 [Normal] (ESP82xx Core 2_5_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.1.2 PUYA support)
225 : WIFI : Current mode 0
226 : WIFI : Set WiFi to STA
362 : WIFI : Connecting Resort office attempt #0
466 : WIFI : WiFi.status() = WL_DISCONNECTED SSID: Resort office
468 : Waiting for WiFi connect
569 : Waiting for WiFi connect
671 : Waiting for WiFi connect
773 : Waiting for WiFi connect
874 : Waiting for WiFi connect
976 : Waiting for WiFi connect
1077 : Waiting for WiFi connect
1178 : Waiting for WiFi connect
1280 : Waiting for WiFi connect
1381 : Waiting for WiFi connect
1482 : Waiting for WiFi connect
1585 : Waiting for WiFi connect
1686 : Waiting for WiFi connect
1787 : Waiting for WiFi connect
1889 : Waiting for WiFi connect
1990 : Waiting for WiFi connect
2092 : Waiting for WiFi connect
2192 : Waiting for WiFi connect
2293 : Waiting for WiFi connect
2394 : Waiting for WiFi connect
2495 : Waiting for WiFi connect
2596 : Waiting for WiFi connect
2697 : Waiting for WiFi connect
2798 : Waiting for WiFi connect
2899 : Waiting for WiFi connect
3000 : Waiting for WiFi connect
3101 : Waiting for WiFi connect
3202 : Waiting for WiFi connect

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

I did add some extra debug info about the WiFi to investigate the WatchDog reboot issues, so there is more info like @jimmys01 shows.

What bootloops do you see?
Can you show some console output?
What devices and controllers are you using?
If you wait long enough, does the node boot with one (or more) plugins or controllers disabled? If so, which ones are disabled?

@jimmys01

This comment has been minimized.

Copy link
Contributor

commented Jul 16, 2019

The node I updated was completly blank, no plugins no controlers

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

One thing I did change was that I made core 2.5.2 the default now.

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

I flashed the nightly build to a test unit here and now I get what @jimmys01 meant.
It doesn't get passed the log part he posted.

I will mark a bit warning with the release about this.

@umbm

This comment has been minimized.

Copy link
Author

commented Jul 16, 2019

Here's a serial output of my bottloop:

`3772 : Waiting for WiFi connect
3872 : Waiting for WiFi connect
3973 : Waiting for WiFi connect
4074 : Waiting for WiFi connect
4175 : Waiting for WiFi connect
4276 : Waiting for WiFi connect
4376 : Waiting for WiFi connect
4477 : Waiting for WiFi connect
4578 : Waiting for WiFi connect
4679 : Waiting for WiFi connect
4780 : Waiting for WiFi connect
4881 : Waiting for WiFi connect
4981 : Waiting for WiFi connect
5082 : Waiting for WiFi connect
5183 : Waiting for WiFi connect
5284 : Waiting for WiFi connect
5385 : Waiting for WiFi connect
5486 : Waiting for WiFi connect
5586 : Waiting for WiFi connect
5687 : Waiting for WiFi connect
5788 : WIFI : WiFiConnected() out of sync
5789 : Reset WiFi.
5916 : WIFI : Disconnected: WiFi.status() = 6
6123 : WIFI : Disconnected: WiFi.status() = 6
6249 : DHT : No Reading
6354 : WIFI : Disconnected: WiFi.status() = 6
6564 : WIFI : Disconnected: WiFi.status() = 6
6770 : WIFI : Disconnected: WiFi.status() = 6
7016 : WIFI : Disconnected: WiFi.status() = 6
7222 : WIFI : Disconnected: WiFi.status() = 6
7429 : WIFI : Disconnected: WiFi.status() = 6
7635 : WIFI : Disconnected: WiFi.status() = 6
7851 : WIFI : Disconnected: WiFi.status() = 6
8058 : WIFI : Disconnected: WiFi.status() = 6
8277 : WIFI : Disconnected: WiFi.status() = 6
8483 : WIFI : Disconnected: WiFi.status() = 6
8689 : WIFI : Disconnected: WiFi.status() = 6
8790 : WD : Uptime 0 ConnectFailures 0 FreeMem 26544 WiFiStatus 6
8907 : WIFI : Disconnected: WiFi.status() = 6
9112 : WIFI : Disconnected: WiFi.status() = 6
9319 : WIFI : Disconnected: WiFi.status() = 6
9524 : WIFI : Disconnected: WiFi.status() = 6
9729 : WIFI : Disconnected: WiFi.status() = 6
9935 : WIFI : Disconnected: WiFi.status() = 6
10155 : WIFI : Disconnected: WiFi.status() = 6
10360 : WIFI : Disconnected: WiFi.status() = 6
10566 : WIFI : Disconnected: WiFi.status() = 6
10772 : WIFI : Disconnected: WiFi.status() = 6
10978 : WIFI : Disconnected: WiFi.status() = 6
11184 : WIFI : Disconnected: WiFi.status() = 6
11287 : WIFI : Current mode 0
11288 : WIFI : Set WiFi to STA
11291 : IP : Static IP : 192.168.178.109 GW: 192.168.178.1 SN: 255.255.255.0 DNS: 192.168.178.1
11423 : WIFI : Connecting cutoff attempt #0
11425 : IP : Static IP : 192.168.178.109 GW: 192.168.178.1 SN: 255.255.255.0 DNS: 192.168.178.1
11528 : WIFI : WiFi.status() = WL_DISCONNECTED SSID: cutoff
11530 : Waiting for WiFi connect
11632 : Waiting for WiFi connect
11734 : Waiting for WiFi connect
11835 : Waiting for WiFi connect
11936 : Waiting for WiFi connect
12038 : Waiting for WiFi connect
12139 : Waiting for WiFi connect
12240 : Waiting for WiFi connect
12342 : Waiting for WiFi connect
12443 : Waiting for WiFi connect
12545 : Waiting for WiFi connect
12646 : Waiting for WiFi connect
12747 : Waiting for WiFi connect
12848 : Waiting for WiFi connect
12949 : Waiting for WiFi connect
13050 : Waiting for WiFi connect
13152 : Waiting for WiFi connect
13253 : Waiting for WiFi connect
13354 : Waiting for WiFi connect
13454 : Waiting for WiFi connect
13555 : Waiting for WiFi connect
13656 : Waiting for WiFi connect
13757 : Waiting for WiFi connect
13859 : Waiting for WiFi connect
13960 : Waiting for WiFi connect
14061 : Waiting for WiFi connect
14162 : Waiting for WiFi connect
14263 : Waiting for WiFi connect

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

wdt reset
load 0x4010f000, len 1384, room 16
tail 8
chksum 0x2d
csum 0x2d
v8b899c12
~ld
¬U54 :

INIT : Booting version: mega-20190716 (ESP82xx Core 2_5_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.1.2 PUYA support)
55 : INIT : Free RAM:33680
56 : INIT : Warm boot #1 Last Task: Const Interval timer, id: 3 - Restart Reason: Hardware Watchdog
58 : FS : Mounting...
83 : FS : Mount successful, used 75802 bytes of 957314
475 : CRC : program checksum ...OK
487 : CRC : SecuritySettings CRC ...OK
488 : CRC : binary has changed since last save of Settings
489 : IP : Static IP : 192.168.178.109 GW: 192.168.178.1 SN: 255.255.255.0 DNS: 192.168.178.1
600 : INIT : Free RAM:28408
602 : INIT : I2C
603 : INIT : SPI not enabled
609 : INIT : Pulse 5
643 : INFO : Plugins: 47 [Normal] (ESP82xx Core 2_5_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.1.2 PUYA support)
747 : Waiting for WiFi connect
848 : Waiting for WiFi connect
949 : Waiting for WiFi connect
1050 : Waiting for WiFi connect
1151 : Waiting for WiFi connect
1252 : Waiting for WiFi connect
1353 : Waiting for WiFi connect
1453 : Waiting for WiFi connect
1554 : Waiting for WiFi connect
1655 : Waiting for WiFi connect
1756 : Waiting for WiFi connect
1857 : Waiting for WiFi connect
1957 : Waiting for WiFi connect
2058 : Waiting for WiFi connect
2159 : Waiting for WiFi connect
2260 : Waiting for WiFi connect
2361 : Waiting for WiFi connect
2462 : Waiting for WiFi connect
2563 : Waiting for WiFi connect
2663 : Waiting for WiFi connect
2764 : Waiting for WiFi connect
2865 : Waiting for WiFi connect
2966 : Waiting for WiFi connect
3067 : Waiting for WiFi connect
3167 : Waiting for WiFi connect
3268 : Waiting for WiFi connect
3369 : Waiting for WiFi connect
3470 : Waiting for WiFi connect
3571 : Waiting for WiFi connect
3672 : Waiting for WiFi connect
3773 : Waiting for WiFi connect
3873 : Waiting for WiFi connect
3974 : Waiting for WiFi connect
4075 : Waiting for WiFi connect
4176 : Waiting for WiFi connect
4277 : Waiting for WiFi connect
4378 : Waiting for WiFi connect
4478 : Waiting for WiFi connect
4579 : Waiting for WiFi connect
4680 : Waiting for WiFi connect
4781 : Waiting for WiFi connect
4882 : Waiting for WiFi connect
4983 : Waiting for WiFi connect
5083 : Waiting for WiFi connect
5184 : Waiting for WiFi connect
5285 : Waiting for WiFi connect
5386 : Waiting for WiFi connect
5487 : Waiting for WiFi connect
5588 : Waiting for WiFi connect
5688 : Waiting for WiFi connect
5789 : WIFI : WiFiConnected() out of sync
5790 : Reset WiFi.
5917 : WIFI : Disconnected: WiFi.status() = 6
6124 : WIFI : Disconnected: WiFi.status() = 6
6252 : DHT : No Reading
6356 : WIFI : Disconnected: WiFi.status() = 6
6567 : WIFI : Disconnected: WiFi.status() = 6
6773 : WIFI : Disconnected: WiFi.status() = 6
7019 : WIFI : Disconnected: WiFi.status() = 6
7224 : WIFI : Disconnected: WiFi.status() = 6
7430 : WIFI : Disconnected: WiFi.status() = 6
7636 : WIFI : Disconnected: WiFi.status() = 6
7853 : WIFI : Disconnected: WiFi.status() = 6
8059 : WIFI : Disconnected: WiFi.status() = 6
8279 : WIFI : Disconnected: WiFi.status() = 6
8486 : WIFI : Disconnected: WiFi.status() = 6
8693 : WIFI : Disconnected: WiFi.status() = 6
8794 : WD : Uptime 0 ConnectFailures 0 FreeMem 26512 WiFiStatus 6
8910 : WIFI : Disconnected: WiFi.status() = 6
9116 : WIFI : Disconnected: WiFi.status() = 6
9323 : WIFI : Disconnected: WiFi.status() = 6
9527 : WIFI : Disconnected: WiFi.status() = 6
9733 : WIFI : Disconnected: WiFi.status() = 6
9939 : WIFI : Disconnected: WiFi.status() = 6
10158 : WIFI : Disconnected: WiFi.status() = 6
10364 : WIFI : Disconnected: WiFi.status() = 6
10570 : WIFI : Disconnected: WiFi.status() = 6
10776 : WIFI : Disconnected: WiFi.status() = 6
10981 : WIFI : Disconnected: WiFi.status() = 6
11188 : WIFI : Disconnected: WiFi.status() = 6
11291 : WIFI : Current mode 0
11292 : WIFI : Set WiFi to STA
11295 : IP : Static IP : 192.168.178.109 GW: 192.168.178.1 SN: 255.255.255.0 DNS: 192.168.178.1
11427 : WIFI : Connecting cutoff attempt #0
11428 : IP : Static IP : 192.168.178.109 GW: 192.168.178.1 SN: 255.255.255.0 DNS: 192.168.178.1
11532 : WIFI : WiFi.status() = WL_DISCONNECTED SSID: cutoff
11533 : Waiting for WiFi connect
11635 : Waiting for WiFi connect
11737 : Waiting for WiFi connect
11838 : Waiting for WiFi connect
11939 : Waiting for WiFi connect
12040 : Waiting for WiFi connect
12141 : Waiting for WiFi connect
12242 : Waiting for WiFi connect
12343 : Waiting for WiFi connect
12445 : Waiting for WiFi connect
12546 : Waiting for WiFi connect
12647 : Waiting for WiFi connect
12748 : Waiting for WiFi connect
12849 : Waiting for WiFi connect
12950 : Waiting for WiFi connect
13052 : Waiting for WiFi connect
13153 : Waiting for WiFi connect
13254 : Waiting for WiFi connect
13355 : Waiting for WiFi connect
13456 : Waiting for WiFi connect
13557 : Waiting for WiFi connect
13658 : Waiting for WiFi connect
13758 : Waiting for WiFi connect
13859 : Waiting for WiFi connect
13960 : Waiting for WiFi connect
14061 : Waiting for WiFi connect
14162 : Waiting for WiFi connect
14263 : Waiting for WiFi connect
`

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

I deleted the ZIP from the releases, I'm seeing the same here.
I suspect a build issue and will test some builds I'm making in Linux.

@jimmys01

This comment has been minimized.

Copy link
Contributor

commented Jul 20, 2019

@TD-er Any updates about this issue?

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 20, 2019

@jimmys01 See my struggles here: esp8266/Arduino#6172 (comment)

I have no idea what's happening here.
The same code, but with more plugins may result in a build that is not capable to connect to WiFi.
It is like Russian Roulette right now whether a build may be able to connect.

@ristomatti

This comment has been minimized.

Copy link

commented Jul 27, 2019

Another one here running into this. Normally I'd run a release build but this time I wanted to include _P130_VEML6075.ino from the playground so I flashed a custom build. I thought I was losing my mind as I've never run into this with ESPEasy. After trying everything I could think of I gave up and thought I'll return to this by flashing an older release version to see if the problem still exists but found this thread first.

I also tried removing AP config from Custom.h to try if configuring from the web portal would do it any difference. Most of times the web portal would freeze after submitting the form but once I got a "Not enough memory" (or something similar) message.

Reverting back to tag mega-20190630 fixes the issue for me regardless if I use core 241 or 252. Could the runtime memory consumption just have gone over some critical point between these two releases? At least I have been able to reproduce the problem 100% of times and not only on random builds. @TD-er have you been able to isolate the commit that first introduced the issue?

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 28, 2019

@ristomatti I am not entirely sure I have, since the 'bug' we're seeing here is that it may work on one build (e.g. normal) and crash on another (e.g. test) or vice verse.
But by reverting all my WiFi related changes I was not able to let it crash at first attempt to connect to WiFi.

Thanks for submitting the suggestion you saw memory issues. It may help me track down this issue.

@ristomatti

This comment has been minimized.

Copy link

commented Jul 28, 2019

@TD-er I'm likely relatively a complete novice as a C/C++/Arduino developer compared to you but these kind intermittent issues would to me sound very likely to be related to dynamic memory usage.

Since the latest mega release on the downloads list contains a huge amount of changes, I would suggest going through the commits in between using a binary search style approach. Then when the commit or commit range with the culprit changes is found, do a diff between the changes and once again apply each independent change back manually.

I am certain that as an experienced developer you're already familiar with this tedious approach of debugging but I can't count the times a colleague has had to suggest me exactly this when I've got stuck with an intermittent problem.

To me it's crazy how many by default enabled features have already been managed to be crammed into ESPEasy. Any future change is bound to be a potential regression somewhere.

And in case you're only seeing this intermittently on your system. If it's of any help, the cycle that caused this to occur 100% times at least for me was: erase flash, then upload the normal 4M build (with any core). While doing this I had a predefined device name, AP/AP password and an admin password in my Custom.h. This way I also saw the issue right away.

Good luck cracking the issue!

@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 28, 2019

Since the latest mega release on the downloads list contains a huge amount of changes, I would suggest going through the commits in between using a binary search style approach. Then when the commit or commit range with the culprit changes is found, do a diff between the changes and once again apply each independent change back manually.

I've maybe not used binary search here, but did exclude some plugins in my builds to exclude at least the IR library update just to make sure I didn't have to dive into those. Although these are already not present anymore in the normal build and that one was also showing issues.
But even then the same set of plugins but only changing something seemingly unrelated in the code was resulting in a build that was unable to connect to WiFi.

If you're running out of memory like you saw happening, then it may give me some clue to where to look for the changes.
I think I will be rolling back all my changes related to WiFi/network code since 20190630, since that one was relatively stable regarding to WiFi.
There were still some reports of users which are not able to connect to WiFi, but that's only a handful and may be related to some other issues like power or flaky board designs.

@umbm

This comment has been minimized.

Copy link
Author

commented Jul 31, 2019

Tested newest from 20190731 with changelog " [Static IP] Fix unable to connect with static IP."
It works well now, no wifi-issue as before.

And yes, I'm using static IP at all my espeasy-devices so thats why I was running in this issue?

@umbm umbm closed this Jul 31, 2019
@TD-er

This comment has been minimized.

Copy link
Member

commented Jul 31, 2019

And yes, I'm using static IP at all my espeasy-devices so thats why I was running in this issue?

That was only one of the issues.
The other problem was that the ESP8266 has a very strict order of enabling WiFi, setting credentials and initiating WiFi session. (and vice verse when disconnecting)
Not only the order was wrong, but also the WiFi radio was not forced to be awake or going to sleep which put things into unknown state.
From this unknown state it is also very timing specific whether a unit may be able to connect to WiFi, so it could differ per build/unit whether it was successful.

And on top of that we had also an issue with static IP config, which is now also fixed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
4 participants
You can’t perform that action at this time.