search

letscontrolit / ESPEasy

Easy MultiSensor device based on ESP8266/ESP32
http://www.espeasy.com
Other
3.26k stars 2.21k forks source link

WiFi connection fails on some ESP8266 nodes if Do Not Start AP: option is enabled #4337

Closed ghtester closed 8 months ago

ghtester commented 1 year ago

I have upgraded one ESP Easy node (8266) from custom firmware 20220829 to custom 20221031 as it started disappearing from WiFi network.
After the upgrade and node reboot it seemed to be working fine but after several hours it disappeared again. Then I tried to edit some WiFi settings but after the reboot the node did not boot properly anymore. The WiFi status LED was just changing the light intensity from low to medium after several seconds and that was all. Repeated connecting to serial console showed just some garbage characters or even nothing. Then I decided to reflash with empty bin, reflashed again with custom 20221031 which was working again with default configuration. As soon as I restored the earlier config, the described issue returned... Then I reflashed with custom 20220829 firmware which is so far working fine with the restored config. The question is what could make the config incompatible with latest firmware release? Another question is - could we make a feature for exporting all configuration parameters in text form from ESP node? Also a simple viewer or config exporter could be useful (I mean an app or a script ) to be used with already existing binary config files. Maybe I could perhaps try to do some work on it if somebody reminds me with the current config binary file structure. image

Jason2866 commented 1 year ago

@TD-er Could be the change of the used SDK.

TD-er commented 1 year ago

@Jason2866 Also for ESP8266 builds?

TD-er commented 1 year ago

@ghtester I really don't know what may have made the settings incompatible. The only thing added to the settings is the added md5 checksum at the end (to re-introduce the feature to not saving settings when nothing was changed) and the internal build nr is updated to know if we need to perform version transitions. These transitions are only used to convert some settings if we add some features. For example P014 now supports multiple sensors which adds the need to set an I2C address. So there is a transition on existing settings to set the previous default address.

The settings are kept as much backwards compatible as possible. As a matter of fact, last week I upgraded a node with 4 year old settings and this worked just fine.

Jason2866 commented 1 year ago

@TD-er Only for esp8266. The change of the used SDK you did.

TD-er commented 1 year ago

@TD-er Only for esp8266. The change of the used SDK you did.

Hmm I wasn't aware I did change something significant for the ESP8266. Do you know what may have changed what may cause these things? Where do I need to look?

Edit: Or do you mean this: PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK22x_190313 ?

Jason2866 commented 1 year ago

Or do you mean this: PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK22x_190313 ?

Yes! You opened the esp8266 pandoras box by doing this ;-)

TD-er commented 1 year ago

Why does Pandora leave these boxes laying around... Hasn't she learned to clean up?

ghtester commented 1 year ago

As a matter of fact, last week I upgraded a node with 4 year old settings and this worked just fine.

I don't know, maybe my custom build uses some unusual settings / directives in Custom.h or a plugin combinations... Or a HW issue of affected ESP node (it's permanently running for about 4 years so may be it's a bit dying)?
Perhaps I should try upgrading another ESP node but there's always a different configuration. As the custom release 20220829 works pretty fine on my nodes, also some of them are not easily reflashable if I defunct them by upgrade so I have to be careful. Hopefully the SDK change is the reason... ;-)

TD-er commented 1 year ago

I will look into the SDK change. This was mainly done to have 802.11n connections which really obey the standards and also for those problematic units that worked on really old builds but no more on builds made in the last 3 years.

TD-er commented 1 year ago

Can you please re-test using the current 'mega' branch code? This still uses the same ESP8266 SDK version, but @Jason2866 did suggest to change the way how PlatformIO tries to find the required libraries and this does seem to have an effect on the 'build predictability', which is what we really need.

ghtester commented 1 year ago

Thanks a lot, I have just recompiled the firmware from current sources, in the evening I'll try to upgrade the node again and share the feedback.

ghtester commented 1 year ago

