Very long time connecting to WiFi

Moderators: grovkillen, Stuntteam, TD-er

Message
Author
skwaruch
New user
Posts: 8
Joined: 03 Jan 2020, 14:08

Very long time connecting to WiFi

#1 Post by skwaruch » 19 Nov 2022, 19:06

I have an ESP8266 with ESP_Easy_mega_20211005_test_A_ESP8266_4M1M and it connects to WiFi in about 4s.
On another ESP8266 I uploaded ESP_Easy_mega_20221119_climate_ESP8266_4M1M and it connects over 30s.
What could be causing such a long connection time?

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#2 Post by TD-er » 19 Nov 2022, 19:09

Can you see what it shows on the serial logs?

chemmex
Normal user
Posts: 92
Joined: 15 Feb 2019, 16:18

Re: Very long time connecting to WiFi

#3 Post by chemmex » 19 Nov 2022, 23:34

When testing external RTC around 10 November, I noticed that ESP8266 made 3 attempts to connect to the same AP of which only third was successful. It even started AP mode in between attempts.

Code: Select all

INIT : Booting version: ESP_Easy_mega_20221108_custom_ESP8266_4M1M, (Self built) 20221108TZ_noDebug (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
5267 : Info   : INIT : Free RAM:25688
5268 : Info   : INIT : Cold Boot - Restart Reason: Power On
5269 : Info   : FS   : Mounting...
5295 : Info   : FS   : Mount successful, used 85591 bytes of 957314
5310 : Info   : CRC  : Settings CRC           ...OK
5313 : Info   : CRC  : SecuritySettings CRC   ...OK
5316 : Info   : INIT : I2C
5318 : Info   : INIT : SPI not enabled
5319 : Error  : ExtRTC: Cannot get time from external time source
5424 : Info   : WIFI : Set WiFi to STA
7724 : Info   : WIFI : Connecting xxxx  (-55dBm) WPA2/PSK attempt #0
7907 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 81 ms
8008 : Info   : Reset WiFi.
10209 : Info   : WIFI : Connecting xxxx (-57dBm) WPA2/PSK attempt #1
11159 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 81 ms
11159 : Info   : WIFI : Set WiFi to OFF
11272 : Info   : INIT : Free RAM:24136
11364 : Info   : INFO : Plugins: 14 [No Debug Log] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
11365 : Info   : EVENT: System#Wake
11508 : Info   : Webserver: start
11509 : Info   : EVENT: System#Boot
15288 : Info   : ExtRTC: Read external time source: 1667914925
15288 : Info   : Time set to 1667914925.000
15290 : Info   : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 180 min
15293 : Info   : Local time: 2022-11-08 16:42:05
15307 : Info   : EVENT: WiFi#Disconnected
15381 : Info   : EVENT: Clock#Time=Tue,16:42
15400 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 13848 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
15478 : Info   : EVENT: WiFi#Disconnected
15497 : Info   : EVENT: WiFi#APmodeEnabled
15538 : Info   : EVENT: Time#Initialized
20212 : Info   : WIFI : Connecting xxx (-51dBm) WPA2/PSK attempt #2
21612 : Info   : WIFI : DHCP IP: 192.168.10.229 (ESPEasy) GW: 192.168.10.129 SN: 255.255.255.128   duration: 296 ms
21614 : Info   : firstLoopConnectionsEstablished
21616 : Info   : WIFI : Connected! AP: xxxx Ch: 9 Duration: 1090 ms
21618 : Info   : EVENT: WiFi#Connected
21631 : Info   : EVENT: WiFi#ChangedAccesspoint
21641 : Info   : EVENT: WiFi#ChangedWiFichannel
21721 : Error  : MQTT : Intentional reconnect
21777 : Info   : MQTT : Connected to broker with client ID: ESPEasy
21780 : Info   : Subscribed to: ESPEasy/#
21785 : Info   : EVENT: MQTT#Connected

skwaruch
New user
Posts: 8
Joined: 03 Jan 2020, 14:08

Re: Very long time connecting to WiFi

#4 Post by skwaruch » 20 Nov 2022, 13:47

Code: Select all

INIT : Booting version: ESP_Easy_mega_20221105_climate_ESP8266_4M1M, (GitHub Actions) mega-20221105 (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
4949 : Info   : INIT : Free RAM:25664
4951 : Info   : INIT : Manual Reboot #25 Last Action before Reboot: Background Task Last systime: 176 - Restart Reason: External System
4952 : Info   : FS   : Mounting...
4978 : Info   : FS   : Mount successful, used 75802 bytes of 957314
5071 : Info   : FS   : Success garbage collection
5166 : Info   : FS   : Success garbage collection
5261 : Info   : FS   : Success garbage collection
5265 : Info   : CRC  : Settings CRC           ...OK
5278 : Info   : CRC  : SecuritySettings CRC   ...OK
5280 : Info   : INIT : I2C
5281 : Info   : INIT : SPI not enabled
5283 : Info   : WiFi : Best AP candidate: Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-60dBm) WPA2/PSK
5387 : Info   : WIFI : Set WiFi to STA
5491 : Info   : WiFi : Start network scan all channels
7676 : Info   : WiFi : Scan finished, found: 6
7679 : Info   : WiFi : Best AP candidate: Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-64dBm) WPA2/PSK
7680 : Info   : WiFi : Added known candidate, try to connect
7682 : Info   : WIFI : Connecting Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-64dBm) WPA2/PSK attempt #0
7689 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7692 : Info   : WiFi : WifiDisconnect()
7794 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
7895 : Info   : Reset WiFi.
7897 : Info   : WiFi : Start network scan all channels
10087 : Info   : WiFi : Scan finished, found: 9
10090 : Info   : WiFi : Best AP candidate: Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-65dBm) WPA2/PSK
10091 : Info   : WiFi : Added known candidate, try to connect
10092 : Info   : WIFI : Connecting Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-65dBm) WPA2/PSK attempt #1
10100 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
11043 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
11045 : Info   : WIFI : Set WiFi to OFF
11159 : Info   : INIT : Free RAM:23472
11167 : Info   : PMSx003 : using software serial
11179 : Info   : PMSx003: Wake sensor
11279 : Info   : INFO : Plugins: 47 [Climate] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
11280 : Info   : EVENT: System#Wake
11367 : Error  : WiFi : Connecting not possible, unprocessed WiFi events:  disconn
11368 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
11371 : Info   : Webserver: start
11372 : Info   : EVENT: System#Boot
11375 : Info   : WIFI : Disconnected! Reason: '(202) Auth fail' Connected for 953 ms
11580 : Info   : WIFI : Set WiFi to STA
11684 : Info   : WiFi : Start network scan all channels
13875 : Info   : WiFi : Best AP candidate: Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-65dBm) WPA2/PSK
13876 : Info   : WiFi : Scan finished, found: 6
13878 : Info   : WiFi : Best AP candidate: Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-64dBm) WPA2/PSK
13879 : Info   : WiFi : Added known candidate, try to connect
13981 : Info   : WIFI : Set WiFi to AP+STA
14974 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1
14986 : Info   : EVENT: WiFi#Disconnected
15043 : Info   : SHT3x: Temperature: nan
15045 : Info   : SHT3x: Humidity: nan
15063 : Info   : EVENT: TaskInit#Dust=1,1
15084 : Info   : ADC  : Analog value: 944 = 4.798
15105 : Info   : Dummy: value 1: 0.0
15181 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 14136 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
15233 : Info   : ADC  : Analog value: 944 = 4.798
15253 : Info   : EVENT: TaskInit#BME280=2,1
15279 : Info   : EVENT: TaskInit#Voltage=3,1
15291 : Info   : EVENT: TaskInit#dew_point=4,1
15304 : Info   : EVENT: WiFi#Disconnected
15329 : Info   : EVENT: WiFi#APmodeEnabled
15355 : Info   : EVENT: BME280#Temperature=nan
15371 : Info   : SHT3x: Temperature: nan
15372 : Info   : SHT3x: Humidity: nan
15394 : Info   : EVENT: BME280#Humidity=nan
15406 : Info   : EVENT: Voltage#Analog=4.798
15418 : Info   : EVENT: dew_point#DewPoint=0.0
15444 : Info   : EVENT: Voltage#Analog=4.798
15457 : Info   : EVENT: BME280#Temperature=nan
15468 : Info   : EVENT: BME280#Humidity=nan
16431 : Info   : Dummy: value 1: 0.0
16464 : Info   : EVENT: dew_point#DewPoint=0.0
17392 : Info   : ADC  : Analog value: 944 = 4.798
17413 : Info   : EVENT: Voltage#Analog=4.798
19361 : Info   : SHT3x: Temperature: nan
19363 : Info   : SHT3x: Humidity: nan
19385 : Info   : EVENT: BME280#Temperature=nan
19398 : Info   : EVENT: BME280#Humidity=nan
20395 : Info   : ADC  : Analog value: 944 = 4.798
20416 : Info   : EVENT: Voltage#Analog=4.798
21427 : Info   : Dummy: value 1: 0.0
21460 : Info   : EVENT: dew_point#DewPoint=0.0
23358 : Info   : SHT3x: Temperature: nan
23360 : Info   : SHT3x: Humidity: nan
23381 : Info   : EVENT: BME280#Temperature=nan
23397 : Info   : ADC  : Analog value: 944 = 4.798
23417 : Info   : EVENT: BME280#Humidity=nan
23443 : Info   : EVENT: Voltage#Analog=4.798
26394 : Info   : ADC  : Analog value: 944 = 4.798
26412 : Info   : EVENT: Voltage#Analog=4.798
26438 : Info   : Dummy: value 1: 0.0
26472 : Info   : EVENT: dew_point#DewPoint=0.0
27365 : Info   : SHT3x: Temperature: nan
27367 : Info   : SHT3x: Humidity: nan
27388 : Info   : EVENT: BME280#Temperature=nan
27402 : Info   : EVENT: BME280#Humidity=nan
29394 : Info   : ADC  : Analog value: 944 = 4.798
29415 : Info   : EVENT: Voltage#Analog=4.798
30101 : Info   : WIFI : Connecting Gargoyle 62:38:E0:DA:41:F7 Ch:13 (-64dBm) WPA2/PSK attempt #2
30108 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
31405 : Info   : SHT3x: Temperature: nan
31407 : Info   : SHT3x: Humidity: nan
31438 : Info   : EVENT: BME280#Temperature=nan
31463 : Info   : Dummy: value 1: 0.0
31516 : Info   : EVENT: BME280#Humidity=nan
31560 : Info   : EVENT: dew_point#DewPoint=0.0
32418 : Info   : ADC  : Analog value: 944 = 4.798
32448 : Info   : EVENT: Voltage#Analog=4.798
34067 : Info   : WIFI : DHCP IP: 192.168.2.13 (ESP-Easy) GW: 192.168.2.1 SN: 255.255.255.0   duration: 1976 ms
34069 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
34070 : Info   : firstLoopConnectionsEstablished
34074 : Info   : EVENT: WiFi#Connected
34076 : Info   : WIFI : Connected! AP: Gargoyle (62:38:E0:DA:41:F7) Ch: 13 Duration: 1985 ms
34078 : Info   : EVENT: WiFi#ChangedAccesspoint
34079 : Info   : EVENT: WiFi#ChangedWiFichannel

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#5 Post by TD-er » 20 Nov 2022, 21:05

