search

letscontrolit / ESPEasy

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

WifiAPMode not working since 20220616 #4118

Open chromoxdor opened 2 years ago

chromoxdor commented 2 years ago

Just found out that calling WifiAPMode causes the Wifi do disconnect entirely and reconnect without beeing able to establish an AP. Works in prior’s release....

16390 : Info   : HTTP: WifiAPMode
16497 : Info   : WIFI : Set WiFi to AP+STA
17488 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1
17616 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 12 s
17628 : Error  : WiFi : Scan not allowed, unprocessed WiFi events:  disconn
17729 : Info   : WIFI : Set WiFi to OFF
17944 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
17947 : Info   : WiFi : Best AP candidate: test 00:90:4C:1F:F0:1A Ch:1 (-36dBm) WPA2/PSK
17948 : Info   : WIFI : Connecting test 00:90:4C:1F:F0:1A Ch:1 (-36dBm) WPA2/PSK attempt #1
18052 : Info   : WIFI : Set WiFi to STA
18169 : Info   : EVENT: WiFi#APmodeEnabled
18192 : Info   : EVENT: WiFi#Disconnected
19112 : Info   : EVENT: WiFi#APmodeDisabled
19127 : Info   : WIFI : Connected! AP: test (00:90:4C:1F:F0:1A) Ch: 1 Duration: 1177 ms
19128 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: Conn. 
19164 : Info   : EVENT: WiFi#ChangedAccesspoint
19189 : Info   : EVENT: WiFi#ChangedWiFichannel
19247 : Info   : WIFI : DHCP IP: 192.168.1.146 (ESP-Easy) GW: 192.168.1.1 SN: 255.255.255.0   duration: 119 ms
19252 : Info   : EVENT: WiFi#Connected
chromoxdor commented 2 years ago

This seems to be an esp8266 only thing... just tested it on an esp32 and there it works. Builds are from yesterday...

TD-er commented 2 years ago

What core SDK version do you use? (see sysinfo page)

chromoxdor commented 2 years ago

ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support

TD-er commented 2 years ago

OK, that's for sure not a "new" SDK, so it is nothing recently introduced regarding the SDK. That means I'm probably to blame here...

chromoxdor commented 2 years ago

https://github.com/letscontrolit/ESPEasy/pull/4186 seemed to fix it. Tank you! But now it takes a lot longer to reconnect in sta mode... In the log you can see several disconnections before it gets connected again. For me it is not an real issue but i thought i mention it.

Here log from an old build:

32106 : Info   : HTTP: WifiAPMode
32110 : Info   : WIFI : Set WiFi to AP+STA
33100 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1
33189 : Info   : EVENT: WiFi#APmodeEnabled

Thats how it looks now:

33793 : Info   : HTTP: WifiAPMode
33900 : Info   : WIFI : Set WiFi to AP+STA
34891 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1 ch: 1
34915 : Info   : WiFi : processDisconnect()
35016 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 14 s
35017 : Info   : WiFi : WifiDisconnect()
35018 : Info   : WiFi : processDisconnect()
35019 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
35030 : Info   : EVENT: WiFi#APmodeEnabled
35075 : Info   : EVENT: WiFi#Disconnected
36027 : Info   : WiFi : Start network scan all channels
38210 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
41029 : Info   : WiFi : Start network scan all channels
43211 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
46042 : Info   : WiFi : Start network scan all channels
48224 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
48281 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 17104 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
51054 : Info   : WiFi : Start network scan all channels
53236 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
56066 : Info   : WiFi : Best AP candidate: test 30:B5:C2:22:A2:FA Ch:3 (-75dBm) WPA2/PSK
56067 : Info   : WIFI : Connecting test 30:B5:C2:22:A2:FA Ch:3 (-75dBm) WPA2/PSK attempt #1
56073 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
57062 : Info   : WIFI : Connected! AP: test (30:B5:C2:22:A2:FA) Ch: 3 Duration: 972 ms
57089 : Info   : EVENT: WiFi#ChangedAccesspoint
57112 : Info   : EVENT: WiFi#ChangedWiFichannel
57184 : Info   : WIFI : DHCP IP: 192.168.1.146 (ESP-Easy) GW: 192.168.1.1 SN: 255.255.255.0   duration: 140 ms
57186 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP 
57187 : Info   : EVENT: WiFi#Connected

Edit: i think the issue is that the AP starts with Channel:1 and in order to get reconnected in sta it needs to change the channel afterwards

TD-er commented 2 years ago

There is still another issue too. I noticed the AP mode may not always work the first time. I had to enable it often twice. Also it is a bit unclear (to the user) when the AP will be turned off. As long as the AP is stil on, the WiFi will not reconnect when connection gets lost.

So I'm still looking into this.

TD-er commented 2 years ago

Edit: i think the issue is that the AP starts with Channel:1 and in order to get reconnected in sta it needs to change the channel afterwards