OK, some news - the same issue on the same node with fresh Vagrant custom build, right after the update & reboot it did not work properly anymore. LCD display was initialized but rules did not work, WiFi LED changing light intensity after several seconds., no connection to WiFi AP. Reflashed back to 20220929 and working again. Checked the configuration and discovered the Serial port & Serial Log was disabled earlier to save RAM (that's why I did not see any serial log). Upgraded another ESP node from 20220829 to 20221108 without issue...

cybermcm commented 1 year ago

I may have a similar problem (or maybe it is not related at all ;-), I'm not an expert. I have 9 ESP8266 running on mega-20220809_normal just fine (most of them only have one temperature sensor attached) Updated all of them to mega-20221105 -> 5 working without any issue, 4 do not connect to my wifi anymore. After rebooting a faulty device, the ESP are sending their own Wi-Fi, then I'm able to connect to it (192.168.4.1) and revert to 20220809 -> issue gone, all faulty devices working again (no config changed) The ESP are connected to different APs, the APs running on OpenWRT (latest build)

currently my free time is somehow limited, but if any further data is useful I'll try to provide it.

ghtester commented 1 year ago

Maybe it's HW related... My problematic ESP node:

ESP Board -- ESP Chip ID: | 3523742 (0x35C49E) ESP Chip Frequency: | 80 MHz ESP Chip Model: | ESP8266 ESP Chip Cores: | 1 ESP Board Name: | Espressif Generic ESP8266 ESPEasy 4M Flash 1M FS

Working firmware:

Firmware -- Build:⋄ | 20220829 - Mega System Libraries:⋄ | ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support Git Build:⋄ | My Build: Aug 29 2022 09:27:48 Plugin Count:⋄ | 39 [IR] Build Origin: | Vagrant Build Time:⋄ | Aug 29 2022 09:27:04 Binary Filename:⋄ | ESP_Easy_mega_20220829_custom_IR_ESP8266_4M1M Build Platform:⋄ | Linux-4.15.0-51-generic-x86_64-with-glibc2.27 Git HEAD:⋄ | mega_44b2677

BTW. I have the AP mode disabled on this node. Maybe I could enable it, reflash to "bad" firmware and test what happens. Serial port & logging now enabled.

TD-er commented 1 year ago

I'm thinking about the following idea:

The SDK now used for ESP8266 builds is PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK22x_190313 This seems to be the (only?) one that's working on "flaky" ESP nodes, like the Sonoff Basic units. What if I revert this SDK back to the one we used on the August build and then set those builds we now have labelled "alt WiFi" to use this 190313 SDK. Right now, I have no idea what is the very specific cause for units that won't work with one SDK and only work with the other and vice verse. Simply because these SDK binary blobs have no release notes or anything indicating what may be different.

TD-er commented 1 year ago

@ghtester Maybe you can already test with the current "alt WiFi" PIO env? It is using a different SDK from the August builds, but at least it is different from the current "default" one.

ghtester commented 1 year ago

I am not sure how the configuration option should look like exactly to use "alt WiFi". For me it's important to have the IR related plugins compiled and I am not sure if there's any possible conflict / missing plugins or not. So I would prefer to revert the SDK with default env. Unfortunately my build environment is inaccessible now anyway so I could recompile tomorrow.

TD-er commented 1 year ago

There are various "custom" builds defined. image

But I don't see an alt WiFi one with IR. Let's continue this tomorrow after I have done some tests on the "problematic" units to see if they now will work well on the previous used SDK for ESP8266.

ghtester commented 1 year ago

OK, thanks for the details, missing IR is a trouble for me. BTW. this is the serial log after upgraded again to "bad" 20221108: ▒U11756 : Info : WIFI : Set WiFi to AP+STA 16546 : Info : WIFI : Set WiFi to OFF 16763 : Info :

INIT : Booting version: ESP_Easy_mega_20221108_custom_IR_ESP8266_4M1M, (Vagrant) My Build: Nov 8 2022 15:03:09 (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support) 16764 : Info : INIT : Free RAM:25272 16766 : Info : INIT : Cold Boot - Restart Reason: Software/System restart 16767 : Info : FS : Mounting... 16793 : Info : FS : Mount successful, used 78061 bytes of 957314 16809 : Error : CRC : Settings CRC ...FAIL 16811 : Info : CRC : SecuritySettings CRC ...OK 16814 : Info : INIT : I2C 16815 : Info : INIT : SPI not enabled 16921 : Info : WIFI : Set WiFi to STA 19218 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-44dBm) WPA2/PSK attempt #0 19432 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 112 ms 19534 : Info : Reset WiFi. 21730 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-43dBm) WPA2/PSK attempt #1 22680 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 112 ms 22681 : Info : WIFI : Set WiFi to OFF

Build changed! 22869 : Info : Skip saving SecuritySettings, not changed 22870 : Info : INIT : Free RAM:24608 22906 : Info : P016_PLUGIN_INIT ... 22908 : Info : INIT: IR RX 22909 : Info : IR lib Version: 2.8.2 22909 : Info : P016_PLUGIN_INIT IR receiver created 22910 : Info : P016_PLUGIN_INIT IR receiver initialized 22910 : Info : P016_PLUGIN_INIT done 24060 : Info : INFO : Plugins: 40 [IR][No Debug Log] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support) 24061 : Info : EVENT: System#Wake 24214 : Info : Webserver: start 24214 : Info : EVENT: System#Boot 24218 : Info : ACT : rtttl,15:d=10,o=6,b=200,c,g,e 24220 : Info : RTTTL : pin: 15 melody: 15:d=10,o=6,b=200,c,g,e 24583 : Info : ACT : LCDCMD,off 24587 : Info : ACT : timerSet,1,5 24591 : Info : ACT : gpio,10,0 24593 : Info : GPIO : port#10: set to 0 24594 : Info : ACT : gpio,10,1 24596 : Info : GPIO : port#10: set to 1 24598 : Info : ACT : gpio,10,0 24599 : Info : GPIO : port#10: set to 0 24604 : Info : WIFI : Disconnected! Reason: '(202) Auth fail' Connected for 951 ms 24805 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 24 s 24906 : Info : Reset WiFi. 25010 : Info : WIFI : Set WiFi to STA 27310 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-47dBm) WPA2/PSK attempt #2 27417 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 27518 : Info : Reset WiFi. 29715 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-47dBm) WPA2/PSK attempt #3 30664 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 30665 : Info : WIFI : Set WiFi to OFF 30989 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 1173 ms 31090 : Info : Reset WiFi. 31195 : Info : WIFI : Set WiFi to STA 33493 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-47dBm) WPA2/PSK attempt #4 33500 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 1173 ms 33501 : Info : WIFI : Set WiFi to OFF 33715 : Info : EVENT: WiFi#APmodeDisabled 33833 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 238 ms 33934 : Info : Reset WiFi. 34039 : Info : WIFI : Set WiFi to STA 36338 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-47dBm) WPA2/PSK attempt #5 36345 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 238 ms 36345 : Info : WIFI : Set WiFi to OFF 36560 : Info : EVENT: WiFi#Disconnected 36678 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 238 ms 36779 : Info : Reset WiFi. 36883 : Info : WIFI : Set WiFi to STA 39183 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-45dBm) WPA2/PSK attempt #6 39191 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 238 ms 39191 : Info : WIFI : Set WiFi to OFF 39406 : Info : EVENT: TaskInit#IR=1,1 39524 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 39625 : Info : Reset WiFi. 39730 : Info : WIFI : Set WiFi to STA 42029 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-47dBm) WPA2/PSK attempt #7 42036 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 42037 : Info : WIFI : Set WiFi to OFF 42251 : Info : EVENT: TaskInit#ADC=5,1 42370 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 42471 : Info : Reset WiFi. 42576 : Info : WIFI : Set WiFi to STA 44874 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-43dBm) WPA2/PSK attempt #8 44881 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 44882 : Info : WIFI : Set WiFi to OFF 45096 : Info : EVENT: TaskInit#Kitchen=6,1 45215 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 45316 : Info : Reset WiFi. 45420 : Info : WIFI : Set WiFi to STA 47719 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-45dBm) WPA2/PSK attempt #9 47726 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 47727 : Info : WIFI : Set WiFi to OFF 47941 : Info : EVENT: TaskInit#Motor=7,1 48060 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 48161 : Info : Reset WiFi. 48266 : Info : WIFI : Set WiFi to STA 50565 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-45dBm) WPA2/PSK attempt #10 50572 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 50573 : Info : WIFI : Set WiFi to OFF 50787 : Info : EVENT: TaskInit#Coolbox=8,1 50906 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 51007 : Info : Reset WiFi. 51111 : Info : WIFI : Set WiFi to STA 53410 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-41dBm) WPA2/PSK attempt #11 53418 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 53418 : Info : WIFI : Set WiFi to OFF 53633 : Info : EVENT: TaskInit#SW1=9,1 53751 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 53852 : Info : Reset WiFi. 53957 : Info : WIFI : Set WiFi to STA 56257 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-44dBm) WPA2/PSK attempt #12 56264 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 56265 : Info : WIFI : Set WiFi to OFF 56479 : Info : EVENT: TaskInit#Status=10,1 56598 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 56699 : Info : Reset WiFi. 56804 : Info : WIFI : Set WiFi to STA 59103 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-45dBm) WPA2/PSK attempt #13 59110 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 59110 : Info : WIFI : Set WiFi to OFF 59325 : Info : EVENT: TaskInit#LCD=11,1 59444 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 59545 : Info : Reset WiFi. 59649 : Info : WIFI : Set WiFi to STA 61949 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-44dBm) WPA2/PSK attempt #14 61956 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 61956 : Info : WIFI : Set WiFi to OFF 62171 : Info : EVENT: TaskInit#PIR=12,1 62289 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 62390 : Info : Reset WiFi. 62495 : Info : WIFI : Set WiFi to STA 64795 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-44dBm) WPA2/PSK attempt #15 64802 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 64803 : Info : WIFI : Set WiFi to OFF 65017 : Info : EVENT: WiFi#Disconnected 65135 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 238 ms 65236 : Info : Reset WiFi. 65341 : Info : WIFI : Set WiFi to STA