It is very strange to see the ESP does apparently need to set its AP mode before the units can connect.
I've seen it happen also on some of my ESP8266 boards (not all of them)

Have to look into the code to see why this may happen.

dido8884
New user
Posts: 3
Joined: 23 Nov 2022, 18:29

Re: Very long time connecting to WiFi

#6 Post by dido8884 » 27 Nov 2022, 20:12

I had two modules that I configured in a different place, there was a different access point. At the new location, they did not want to work normally, one was always in access point mode, even after setting up. The second did not see the access point at all. It helped me when I reset the wifi settings to default (factory reset)

rige
New user
Posts: 5
Joined: 23 Dec 2022, 23:13

Re: Very long time connecting to WiFi

#7 Post by rige » 24 Dec 2022, 00:18

I observe similar strange behavior with mega-20221105 - long connection (approx 30 seconds or not at all - even after an hour) - tested 3 devices (ESP8266 and ESP32).
Signal strength around -60 to -70 dBm - I would say probability of working connection increased with stronger signal level.

Then I tried previous release mega-20220809 and all devices work well.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#8 Post by TD-er » 24 Dec 2022, 00:38

As I mentioned in the other topic you replied to, please test one of the latest GitHub Actions builds as I really hope this has been fixed.
Please let me know the results as I plan om making a new build tomorrow.