Yep, your log shows it is indeed now running on 2 channels, which is bad. What I try to do is that when starting the AP, while STA mode is already active, I take the active channel and use that to start the AP. However if you're not (yet) connected, this may be an issue which I don't know how to fix. I could do a scan and take the channel of the most likely AP candidate to connect to as the channel to run the local AP. But if there are no WiFi credentials set, then what?

chromoxdor commented 2 years ago

But if there are no WiFi credentials set, then what? When Wifi is not connected a fallback channel would make sense...

However if you're not (yet) connected, this may be an issue which I don't know how to fix. As soon as it gets connected reinitialize the ap-mode with the given channel from sta

chromoxdor commented 2 years ago

What was the behavior in old builds?

TD-er commented 2 years ago

As soon as it gets connected reinitialize the ap-mode with the given channel from sta

But then you will loose connection when initially doing the setup.

What was the behavior in old builds?

As far as I know there should not be a different behavior. At least not intended. The only change I now made was to set the channel to the current one when connected in STA mode. The default channel is 1 (as it always has been)

What build do you test against where it was still working? The issue with not properly performing a disconnect was caused by a commit 14 months ago. (not 100% sure when that was merged, may have been later)

chromoxdor commented 2 years ago

I used the 24.12.2021 release to compare... I take the active channel and use that to start the AP. So the actual issue in my scenario is, that ap-mode was unable to grab the sta-mode channel and therefore used channel 1... Edit: So this is something that should work already?

TD-er commented 2 years ago

Edit: So this is something that should work already?

If the ESP is still connected and has STA active when starting the AP. Thus from mode STA => STA+AP If you have enabled the checkbox to restart WiFi on an error, then STA is probably not yet connected when starting AP mode.

chromoxdor commented 2 years ago

If you have enabled the checkbox to restart WiFi on an error, then STA is probably not yet connected when starting AP mode.

No, i haven’t.... 

33793 : Info   : HTTP: WifiAPMode
33900 : Info   : WIFI : Set WiFi to AP+STA
34891 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1 ch: 1
34915 : Info   : WiFi : processDisconnect()

And the disconnect happens after the ap mode so until then the sta channel shouldn’t have changed..

Edit: to be clear:

If the ESP is still connected and has STA active when starting the AP.

this is my scenario

TD-er commented 2 years ago

Not 100% the disconnect actually happened after starting the AP mode. The log is reported after, but since the WiFi events happen async and are reported via callback functions, I only set the flag the event has happened and later handle this flag.

I will have a look to see whether I can fetch the channel before doing anything regarding starting the AP as you have to set the IP config first and then start the AP. I think the disconnect may happen when I set the AP IP config.

TD-er commented 2 years ago

Can you try the last commit? I try to fetch the channel before even changing the WiFi mode from STA -> STA+AP And if STA isn't enabled, the channel is based on the last connected channel. (if any)

chromoxdor commented 2 years ago

Not quite... AP-mode works but connection loss and no reconnect as STA until reboot... but channel changing for AP-mode works :)

37384 : Info   : HTTP: WifiAPMode
37692 : Info   : WIFI : Set WiFi to AP+STA
38684 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1 ch: 3
38708 : Info   : WiFi : processDisconnect()
38809 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 18 s
38810 : Info   : WiFi : WifiDisconnect()
38811 : Info   : WiFi : processDisconnect()
38812 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
38823 : Info   : EVENT: WiFi#APmodeEnabled
38847 : Info   : EVENT: WiFi#Disconnected
47868 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 14808 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
77867 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 14856 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
TD-er commented 2 years ago

AP-mode works but connection loss and no reconnect as STA until reboot...

The timeout for disabling the AP is 5 minutes. (which may be too long?) Maybe I should just reset this timer to 1 minute as soon as someone connects to it or disconnects from it?

chromoxdor commented 2 years ago

A timeout of 1 minute is too short... 5minutes are fine...

but what does it has to do whith the permanent disconnection as sta?

TD-er commented 2 years ago

but what does it has to do whith the permanent disconnection as sta?

Working on that right now.

TD-er commented 2 years ago

OK, we might be on to something really serious.

I now have it working to reconnect to the AP in STA mode when AP is running on the ESP. However, this is then the last time the ESP may be able to connect to an AP until you reflash it (!!!!) Power cycle does not fix it.

So not sure what's happening here, but the code I have now, will not (!!) be pushed as I have no idea how seriously damaging this may be.

chromoxdor commented 2 years ago

Ohh. that doesn’t sound good... hope you’ll find a easy fix for that.

TD-er commented 2 years ago

OK, pushed a new commit. I have now disabled setting the TX power entirely, so no calls to this function from anywhere anymore. It may be messing up the WiFi radio seriously.

So please test this on a node that's well reachable as you may need to flash it via serial to get it to work again.

chromoxdor commented 2 years ago

Similar behavior than before with the extra addition of a short boot loop (6x) when i hit reboot. After that the esp boots normal again . 