ghtester commented 1 year ago

BTW. when I entered the WifiAPMode command to serial console, the node connected to AP and started working. :-) To be analyzed a bit...

TD-er commented 1 year ago

hmm can you set it to " force B/G"? Thing is, with AP enabled, the ESP radio cannot use 802.11n, thus is forced to use 802.11g anyway.

TD-er commented 1 year ago

By the way, this does look like a big clue to me. The SDK currently used is the only one (I am aware of) that does allow for 802.11n according to the standards. The later SDK versions (at least for the 2.x SDK revisions) do not connect fully according to the specs. So it could be the other SDK versions were already treated by the access point as 802.11g clients.

ghtester commented 1 year ago

See the log: .... 62217 : Info : Reset WiFi. 62321 : Info : WIFI : Set WiFi to STA 64622 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-51dBm) WPA2/PSK attempt #19 64629 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 239 ms 64630 : Info : WIFI : Set WiFi to OFF 64844 : Info : EVENT: WiFi#Disconnected

WifiAPMode 64955 : Info : WIFI : Set WiFi to AP 65061 : Error : WIFI : Error while starting AP Mode with SSID: ESP11 IP: 192.168.4.1

OK 65119 : Info : ADC : Analog value: 1 = 1.00 65197 : Info : Dummy: value 1: 0 65199 : Info : Dummy: value 2: 0 65199 : Info : Dummy: value 3: 0 65200 : Info : Dummy: value 4: 0 65297 : Info : EVENT: WiFi#Disconnected 65426 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 13736 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED 65596 : Info : EVENT: WiFi#Disconnected 65662 : Info : EVENT: Rules#Timer=1,1 65670 : Info : ACT : TaskValueSet 10,3,1 65674 : Info : ACT : rtttl,15:d=100,o=7,b=200,g 65676 : Info : RTTTL : pin: 15 melody: 15:d=100,o=7,b=200,g 65691 : Info : ACT : gpio,10,1 65693 : Info : GPIO : port#10: set to 1 66104 : Info : EVENT: WiFi#Disconnected 66658 : Info : EVENT: WiFi#Disconnected 66873 : Info : ADC : Analog value: 1 = 1.00 67213 : Info : EVENT: WiFi#Disconnected 67729 : Info : EVENT: WiFi#Disconnected 68132 : Info : EVENT: WiFi#Disconnected 68154 : Info : IR: No replay solutions found! Press button again or try RAW encoding (timings are in the serial output) IR: RAW TIMINGS: uint16_t rawData[17] = {186, 7698, 588, 2530, 522, 532, 306, 5202, 332, 5524, 446, 1864, 302, 17282, 328, 3524, 382}; // UNKNOWN 8D5ED574 68246 : Info : EVENT: WiFi#Disconnected 68363 : Info : EVENT: WiFi#Disconnected 68415 : Info : EVENT: WiFi#Disconnected 68433 : Info : EVENT: WiFi#Disconnected 68451 : Info : EVENT: WiFi#Disconnected 68481 : Info : EVENT: WiFi#Disconnected 68499 : Info : EVENT: WiFi#Disconnected 68516 : Info : EVENT: ADC#Voltage=1.00 68535 : Info : EVENT: SW1#State=1 68541 : Info : ACT : TaskValueSet 10,2,1 68558 : Info : EVENT: Status#1=0 68592 : Info : EVENT: Status#2=0 68611 : Info : EVENT: Status#3=0 68628 : Info : EVENT: Status#4=0 68646 : Info : EVENT: PIR#State=0 68671 : Info : ACT : TaskValueSet 10,1,0 68700 : Info : EVENT: ADC#Voltage=1.00 68719 : Info : EVENT: IR#input=2371802484 71601 : Info : ADC : Analog value: 1 = 1.00 71619 : Info : EVENT: ADC#Voltage=1.00 71802 : Info : Dummy: value 1: 0 71803 : Info : Dummy: value 2: 1 71804 : Info : Dummy: value 3: 1 71805 : Info : Dummy: value 4: 0 71823 : Info : EVENT: Status#1=0 71841 : Info : EVENT: Status#2=1 71859 : Info : EVENT: Status#3=1 71889 : Info : EVENT: Status#4=0 74400 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 14960 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED 74728 : Info : WIFI : Set WiFi to AP+STA 74836 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-51dBm) WPA2/PSK attempt #20 76586 : Info : WIFI : DHCP IP: 192.168.36.102 (ESP11) GW: 192.168.36.1 SN: 255.255.255.0 duration: 536 ms 76587 : Info : IP : Fixed IP octet:192.168.36.141 76591 : Info : firstLoopConnectionsEstablished 76597 : Info : WIFI : Connected! AP: MyTestAP (17:C4:C7:FE:11:84) Ch: 12 Duration: 1199 ms 76598 : Info : WIFI : Starting mDNS... 76601 : Info : WIFI : mDNS started, with name: ESP11.local 77721 : Info : EVENT: WiFi#Connected 77730 : Info : EVENT: WiFi#ChangedAccesspoint 77749 : Error : MQTT : Intentional reconnect 78014 : Info : MQTT : Connected to broker