skwaruch
New user
Posts: 8
Joined: 03 Jan 2020, 14:08

Re: Very long time connecting to WiFi

#9 Post by skwaruch » 08 Jan 2023, 15:45

It's definitely better on 20221224 but still 2x slower than some earlier versions

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#10 Post by TD-er » 09 Jan 2023, 00:22

skwaruch wrote: 08 Jan 2023, 15:45 It's definitely better on 20221224 but still 2x slower than some earlier versions
That's on purpose, to make sure those units with poor power supplies and flaky board designs (<kuch> Sonoff Basic </>) to be able to connect to WiFi.

chemmex
Normal user
Posts: 92
Joined: 15 Feb 2019, 16:18

Re: Very long time connecting to WiFi

#11 Post by chemmex » 09 Jan 2023, 19:30

TD-er wrote: 09 Jan 2023, 00:22 That's on purpose, to make sure those units with poor power supplies and flaky board designs (<kuch> Sonoff Basic </>) to be able to connect to WiFi.
Maybe make it a build-time option? To preserve some power for sleep mode devices?

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#12 Post by TD-er » 09 Jan 2023, 20:08

There's a lot of changes coming regarding low-power deepsleep mode.

And I'm also looking into why apparently reconnecting to the last known AP as stored in RTC is no longer working. (was reported a few days ago by another user)

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#13 Post by chromo23 » 18 Jan 2023, 15:49

TD-er wrote: 09 Jan 2023, 20:08 And I'm also looking into why apparently reconnecting to the last known AP as stored in RTC is no longer working. (was reported a few days ago by another user)
Hey Td-er, is there any progress with this issue?
I just made an update of my "Wifi-Button" with the latest build. (Unfortunately i forgot to write down the build number of the old build :shock: )
Sending a command went from 2sec straight up to 12sec.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#14 Post by TD-er » 18 Jan 2023, 15:57