35245 : Info   : HTTP: WifiAPMode
35352 : Info   : WIFI : Set WiFi to AP+STA
36343 : Info   : WIFI : AP Mode ssid will be ESP-Easy with address 192.168.4.1 ch: 3
36367 : Info   : WiFi : processDisconnect()
36468 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 15 s
36469 : Info   : WiFi : WifiDisconnect()
36471 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
36482 : Info   : EVENT: WiFi#APmodeEnabled
36527 : Info   : EVENT: WiFi#Disconnected
37475 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
38482 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
39490 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
40496 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
41502 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
42509 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
43515 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
44522 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
45529 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
46535 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
47542 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
47889 : Info   : WD   : Uptime 1 ConnectFailures 0 FreeMem 17048 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
48551 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
49557 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
50564 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
51572 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
52579 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
53585 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
54593 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
55604 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
56479 : Info   : WiFi : Best AP candidate: test 30:B5:C2:22:A2:FA Ch:3 (-83dBm) WPA2/PSK
56480 : Info   : WIFI : Connecting test 30:B5:C2:22:A2:FA Ch:3 (-83dBm) WPA2/PSK attempt #1
57476 : Info   : WIFI : Connected! AP: test (30:B5:C2:22:A2:FA) Ch: 3 Duration: 973 ms
57477 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: Conn. 
57502 : Info   : EVENT: WiFi#ChangedAccesspoint
57526 : Info   : EVENT: WiFi#ChangedWiFichannel
57607 : Info   : WIFI : DHCP IP: 192.168.1.146 (ESP-Easy) GW: 192.168.1.1 SN: 255.255.255.0   duration: 150 ms
57609 : Info   : EVENT: WiFi#Connected
TD-er commented 2 years ago

OK, so we're hitting some 20 seconds timeout here.

tonhuisman commented 1 year ago

Is this issue still relevant? If not it should be closed.

TD-er commented 1 year ago

Yep, still an issue :(

tonhuisman commented 1 year ago

@chromoxdor I've found and fixed an issue that prevented AP mode from starting when no matching AP was found, you can download form this Actions run for testing.

chromoxdor commented 1 year ago

No luck for me...

11173 : Info   : HTTP: WiFiAPMode
11279 : Info   : WIFI : Set WiFi to AP+STA
12272 : Info   : WIFI : AP Mode ssid will be ESP-Dev with address 192.168.4.1 ch: 1
12298 : Info   : WIFI : Disconnected! Reason: ‚(8) Assoc leave‘ Connected for 6947 ms
12299 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: Conn. IP Init
12400 : Info   : WiFi : WifiDisconnect()
12502 : Info   : WIFI : Disconnected! Reason: ‚(1) Unspecified‘
12603 : Info   : Reset WiFi.
12605 : Info   : WiFi : Start network scan all channels
14791 : Info   : WiFi : Scan finished, found: 11
14794 : Info   : WiFi : Best AP candidate: **** AA:D6:C7:F9:C4:CB Ch:6 (-36dBm) WPA2/PSK
14796 : Info   : WiFi : Added known candidate, try to connect
14796 : Info   : WiFi : WifiDisconnect()
14898 : Info   : WIFI : Disconnected! Reason: ‚(1) Unspecified‘
14899 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
15000 : Info   : Reset WiFi.
15003 : Info   : WiFi : Start network scan all channels
17189 : Info   : WiFi : Scan finished, found: 11
17193 : Info   : WiFi : Best AP candidate: **** AA:D6:C7:F9:C4:CB Ch:6 (-36dBm) WPA2/PSK
17194 : Info   : WiFi : Added known candidate, try to connect
17295 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
17296 : Info   : WIFI : Set WiFi to OFF
17613 : Info   : WIFI : Set WiFi to STA
17718 : Info   : WIFI : Connecting **** AA:D6:C7:F9:C4:CB Ch:6 (-36dBm) WPA2/PSK attempt #1
17735 : Info   : EVENT: WiFi#APmodeEnabled
17762 : Info   : EVENT: WiFi#Disconnected
18667 : Info   : EVENT: WiFi#Disconnected
18729 : Info   : WIFI : DHCP IP: 192.168.1.209 (ESP-Dev) GW: 192.168.1.1 SN: 255.255.255.0 DNS: 192.168.1.1 / (IP unset)   duration: 16 ms
18742 : Info   : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: IP 
18747 : Info   : EVENT: WiFi#Disconnected
18752 : Info   : EVENT: WiFi#APmodeDisabled
18756 : Info   : EVENT: WiFi#Connected
18842 : Info   : WIFI : Connected! AP: **** (AA:D6:C7:F9:C4:CB) Ch: 6 Duration: 981 ms
tonhuisman commented 1 year ago

Do you have a credential stored with a wrong password? As it tries to match on SSID, and seems to find a match with a stored credential(SSID), but still can't connect...

chromoxdor commented 1 year ago

Do you have a credential stored with a wrong password?

What credential do you mean? I connect to my home AP and then run WiFIAPMode