I think B/G won't help as I have enabled it right before the issue was encountered first time. I'll try reboot

TD-er commented 1 year ago

Another thing changed with AP enabled is that the WiFi radio never sleeps. So this may be -again- one of those awfully timing critical issues. You could try to reduce the max. TX power and still have the "send with max. TX power" checked.

For example by setting it to 7 dBm, you already reduce the TX power (in Watt) considerably and "7" is probably still enough given your AP is seen at an RSSI of -51.

ghtester commented 1 year ago

Yes I can confirm forcing B/G mode does not help. The node is now next to AP but the original location is a bit far from it and the issue was exactly the same. So I think struggling with TX power won't bring any useful feedback. It should work reliable with any settings...

Edit - decreased max TX power to 7 , rebooted - the same issue. As soon as the WifiAPmode command entered, the node quickly connects to AP.

Edit2 - checked the Force WiFi No Sleep: option, rebooted - the same issue.

Edit3 - unchecked the Do Not Start AP: option, rebooted - and it helped! The node connected to AP succesfully (but it took a bit longer than with earlier firmware).

Edit4 - checked the Do Not Start AP: option again, rebooted - and issue is back... The bad thing is I would like keep this option checked... For now I'll uncheck it and keep the 20221108 firmware running.

ghtester commented 1 year ago

BTW. this is the log after unchecked Do Not Start AP: option:

load 0x4010f000, len 3584, room 16 tail 0 chksum 0xb0 csum 0xb0 v2843a5ac ~ld ▒U309 : Info : WIFI : Set WiFi to AP+STA 5101 : Info : WIFI : Set WiFi to OFF 5318 : Info :