chromo23 wrote: 18 Jan 2023, 15:49 [...]
Sending a command went from 2sec straight up to 12sec.
Can you be a bit more specific as in what kind of command?

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#15 Post by chromo23 » 18 Jan 2023, 16:03

My button does a sendtohttp command to switch on a light.
This is my rule where i also determined the time until wifi becomes available:
(PostToHTTP is pretty useful for this :) )

Code: Select all

On System#Wake Do
  Let,1,%uptime_ms%     
Endon

On WiFi#Connected Do
 Let,2,%uptime_ms%-[var#1]
 PostToHTTP ntfy.sh,80,test**?title=%sysname%,,Uptime=%uptime_ms%_Uptime2=[var#2]
 SendToHTTP,192.168.1.96,80,/control?cmd=event,toggle
Endon
Settings are all standard (except "Use Last Connected AP from RTC" enabled of course)

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#16 Post by TD-er » 18 Jan 2023, 16:12

So the ESP needs to power on and boot and then send out the command?

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#17 Post by chromo23 » 18 Jan 2023, 16:13

It sleeps until the button is pressed and goes back to sleep again...
Edit: it is a battery powered device with is working fine since two years.. the button does rst to gnd
Edit2: what i didn’t try is a factory reset but i'm doing it right now
Edit§: factory reset didn’t help....

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#18 Post by TD-er » 18 Jan 2023, 16:31

I don't think I have time this week, but let's try to have this looked at beginning of next week.
At least the "quick connect from RTC" should work.
So this checkbox could also function as a "don't mind the higher power surge at boot, gimme WiFi!!!!111oneoneeleven"

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#19 Post by chromo23 » 18 Jan 2023, 16:38

TD-er wrote: 18 Jan 2023, 16:31 I don't think I have time this week, but let's try to have this looked at beginning of next week.
Thank you, but no rush... it is definitely not urgent. I will try to find the old build and move back to it.
TD-er wrote: 18 Jan 2023, 16:31 At least the "quick connect from RTC" should work.
Do you mean "Use Last Connected AP from RTC" with this?
TD-er wrote: 18 Jan 2023, 16:31 So this checkbox could also function as a "don't mind the higher power surge at boot, gimme WiFi!!!!111oneoneeleven"
If it helps. :)

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#20 Post by chromo23 » 18 Jan 2023, 16:47

FIY:
I went back to:
ESP_Easy_mega_20211224_normal_ESP8266_4M1M
and light went on in after 3secs after i pressed the button..

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#21 Post by TD-er » 18 Jan 2023, 16:50

So I only need to track back over 1 year of commits....

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#22 Post by chromo23 » 18 Jan 2023, 17:01

TD-er wrote: 18 Jan 2023, 16:50 So I only need to track back over 1 year of commits....
If it helps, i am willing to find the latest "working" build for you..

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#23 Post by TD-er » 18 Jan 2023, 17:04

I got some idea... probably when I started tinkering with the WiFI code again to get those nasty Sonoff devices to connect.

User avatar
dynamicdave
Normal user
Posts: 257
Joined: 30 Jan 2017, 20:25
Location: Hampshire, UK

Re: Very long time connecting to WiFi

#24 Post by dynamicdave » 18 Jan 2023, 17:07

I've encountered the same problem (long time to connect to WiFi) on the last two releases on a Wemos D1 Mini.

The last release that gave an acceptable connect time for me was... Mega_20220809_normal_ESP8266_4M1M.bin

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#25 Post by TD-er » 18 Jan 2023, 17:13

Just did a test with the latest code here on a Wemos unit and it needed 6 seconds since boot to be connected and have the web interface accessible + got reply from NTP server.

Code: Select all

4855 : Info   : WIFI : Set WiFi to OFF
5072 : Info   :

INIT : Booting version: ESP_Easy_mega_20230118_custom_ESP8266_4M1M, (Self built) feature/esp-now-controller_a4373be (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
5073 : Info   : INIT : Free RAM:24832
5075 : Info   : INIT : Manual Reboot #3 Last Action before Reboot: Background Task Last systime: 1674058362 - Restart Reason: External System
5076 : Info   : FS   : Mounting...
5101 : Info   : FS   : Mount successful, used 76053 bytes of 957314
5122 : Info   : CRC  : Settings CRC           ...OK
5126 : Error  : CRC  : SecuritySettings CRC   ...FAIL
5166 : Info   : INIT : SPI not enabled
5179 : Info   : INIT : Free RAM:22584
5205 : Info   : INFO : Plugins: 20  (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
5206 : Info   : EVENT: System#Wake
5417 : Info   : WIFI : Set WiFi to STA
5522 : Info   : WiFi : Best AP candidate: Lurch4 CC:CE:1E:13:B7:58 Ch:1 (-46dBm) WPA2/PSK
5523 : Info   : WIFI : Connecting Lurch4 CC:CE:1E:13:B7:58 Ch:1 (-46dBm) WPA2/PSK attempt #0
5524 : Info   : Set Network mode: WiFi
5532 : Info   : Webserver: start
5544 : Info   : EVENT: System#Boot
5566 : Info   : EVENT: WiFi#APmodeDisabled
6472 : Info   : EVENT: TaskInit#temp=1,1
6555 : Info   : WIFI : DHCP IP: 192.168.10.153 (ESP-Easy-10) GW: 192.168.10.1 SN: 255.255.255.0 DNS: 192.168.10.1 / (IP unset)   duration: 15 ms
6581 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
6596 : Info   : EVENT: WiFi#Connected
6623 : Info   : UDP : Start listening on port 8266
6623 : Info   : firstLoopConnectionsEstablished
6728 : Info   : NTP  : NTP replied: delay 91 mSec Accuracy increased by 0.992 seconds
6729 : Info   : Time set to 1674058432.992
6731 : Info   : Current Time Zone:  DST time start: 2023-03-26 02:00:00 offset: 120 min STD time start: 2023-10-29 03:00:00 offset: 60 min

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#26 Post by chromo23 » 18 Jan 2023, 17:53

TD-er wrote: 18 Jan 2023, 17:13 ust did a test with the latest code here on a Wemos unit and it needed 6 seconds since boot to be connected and have the web interface accessible + got reply from NTP server.
Not bad. How did you do it? (edit: but far from good :))
I tried now with two different wemos boards, latest normal 4m1m build from main repo.
I tried combinations of Power cycle and reset button with "Use Last Connected AP from RTC" enabled and disabled. I always get around 12secs. :(

This i get from the old build with normal boot:

Code: Select all

1737: WD : Uptime 0 ConnectFailures 0 FreeMem 20304 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
2394: WiFi : Scan finished, found: 7
2397: WiFi : Best AP candidate: ***  Ch:6 (-55dBm) WPA2/PSK
2398: WIFI : Connecting ***  Ch:6 (-55dBm) WPA2/PSK attempt #0
2404: WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
3398: WIFI : Connected! AP: *** Ch: 6 Duration: 974 ms
3495: EVENT: WiFi#ChangedAccesspoint
3523: WIFI : DHCP IP: 192.168.1.202 (bigbutton) GW: 192.168.1.1 SN: 255.255.255.0 duration: 141 ms
3524: WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP
3527: UDP : Start listening on port 8266
3527: firstLoopConnectionsEstablished
3585: EVENT: WiFi#ChangedWiFichannel
3685: EVENT: WiFi#Connected
Since in the old build as well as in the new ones it doesn’t seem to matter if "Use Last Connected AP from RTC" is enabled or not in terms of connection speed... what is it good for? :o

User avatar
dynamicdave
Normal user
Posts: 257
Joined: 30 Jan 2017, 20:25
Location: Hampshire, UK

Re: Very long time connecting to WiFi

#27 Post by dynamicdave » 07 Mar 2023, 08:50

Just flashed ESP_Easy_mega_20230306_normal_ESP8266_4M1M onto a Wemos D1 Mini (that I've been using for a year or two with various releases of ESPeasy).
It takes nearly 15-seconds from pressing the Tools > Reboot option to when the blue LED comes on.

Are there any specific options I should be using with this release?

The last release that gave an acceptable connect time for me was... Mega_20220809_normal_ESP8266_4M1M.bin

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#28 Post by TD-er » 07 Mar 2023, 08:54

Hmm, I got the impression the reconnect from RTC was working again...
I will look into this.
I haven't tested it the last few weeks on ESP8266 a lot, so maybe I missed something here.
I mainly tested stability on the latest ESP8266 SDK3.x ("beta" builds) and not the older SDK.

User avatar
dynamicdave
Normal user
Posts: 257
Joined: 30 Jan 2017, 20:25
Location: Hampshire, UK

Re: Very long time connecting to WiFi

#29 Post by dynamicdave » 07 Mar 2023, 09:10

I mainly tested stability on the latest ESP8266 SDK3.x ("beta" builds) and not the older SDK.
Where do I find that version?

The sequence I performed was... I downloaded ESPEasy_mega_20230306_ESP82xx_binaries.zip from the website, then unzipped it and used ESP_Easy_mega_20230306_normal_ESP8266_4M1M to flash the Wemos D1.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#30 Post by TD-er » 07 Mar 2023, 09:34

I guess the "normal_beta_ESP8266_4M1M" build in the ZIP file.
But the latest SDK was mainly tested on stability and not really on time it takes to connect.

User avatar
dynamicdave
Normal user
Posts: 257
Joined: 30 Jan 2017, 20:25
Location: Hampshire, UK

Re: Very long time connecting to WiFi

#31 Post by dynamicdave » 07 Mar 2023, 10:40

Just tried... normal_beta_ESP8266_4M1M
It takes the same length of time (approx 15s) to boot-up/connect.

User avatar
Ath
Normal user
Posts: 3416
Joined: 10 Jun 2018, 12:06
Location: NL

Re: Very long time connecting to WiFi

#32 Post by Ath » 07 Mar 2023, 10:45

Have you tried enabling the "Use Last Connected AP from RTC" option (last one on the Tools/Advanced page)? That should speed things up.
/Ton (PayPal.me)

User avatar
dynamicdave
Normal user
Posts: 257
Joined: 30 Jan 2017, 20:25
Location: Hampshire, UK

Re: Very long time connecting to WiFi

#33 Post by dynamicdave » 07 Mar 2023, 12:22

Just tried that option - no difference in boot time.
It will be interesting to see if my friend in Boston, USA (who also uses Wemos D1 devices) encounters the same boot-up time.

If I revert to Mega_20220809_normal_ESP8266_4M1M.bin, the boot time is 5secs

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#34 Post by TD-er » 08 Mar 2023, 16:08

When the GH Actions build is done, can you test this build: https://github.com/letscontrolit/ESPEas ... 4365615113

N.B. the commit I merged this morning also broke the entire WiFi connect process, so I had to immediately look into this.
So as soon as this PR is successfully built, I will merge it.

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#35 Post by chromo23 » 08 Mar 2023, 17:16

Since i have the same issues:
TD-er wrote: 08 Mar 2023, 16:08 can you test this build: https://github.com/letscontrolit/ESPEas ... 4365615113
It is faster! 4,5-7sec until WiFi is connected (I did several reboots for testing)

What i don´t understand is:

It seems, that channel scanning takes a long time.
Two questions regarding this:
1. Why is there a need of scanning at all when "Use Last Connected AP from RTC" is enabled?
2. Why is this scan happening two times

Code: Select all

931 : Info   : WiFi : Start network scan all channels  
3118 : Info   : WiFi : Scan finished, found: 20
3126 : Info   : INIT : Free RAM:24040
3203 : Info   : INFO : Plugins: 47 [Normal] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
3205 : Info   : EVENT: System#Wake
3299 : Info   : WiFi : Start network scan all channels
5487 : Info   : WiFi : Scan finished, found: 27
EDIT:
Ok, double scan of channels seemed to be an exception since it doesn’t happen anymore
Last edited by chromo23 on 08 Mar 2023, 17:33, edited 1 time in total.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#36 Post by TD-er » 08 Mar 2023, 17:30

chromo23 wrote: 08 Mar 2023, 17:16 [...]
It seems, that channel scanning takes a long time.
Two questions regarding this:
1. Why is there a need of scanning at all when "Use Last Connected AP from RTC" is enabled?
2. Why is this scan happening two times
[...]
It shouldn't.
I did test it here and it was reconnected on my node within 2.3 sec after boot, without rescan.

This is a reboot with scan:

Code: Select all

274 : Info   : WIFI : Set WiFi to OFF
491 : Info   :

INIT : Booting version: ESP_Easy_mega_20230308_climate_ESP8266_4M1M, (Self built) bugfix/WiFi_Connect_speed_84bcc5c (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
492 : Info   : INIT : Free RAM:27064
494 : Info   : INIT : Manual Reboot #30 Last Action before Reboot: Background Task Last systime: 1678292654 - Restart Reason: External System
495 : Info   : FS   : Mounting...
521 : Info   : FS   : Mount successful, used 75802 bytes of 957314
540 : Info   : CRC  : Settings CRC           ...OK
543 : Info   : CRC  : SecuritySettings CRC   ...OK
546 : Info   : INIT : I2C
548 : Info   : INIT : SPI not enabled
549 : Info   : Time : Set Ext. Time Source: RTC at boot time: 1678292654
551 : Info   : Time set to 1678292654.000
553 : Info   : Current Time Zone: STD time start: 2023-10-29 03:00:00 offset: 0 min
556 : Info   : Local time: 2023-03-08 16:24:14
558 : Info   : Set Network mode: WiFi
663 : Info   : WIFI : Set WiFi to STA
817 : Info   : WiFi : Start network scan all channels
3003 : Info   : WiFi : Scan finished, found: 11
3007 : Info   : WiFi : Best AP candidate: Lurch4 CC:CE:1E:13:B7:58 Ch:1 (-44dBm) WPA2/PSK n
3008 : Info   : WiFi : Added known candidate, try to connect
3021 : Info   : INIT : Free RAM:23952
3104 : Info   : INFO : Plugins: 48 [Climate] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
3107 : Info   : WiFi : Best AP candidate: Lurch4 CC:CE:1E:13:B7:58 Ch:1 (-44dBm) WPA2/PSK n
3109 : Info   : WIFI : Connecting Lurch4 CC:CE:1E:13:B7:58 Ch:1 (-44dBm) WPA2/PSK n attempt #0
3117 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
3120 : Info   : Webserver: start
4147 : Info   : WIFI : DHCP IP: 192.168.10.153 (ESP-Easy) GW: 192.168.10.1 SN: 255.255.255.0 DNS: 192.168.10.1 / (IP unset)   duration: 27 ms
4161 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
4210 : Info   : firstLoopConnectionsEstablished
4216 : Info   : WIFI : Connected! AP: Lurch4 (CC:CE:1E:13:B7:58) Ch: 1 Duration: 993 ms
4218 : Info   : UDP : Start listening on port 8266

However, the RTC stored value will only be used if it was considered "stable" (> 5 mins connected)

I don't know why it is scanning twice.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#37 Post by TD-er » 08 Mar 2023, 17:34

Ah, I think I know why it might scan twice.

If in the first scan no known AP was found, it will scan again, without throwing away the previous scan results.
So it will then have the combination of both scans as possible candidates to pick from.

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#38 Post by chromo23 » 08 Mar 2023, 17:35

TD-er wrote: 08 Mar 2023, 17:30 I don't know why it is scanning twice.
chromo23 wrote: 08 Mar 2023, 17:16 EDIT:
Ok, double scan of channels seemed to be an exception since it doesn’t happen anymore
:)
TD-er wrote: 08 Mar 2023, 17:30 However, the RTC stored value will only be used if it was considered "stable" (> 5 mins connected)
Ahhh.. 5 minutes is the magic number. Thanks! I´ll give it a try...

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#39 Post by TD-er » 08 Mar 2023, 17:42

chromo23 wrote: 08 Mar 2023, 17:35 [...]
Ahhh.. 5 minutes is the magic number. Thanks! I´ll give it a try...
It may not be this magic number, as there are code paths where this RTC is being cleared while not needed.
And I looked into the code, the RTC is now set whenever the connected event is being processed.
It used to be this 5 minutes... but apparently not anymore.

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#40 Post by chromo23 » 08 Mar 2023, 17:53

This whole RTC thing is actually only important for me when i use it for battery powered devices that are most of the time in sleep mode. Right now i get 7 months from an 1400mAh battery while being awake for around 5 seconds every half an hour.
(sending bme280 data to thingspeak)

So it seems i should run such a device initially a while until RTC is set?

I did further testing and you are right...2,5 seconds i got but after a second reboot ESPeasy was already scanning channels again.
I might be something i can not rely on?

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#41 Post by chromo23 » 08 Mar 2023, 17:59

Testing sleep mode gives the same results..
The first wake it takes 2 seconds and every following scan >4 seconds because of channel scanning

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#42 Post by TD-er » 08 Mar 2023, 18:05

The RTC is being cleared in quite a lot of occasions.
Maybe a bit too often.

I'm thinking of other ways we can reduce the connection time.
One way can be to store the BSSID/channel in the settings, or maybe have a preferred channel to try first as I can also scan per channel.

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#43 Post by chromo23 » 08 Mar 2023, 18:09

TD-er wrote: 08 Mar 2023, 18:05 The RTC is being cleared in quite a lot of occasions.
Maybe a bit too often.
If it is working only under rare conditions and it than only works one time, it raises the question what it is good for anyway and if we really need it? :)

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#44 Post by chromo23 » 08 Mar 2023, 18:56

TD-er wrote: 08 Mar 2023, 18:05 One way can be to store the BSSID/channel in the settings,
For me personally, this would be great since i only use fixed channels...

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#45 Post by TD-er » 08 Mar 2023, 19:33

Is this better?

Code: Select all

392 : Info   : WIFI : Set WiFi to OFF
610 : Info   :

INIT : Booting version: ESP_Easy_mega_20230308_climate_ESP8266_4M1M, (Self built) bugfix/WiFi_Connect_speed_84bcc5c (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
611 : Info   : INIT : Free RAM:27064
612 : Info   : INIT : Soft Reboot #50 Last Action before Reboot: Intended Reboot: CommandReboot Last systime: 1678300331 - Restart Reason: Software/System restart
614 : Info   : FS   : Mounting...
639 : Info   : FS   : Mount successful, used 75802 bytes of 957314
659 : Info   : CRC  : Settings CRC           ...OK
688 : Info   : CRC  : SecuritySettings CRC   ...OK
702 : Info   : INIT : I2C
703 : Info   : INIT : SPI not enabled
704 : Info   : Set Network mode: WiFi
808 : Info   : WIFI : Set WiFi to STA
912 : Info   : INIT : Free RAM:24832
991 : Info   : INFO : Plugins: 48 [Climate] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
994 : Info   : WIFI : Connecting Lurch4 CC:CE:1E:13:B7:58 Ch:1 (0dBm) - attempt #0
1003 : Info   : Webserver: start
2082 : Info   : WIFI : DHCP IP: 192.168.10.153 (ESP-Easy) GW: 192.168.10.1 SN: 255.255.255.0 DNS: 192.168.10.1 / (IP unset)   duration: 24 ms
2098 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP
2151 : Info   : WIFI : Connected! AP: Lurch4 (CC:CE:1E:13:B7:58) Ch: 1 Duration: 1047 ms

User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#46 Post by chromo23 » 08 Mar 2023, 19:42

If this would happen on every start then definitely yes!!! :)

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#47 Post by TD-er » 08 Mar 2023, 20:17

chromo23 wrote: 08 Mar 2023, 19:42 If this would happen on every start then definitely yes!!! :)
On every start without power loss.

I will later add a preferred WiFi channel, which can then be scanned first as single channel.
If this is enough, it will take roughly 150 msec for 1 channel to scan.

I also would like to try to always scan the channel, even if the info is present from RTC. I played a bit with it and I got the impression the connect itself may even speed up from this, but have to do some more tests as it may have been a fluke.

I've even seen the connected log + IP being reported at 1500 msec from boot, so there is still some room for improvement.
However, there is always the risk we may put too much stress on the node, causing poor quality ones to fail.

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: Very long time connecting to WiFi

#48 Post by TD-er » 08 Mar 2023, 20:25

It also does seem to work on ESP32 :)

Code: Select all

138 : Info   : 

INIT : Booting version: ESP_Easy_mega_20230308_normal_ESP32_4M316k, (Self built) bugfix/WiFi_Connect_speed_8a62b24 (ESP32 SDK 4.4.3.20230129)
139 : Info   : INIT : Free RAM:279760
141 : Info   : INIT : Soft Reboot #1 Last Action before Reboot: Intended Reboot: CommandReboot Last systime: 1678303465 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
142 : Info   : FS   : Mounting...
166 : Info   : FS   : Mount successful, used 138301 bytes of 290156
183 : Info   : CRC  : Settings CRC           ...OK
198 : Info   : CRC  : SecuritySettings CRC   ...OK 
204 : Info   : INIT : SPI not enabled
205 : Info   : Time : Set Ext. Time Source: RTC at boot time: 1678303465
206 : Info   : Time set to 1678303465.000
207 : Info   : Current Time Zone: STD time start: 2023-10-29 03:00:00 offset: 0 min
208 : Info   : Local time: 2023-03-08 19:24:25
210 : Info   : Set Network mode: WiFi
314 : Info   : WIFI : Set WiFi to STA
427 : Info   : WiFi : Event STA Started
539 : Info   : INIT : Free RAM:231648
661 : Info   : INFO : Plugins: 47 [Normal] (ESP32 SDK 4.4.3.20230129)
662 : Info   : EVENT: System#Wake
807 : Info   : EVENT: System#BootMode=1,1,0,0
811 : Info   : WIFI : Connecting Lurch4 CC:CE:1E:13:B7:58 Ch:1 (0dBm) open attempt #0
822 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
1289 : Info   : Webserver: start
1290 : Info   : EVENT: System#Boot
1318 : Info   : EVENT: Time#Initialized
1369 : Info   : Dummy: value 1: 0.00
1373 : Info   : Dummy: value 2: 0.00
1376 : Info   : Dummy: value 3: 0.00
1380 : Info   : Dummy: value 4: 0.00
1397 : Info   : WIFI : Connected! AP: Lurch4 (CC:CE:1E:13:B7:58) Ch: 1 Duration: 517 ms
1399 : Info   : WIFI : DHCP IP: 192.168.10.151 (meshtest-5) GW: 192.168.10.1 SN: 255.255.255.0 DNS: 192.168.10.1 / 0.0.0.0   duration: 38 ms
1444 : Info   : SYS  : 0.00,218992.00,-49.00,100.00
1488 : Info   : UDP : Start listening on port 8266
1489 : Info   : firstLoopConnectionsEstablished
1498 : Info   : EVENT: TaskInit#test=1,1
1518 : Error  : MQTT : Intentional reconnect
1552 : Info   : MQTT : Connected to broker with client ID: meshtest_5_5


User avatar
chromo23
Normal user
Posts: 821
Joined: 10 Sep 2020, 16:02
Location: germany

Re: Very long time connecting to WiFi

#50 Post by chromo23 » 08 Mar 2023, 20:45

TD-er wrote: 08 Mar 2023, 20:17 I've even seen the connected log + IP being reported at 1500 msec from boot, so there is still some room for improvement.
However, there is always the risk we may put too much stress on the node, causing poor quality ones to fail.
Don't push the limits too far.. it all looks already really good. ;)

Post Reply

Who is online

Users browsing this forum: No registered users and 34 guests