INIT : Booting version: ESP_Easy_mega_20221108_custom_IR_ESP8266_4M1M, (Vagrant) My Build: Nov 8 2022 15:03:09 (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support) 5318 : Info : INIT : Free RAM:25040 5320 : Info : INIT : Soft Reboot #9 - Restart Reason: Software/System restart 5321 : Info : FS : Mounting... 5347 : Info : FS : Mount successful, used 78061 bytes of 957314 5363 : Info : CRC : Settings CRC ...OK 5391 : Info : CRC : SecuritySettings CRC ...OK 5394 : Info : INIT : I2C 5395 : Info : INIT : SPI not enabled 5407 : Info : Time set to 1667951617.000 5410 : Info : Current Time Zone: DST time start: 2022-03-27 02:00:00 offset: 120 min STD time start: 2022-10-30 03:00:00 offset: 60 min 5413 : Info : Local time: 2022-11-09 00:53:37 5529 : Info : WIFI : Set WiFi to STA 7825 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-44dBm) WPA2/PSK attempt #0 7932 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 8033 : Info : Reset WiFi. 10231 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-42dBm) WPA2/PSK attempt #1 11180 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 11181 : Info : WIFI : Set WiFi to OFF 11294 : Info : INIT : Free RAM:23776 11337 : Info : P016_PLUGIN_INIT ... 11340 : Info : INIT: IR RX 11340 : Info : IR lib Version: 2.8.2 11341 : Info : P016_PLUGIN_INIT IR receiver created 11341 : Info : P016_PLUGIN_INIT IR receiver initialized 11342 : Info : P016_PLUGIN_INIT done 12508 : Info : INFO : Plugins: 40 [IR][No Debug Log] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support) 12510 : Info : EVENT: System#Wake 12673 : Info : Webserver: start 12674 : Info : EVENT: System#Boot 12677 : Info : ACT : rtttl,15:d=10,o=6,b=200,c,g,e 12680 : Info : RTTTL : pin: 15 melody: 15:d=10,o=6,b=200,c,g,e 13043 : Info : ACT : LCDCMD,off 13047 : Info : ACT : timerSet,1,5 13050 : Info : ACT : gpio,10,0 13052 : Info : GPIO : port#10: set to 0 13054 : Info : ACT : gpio,10,1 13056 : Info : GPIO : port#10: set to 1 13058 : Info : ACT : gpio,10,0 13059 : Info : GPIO : port#10: set to 0 13063 : Info : WIFI : Disconnected! Reason: '(202) Auth fail' Connected for 951 ms 13265 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 13 s 13366 : Info : Reset WiFi. 13470 : Info : WIFI : Set WiFi to STA 15770 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-42dBm) WPA2/PSK attempt #2 15877 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 15978 : Info : Reset WiFi. 18175 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-42dBm) WPA2/PSK attempt #3 19130 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 ms 19130 : Info : WIFI : Set WiFi to OFF 19447 : Info : WIFI : Set WiFi to STA 21845 : Info : WIFI : Set WiFi to AP+STA 21951 : Error : WIFI : Error while starting AP Mode with SSID: ESP11 IP: 192.168.4.1 21963 : Info : EVENT: WiFi#APmodeDisabled 21997 : Info : ADC : Analog value: 1 = 1.00 22076 : Info : Dummy: value 1: 0 22077 : Info : Dummy: value 2: 1 22077 : Info : Dummy: value 3: 1 22078 : Info : Dummy: value 4: 14 22192 : Info : EVENT: Time#Initialized 22316 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 12272 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED 22486 : Info : EVENT: WiFi#Disconnected 22552 : Info : EVENT: Rules#Timer=1,1 22560 : Info : ACT : TaskValueSet 10,3,1 22564 : Info : ACT : rtttl,15:d=100,o=7,b=200,g 22566 : Info : RTTTL : pin: 15 melody: 15:d=100,o=7,b=200,g 22581 : Info : ACT : gpio,10,1 22583 : Info : GPIO : port#10: set to 1 22790 : Info : EVENT: TaskInit#IR=1,1 22820 : Info : EVENT: TaskInit#ADC=5,1 22838 : Info : EVENT: TaskInit#Kitchen=6,1 22857 : Info : EVENT: TaskInit#Motor=7,1 22875 : Info : EVENT: TaskInit#Coolbox=8,1 22893 : Info : EVENT: TaskInit#SW1=9,1 22923 : Info : EVENT: TaskInit#Status=10,1 22991 : Info : EVENT: TaskInit#LCD=11,1 23009 : Info : EVENT: TaskInit#PIR=12,1 23038 : Info : EVENT: WiFi#Disconnected 23056 : Info : EVENT: WiFi#Disconnected 23074 : Info : EVENT: WiFi#Disconnected 23092 : Info : EVENT: ADC#Voltage=1.00 23122 : Info : EVENT: SW1#State=1 23128 : Info : ACT : TaskValueSet 10,2,1 23144 : Info : EVENT: Status#1=0 23163 : Info : EVENT: Status#2=1 23181 : Info : EVENT: Status#3=1 23200 : Info : EVENT: Status#4=14 23230 : Info : EVENT: PIR#State=0 23270 : Info : ACT : TaskValueSet 10,1,0 28186 : Info : WIFI : Connecting MyTestAP 17:C4:C7:FE:11:84 Ch:12 (-42dBm) WPA2/PSK attempt #4 29920 : Info : WIFI : DHCP IP: 192.168.36.102 (ESP11) GW: 192.168.36.1 SN: 255.255.255.0 duration: 540 ms 29921 : Info : IP : Fixed IP octet:192.168.36.141 29926 : Info : firstLoopConnectionsEstablished 29971 : Info : WIFI : Connected! AP: MyTestAP (17:C4:C7:FE:11:84) Ch: 12 Duration: 1175 ms 29972 : Info : WIFI : Starting mDNS... 29974 : Info : WIFI : mDNS started, with name: ESP11.local 30019 : Info : NTP : NTP replied: delay 20 mSec Accuracy increased by 0.626 seconds 30021 : Info : Time set to 1667951647.626 Time adjusted by 6012.81 msec. Wander: 0.0 ppm Source: NTP 30025 : Info : Local time: 2022-11-09 00:54:07 30028 : Info : EVENT: WiFi#Connected

ghtester commented 1 year ago

FYI the second mentioned ESP node which I upgraded from 20220829 to 20221108 without issue (a different configuration & plugins used but connected to the same AP and with the Do Not Start AP: option checked) :

ESP Board -- ESP Chip ID: | 5859987 (0x596A93) ESP Chip Frequency: | 80 MHz ESP Chip Model: | ESP8266 ESP Chip Cores: | 1 ESP Board Name: | Espressif Generic ESP8266 ESPEasy 4M Flash 1M FS Firmware -- Build:⋄ | 20221108 - Mega System Libraries:⋄ | ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support Git Build:⋄ | My Build: Nov 8 2022 15:03:09 Plugin Count:⋄ | 40 [IR][No Debug Log] Build Origin: | Vagrant Build Time:⋄ | Nov 8 2022 15:02:21 Binary Filename:⋄ | ESP_Easy_mega_20221108_custom_IR_ESP8266_4M1M Build Platform:⋄ | Linux-4.15.0-51-generic-x86_64-with-glibc2.27 Git HEAD:⋄ | mega_ba182c5
TD-er commented 1 year ago 
13063 : Info : WIFI : Disconnected! Reason: '(202) Auth fail' Connected for 951 ms
13265 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 13 s

This part is a bit strange... It does receive the disconnect event twice. But it may give me a hint where to look as I did 'fix' this last week for ESP32. On ESP32 you register callback functions to capture the events. But before re-registering them, you need to unregister them. The reason you need to re-register them (which I found out last week) is that the SDK only registers those events which are applicable for the currently active interfaces. Thus causing issues when switching between STA/AP/Ethernet. When not de-registering the callback and/or using the same callback function for all interface related events, you get them multiple times. So maybe this also applies to ESP8266...

ghtester commented 1 year ago

So the question is what's the main reason of this different behaviour on different ESP8266 nodes. Nevertheless, the topic name now looks a bit misleading and perhaps I should change it... BTW. in this latest firmware release there's no ESP Easy icon in web browser's tab like on earlier version... image image

TD-er commented 1 year ago

BTW. in this latest firmware release there's no ESP Easy icon in web browser's tab like on earlier version...

Yep, I noticed too. A bit strange, as it is being served when you query it.

Edit: Ah no, the image seems to be corrupt in some way image

TD-er commented 1 year ago

Fix for the Favicon: https://github.com/letscontrolit/ESPEasy/pull/4346

TD-er commented 1 year ago

Swapped the SDKs: https://github.com/letscontrolit/ESPEasy/pull/4347 Can you please test this one as it now is set to use the SDK we used back in August.

I did test it on my flaky Sonoff Basic unit and it still would connect to WiFi. But strangely enough this one now needs to start its AP first before it will connect. So maybe it will be the fix for your unit?

ghtester commented 1 year ago

I am just recompiling, as the PR4347 was already merged, I hope I don't need any change in config files. The result to be shared in evening as the node is at different location.

TD-er commented 1 year ago

I hope I don't need any change in config files.

Nope, that should still be the same. Looking forward to the test results

cybermcm commented 1 year ago

@TD-er: I can now confirm that I'm talking about the same issue. I tried your new build from today 20221109 and now my device can connect again. If I check "Do not start AP" then there is no successful connection like you described But at least in my case there is still a problem, the connection is not stable, there are WiFi "reboots". I managed to capture the output:

Info   : WIFI : Set WiFi to AP+STA
4957 : Info   : WIFI : Set WiFi to OFF
5174 : Info   :

INIT : Booting version: ESP_Easy_mega_20221109_normal_ESP8266_4M1M, (GitHub Actions) HEAD_96ae578 (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
5175 : Info   : INIT : Free RAM:26520
5176 : Info   : INIT : Cold Boot - Restart Reason: Software/System restart
5177 : Info   : FS   : Mounting...
5203 : Info   : FS   : Mount successful, used 75802 bytes of 957314
5290 : Info   : FS   : Success garbage collection
5310 : Error  : CRC  : Settings CRC           ...FAIL
5312 : Info   : CRC  : SecuritySettings CRC   ...OK
5325 : Info   : INIT : I2C
5326 : Info   : INIT : SPI not enabled
5339 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK
5443 : Info   : WIFI : Set WiFi to STA
5546 : Info   : WiFi : Start network scan all channels
7730 : Info   : WiFi : Scan finished, found: 4
7733 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK
7733 : Info   : WiFi : Added known candidate, try to connect
7735 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK attempt #0
7736 : Info   : WIFI : Set to 802.11g
7820 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7822 : Info   : WiFi : WifiDisconnect()
7924 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 87 ms
8025 : Info   : Reset WiFi.
8027 : Info   : WiFi : Start network scan all channels
10210 : Info   : WiFi : Scan finished, found: 4
10213 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK
10214 : Info   : WiFi : Added known candidate, try to connect
10216 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK attempt #1
10223 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
11165 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 87 ms
11166 : Info   : WIFI : Set WiFi to OFF

Build changed!
11282 : Info   : SaveToFile: free stack: 3712
11358 : Info   : FILE : Saved config.dat offset: 0 size: 1316
11359 : Info   : SaveToFile: free stack after: 3712
11359 : Info   : Skip saving SecuritySettings, not changed
11371 : Info   : INIT : Free RAM:25912
11484 : Info   : INFO : Plugins: 47 [Normal] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
11485 : Error  : WiFi : Connecting not possible, unprocessed WiFi events:  disconn
11486 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
11489 : Info   : Webserver: start
11503 : Info   : WIFI : Disconnected! Reason: '(202) Auth fail' Connected for 951 ms
11604 : Info   : WiFi : WifiDisconnect()
11705 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 11 s
11806 : Info   : Reset WiFi.
11910 : Info   : WIFI : Set WiFi to STA
12013 : Info   : WiFi : Start network scan all channels
14198 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK
14199 : Info   : WiFi : Scan finished, found: 3
14201 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK
14202 : Info   : WiFi : Added known candidate, try to connect
14204 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK attempt #2
14211 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
14214 : Info   : WiFi : WifiDisconnect()
14316 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
14417 : Info   : Reset WiFi.
14420 : Info   : WiFi : Start network scan all channels
16604 : Info   : WiFi : Scan finished, found: 4
16607 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK
16608 : Info   : WiFi : Added known candidate, try to connect
16610 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK attempt #3
16617 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
17559 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
17561 : Info   : WIFI : Set WiFi to OFF
17775 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
17880 : Info   : WIFI : Set WiFi to STA
17984 : Info   : WiFi : Start network scan all channels
20168 : Info   : WiFi : Scan finished, found: 4
20171 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK
20171 : Info   : WiFi : Added known candidate, try to connect
20274 : Info   : WIFI : Set WiFi to AP+STA
21265 : Info   : WIFI : AP Mode ssid will be ESP-E-Arbeitszimmer with address 192.168.4.1
21373 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 18256 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
21432 : Info   : SI7013 : sn=74ced-32114854
21433 : Info   : P014: chip_id=50
21765 : Info   : P014: Temperature: 23.96 Humidity: 36.90
36616 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-66dBm) WPA2/PSK attempt #4
36624 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
39614 : Info   : WIFI : DHCP IP: 192.168.10.142 (ESP-E-Arbeitszimmer) GW: 192.168.10.254 SN: 255.255.255.0   duration: 1955 ms
39638 : Error  : NTP  : NTP host (192.168.1.254) unsynchronized
39642 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
39643 : Info   : UDP : Start listening on port 8266
39644 : Info   : firstLoopConnectionsEstablished
39649 : Info   : WIFI : Connected! AP: cybermcm (32:23:03:DE:13:70) Ch: 1 Duration: 1020 ms
40683 : Error  : MQTT : Intentional reconnect
40696 : Info   : MQTT : Connected to broker with client ID: ESP_E_Arbeitszimmer_0
40701 : Info   : Subscribed to: ESP_E_Arbeitszimmer/#
41739 : Info   : static_file: esp.css
41908 : Info   : static_file: favicon.ico
42836 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 16400 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
54496 : Info   : static_file: esp.css
54498 : Info   : Serve 304: 693705601 esp.css
62529 : Info   : static_file: esp.css
62531 : Info   : Serve 304: 693705601 esp.css
65181 : Info   : static_file: esp.css
65182 : Info   : Serve 304: 693705601 esp.css
72835 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 16376 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
99362 : Info   : NTP  : NTP replied: delay 11 mSec Accuracy increased by 0.453 seconds
99364 : Info   : Time set to 1668028377.453
99366 : Info   : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 0 min
99369 : Info   : Local time: 2022-11-09 21:12:57
102835 : Info   : WD   : Uptime 2 ConnectFailures 0 FreeMem 16376 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
120033 : Info   : static_file: favicon.ico
132837 : Info   : WD   : Uptime 2 ConnectFailures 0 FreeMem 16376 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
162837 : Info   : WD   : Uptime 3 ConnectFailures 0 FreeMem 16376 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
165198 : Info   : static_file: esp.css
165200 : Info   : Serve 304: 693705601 esp.css
192835 : Info   : WD   : Uptime 3 ConnectFailures 0 FreeMem 16296 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
203072 : Info   : static_file: esp.css
203074 : Info   : Serve 304: 693705601 esp.css
203259 : Info   : static_file: favicon.ico
222835 : Info   : WD   : Uptime 4 ConnectFailures 0 FreeMem 16248 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
252835 : Info   : WD   : Uptime 4 ConnectFailures 0 FreeMem 16248 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
282836 : Info   : WD   : Uptime 5 ConnectFailures 0 FreeMem 16248 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
312835 : Info   : WD   : Uptime 5 ConnectFailures 0 FreeMem 16248 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
321370 : Info   : WIFI : Set WiFi to STA
321476 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 4 m 43 s
321476 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: Conn. IP Init
321578 : Info   : WiFi : WifiDisconnect()
321679 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 5 m 21 s
321779 : Info   : Reset WiFi.
321781 : Info   : WiFi : Start network scan all channels
323965 : Info   : WiFi : Scan finished, found: 5
323968 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-65dBm) WPA2/PSK
323969 : Info   : WiFi : Added known candidate, try to connect
323970 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-65dBm) WPA2/PSK attempt #5
323979 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
323981 : Info   : WiFi : WifiDisconnect()
324082 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
324184 : Info   : Reset WiFi.
324186 : Info   : WiFi : Start network scan all channels
326370 : Info   : WiFi : Scan finished, found: 6
326373 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK
326374 : Info   : WiFi : Added known candidate, try to connect
326376 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK attempt #6
326383 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
327330 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
327331 : Info   : WIFI : Set WiFi to OFF
327546 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
327605 : Error  : MQTT : Connection lost, state: Connection lost
342845 : Info   : WD   : Uptime 6 ConnectFailures 0 FreeMem 17752 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
346485 : Info   : WIFI : Set WiFi to STA
346589 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-67dBm) WPA2/PSK attempt #7
346590 : Info   : WIFI : Set to 802.11n
346672 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
349646 : Info   : WIFI : DHCP IP: 192.168.10.142 (ESP-E-Arbeitszimmer) GW: 192.168.10.254 SN: 255.255.255.0   duration: 1960 ms
349652 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
349656 : Info   : WIFI : Connected! AP: cybermcm (32:23:03:DE:13:70) Ch: 1 Duration: 1083 ms
349765 : Error  : MQTT : Intentional reconnect
349787 : Info   : MQTT : Connected to broker with client ID: ESP_E_Arbeitszimmer_0
349791 : Info   : Subscribed to: ESP_E_Arbeitszimmer/#
372835 : Info   : WD   : Uptime 6 ConnectFailures 0 FreeMem 18144 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
402836 : Info   : WD   : Uptime 7 ConnectFailures 0 FreeMem 18144 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
432836 : Info   : WD   : Uptime 7 ConnectFailures 0 FreeMem 18144 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init

This doesn't happen with 20220809

ghtester commented 1 year ago

Yeah, here also the same issue with the fresh update to 20221109. So the SDK change did not help unfortunately. Only the plus is that the icon in browser tab is back... ;-)

TD-er commented 1 year ago

The "disconnect" after 5 minutes is to be expected. I do disable the AP mode after 5 minutes, as long as there is no client connected to it. When switching WiFi modes, I now clear the connection and reconnect. So this single disconnect is "perfectly fine".

ghtester commented 1 year ago

Do you have an idea what source changes from 20220829 to 20221031 could have brought this issue?

TD-er commented 1 year ago

Do you have an idea what source changes from 20220829 to 20221031 could have brought this issue?

+/- 2 months of debugging sounds like a plausible source...

ghtester commented 1 year ago

It looks the most easy fix would be to remove the Do Not Start AP: checkbox... ;-)

cybermcm commented 1 year ago

I tried to update another "faulty" module, it can't connect after an update to 20221109. Output attached. Reverting to 20220809 with same config -> all working again

¬U178 : Info   : WIFI : Set WiFi to AP+STA
4953 : Info   : WIFI : Set WiFi to OFF
5171 : Info   :

INIT : Booting version: ESP_Easy_mega_20221109_normal_ESP8266_4M1M, (GitHub Actions) HEAD_96ae578 (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
5171 : Info   : INIT : Free RAM:26520
5173 : Info   : INIT : Manual Reboot #2 Last Action before Reboot: Const Interval: TIMER_MQTT_DELAY_QUEUE Last systime: 335 - Restart Reason: External System
5174 : Info   : FS   : Mounting...
5200 : Info   : FS   : Mount successful, used 75802 bytes of 957314
5219 : Info   : CRC  : Settings CRC           ...OK
5223 : Info   : CRC  : SecuritySettings CRC   ...OK
5236 : Info   : INIT : I2C
5238 : Info   : INIT : SPI not enabled
5251 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-62dBm) WPA2/PSK
5356 : Info   : WIFI : Set WiFi to STA
5460 : Info   : WiFi : Start network scan all channels
7643 : Info   : WiFi : Scan finished, found: 2
7645 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK
7647 : Info   : WiFi : Added known candidate, try to connect
7648 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK attempt #0
7654 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
12021 : Info   : WiFi : WifiDisconnect()
12123 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 4373 ms
12124 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
12225 : Info   : Reset WiFi.
12227 : Info   : WiFi : Start network scan all channels
14410 : Info   : WiFi : Scan finished, found: 5
14413 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK
14414 : Info   : WiFi : Added known candidate, try to connect
14416 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK attempt #1
14423 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
18890 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
18892 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 4373 ms
18893 : Info   : WIFI : Set WiFi to OFF
19007 : Info   : INIT : Free RAM:25544
19093 : Info   : INFO : Plugins: 47 [Normal] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
19198 : Info   : WIFI : Set WiFi to STA
19303 : Info   : WiFi : Start network scan all channels
21488 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK
21489 : Info   : WiFi : Scan finished, found: 4
21491 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-62dBm) WPA2/PSK
21492 : Info   : WiFi : Added known candidate, try to connect
25957 : Info   : WIFI : Set WiFi to AP+STA
26949 : Info   : WIFI : AP Mode ssid will be ESP-E-Cat with address 192.168.4.1
26953 : Info   : Webserver: start
26993 : Info   : BMx280 : Detected BME280
28309 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 18112 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
29775 : Info   : BME280: dew point 6.20C
29802 : Info   : BME280 : Address: 0x76
29804 : Info   : BME280 : Temperature: 21.35
29806 : Info   : BME280 : Humidity: 37.48
29808 : Info   : BME280 : Barometric Pressure: 1000.77
34426 : Info   : WiFi : Start network scan all channels
36611 : Info   : WiFi : Scan finished, found: 4
36613 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-65dBm) WPA2/PSK
36614 : Info   : WiFi : Added known candidate, try to connect
36616 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-65dBm) WPA2/PSK attempt #2
36622 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
40990 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
58332 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
88338 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
118325 : Info   : WD   : Uptime 2 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
141004 : Info   : WiFi : Start network scan all channels
143187 : Info   : WiFi : Scan finished, found: 4
143190 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK
143191 : Info   : WiFi : Added known candidate, try to connect
143193 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-63dBm) WPA2/PSK attempt #3
143198 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
147565 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
148339 : Info   : WD   : Uptime 2 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
178338 : Info   : WD   : Uptime 3 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
208327 : Info   : WD   : Uptime 3 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
238314 : Info   : WD   : Uptime 4 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
247571 : Info   : WiFi : Start network scan all channels
249756 : Info   : WiFi : Scan finished, found: 4
249759 : Info   : WiFi : Best AP candidate: cybermcm 32:23:03:DE:13:70 Ch:1 (-64dBm) WPA2/PSK
249760 : Info   : WiFi : Added known candidate, try to connect
249762 : Info   : WIFI : Connecting cybermcm 32:23:03:DE:13:70 Ch:1 (-64dBm) WPA2/PSK attempt #4
249768 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
254136 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
268365 : Info   : WD   : Uptime 4 ConnectFailures 0 FreeMem 17792 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
TD-er commented 1 year ago

OK, so it seems like I may have changed some timings which made it "more compatible" with the 1903xx SDK and less "compatible" with the later SDK binary blobs.

I've also seen the same here on my test node on my desk. It no longer is able to make a stable connection with the 'default' SDK and when I flash the alt.wifi build, it works perfectly fine.

I'm now looking into options to erase the RFcal partition and the WiFi partition. Made also a "partition chart" for the ESP8266 builds, similar to what already was present on ESP32 builds: image

TD-er commented 1 year ago

See this PR: https://github.com/letscontrolit/ESPEasy/pull/4354

Could any of you flash one of the builds (either alt.WiFi, or the regular builds) which do perform badly with WiFi? I did add 2 commands, which can be executed via serial or rules (restricted commands, thus cannot be given from any source) to clear the RFcal partition or the SDK WiFi partition.

The commands are:

After giving these, it is best to reboot the node. Not sure if a power cycle instead of the warm reboot really makes a difference here.

Jason2866 commented 1 year ago

@TD-er Tasmota has a command to erase the wifi calib data too. A power cycle is needed to start the wifi calib process and using the new values. Just erasing does mean the current values are still used.

TD-er commented 1 year ago

Thanks @Jason2866 Does Tasmota erase both partitions (Noticed there is a function for that in the ESP class) or only the RFcal sector?

Jason2866 commented 1 year ago

It is here https://github.com/arendst/Tasmota/blob/development/tasmota/tasmota_support/support_esp.ino#L256-L293

cybermcm commented 1 year ago

@TD-er tried normal 20221111 build -> no luck -> still no connection. Tried command ClearSdkWifi -> worked command ClearWifiRFcal -> command unknown? did power cylce

tonhuisman commented 1 year ago

That might be a typo in the source...: https://github.com/letscontrolit/ESPEasy/pull/4354/files#diff-0c0d79067d2a3b128344094f5387f9708c268f35cdb99d1b865d4e74ae3dfa75R280

TD-er commented 1 year ago

Yep, made a typo, so with this build you may need to use clearwifirfcall (with 2x l) For any next build, it should be according to the documentation.

TD-er commented 1 year ago

It is here https://github.com/arendst/Tasmota/blob/development/tasmota/tasmota_support/support_esp.ino#L256-L293

That looks like ESP32 code.

I meant the ESP8266 code in bool EspClass::eraseConfig(void)

@Jason2866 Can you send me an email, so we can discuss some other idea I have?