WiFi fails to reconnect after AP reappears (IDFGH-1412)

[rojer]

This seems so blindingly obvious, that I seriously doubt it's a bug, maybe API usage issue, but anyway.
ESP32 fails to reconnect to AP after it goes away and comes back.
My code invoked wifi_connect() immediately on getting SYSTEM_EVENT_STA_DISCONNECTED (for any reason), but it just sits there, in a reason 201 loop:

[Jun 27 23:51:06.901] mgos_wifi_set_mode   WiFi mode: STA
[Jun 27 23:51:06.907] E (4042) wifi: esp_wifi_set_mode 774 wifi is not init
[Jun 27 23:51:06.932] I (4042) wifi: wifi firmware version: bf86460
[Jun 27 23:51:06.932] I (4052) wifi: config NVS flash: enabled
[Jun 27 23:51:06.932] I (4052) wifi: config nano formating: disabled
[Jun 27 23:51:06.932] I (4062) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
[Jun 27 23:51:06.932] I (4062) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
[Jun 27 23:51:06.945] I (4072) wifi: Init dynamic tx buffer num: 32
[Jun 27 23:51:06.951] I (4082) wifi: Init dynamic rx buffer num: 64
[Jun 27 23:51:06.958] I (4092) wifi: wifi driver task: 3ffbd7d0, prio:23, stack:4096
[Jun 27 23:51:06.969] I (4102) wifi: Init static rx buffer num: 10
[Jun 27 23:51:06.969] I (4102) wifi: Init dynamic rx buffer num: 0
[Jun 27 23:51:06.974] I (4112) wifi: Init rx ampdu len mblock:7
[Jun 27 23:51:06.981] I (4112) wifi: Init lldesc rx ampdu entry mblock:4
[Jun 27 23:51:06.989] I (4122) wifi: wifi power manager task: 0x3ffd022c prio: 21 stack: 2560
[Jun 27 23:51:06.996] E (4132) wifi: esp_wifi_connect 816 wifi not start
[Jun 27 23:51:07.004] I (4132) wifi: wifi timer task: 3ffd12b0, prio:22, stack:3584
[Jun 27 23:51:07.034] I (4162) phy: phy_version: 355.1, 59464c5, Jun 14 2017, 20:25:06, 0, 0
[Jun 27 23:51:07.034] I (4162) wifi: mode : sta (24:0a:c4:05:6b:8c)
[Jun 27 23:51:07.039] event_handler        event: 2
[Jun 27 23:51:07.047] mgos_wifi_setup_sta  WiFi STA: Connecting to 10000_Internets
...
[Jun 27 23:51:08.377] I (5512) wifi: n:11 0, o:1 0, ap:255 255, sta:11 0, prof:1
[Jun 27 23:51:09.228] I (6362) wifi: state: init -> auth (b0)
[Jun 27 23:51:09.274] blink_timer_cb       Tock
[Jun 27 23:51:09.343] I (6482) wifi: state: auth -> assoc (0)
[Jun 27 23:51:09.426] I (6562) wifi: state: assoc -> run (10)
[Jun 27 23:51:09.482] I (6612) wifi: connected with 10000_Internets, channel 11
[Jun 27 23:51:09.488] mgos_wifi_on_change_ Wifi: connected
[Jun 27 23:51:09.540] I (6662) event: ip: 192.168.43.99, mask: 255.255.255.0, gw: 192.168.43.1
[Jun 27 23:51:09.540] mgos_wifi_on_change_ WiFi: ready, IP 192.168.43.99, DNS 192.168.43.1

so far so good. now i turn off the AP:

[Jun 27 23:51:22.981] I (20112) wifi: state: run -> auth (3a0)
[Jun 27 23:51:22.988] I (20122) wifi: n:11 0, o:11 0, ap:255 255, sta:11 0, prof:1
[Jun 27 23:51:22.996] esp32_wifi_ev        WiFi STA: disconnected, reason 3; reconnecting
[Jun 27 23:51:23.004] I (20142) wifi: pm stop, total sleep time: 0/3568492
[Jun 27 23:51:23.004] 
[Jun 27 23:51:23.009] mgos_wifi_on_change_ Wifi: disconnected
[Jun 27 23:51:24.697] esp32_wifi_ev        WiFi STA: disconnected, reason 201; reconnecting
[Jun 27 23:51:24.704] mgos_wifi_on_change_ Wifi: disconnected
[Jun 27 23:51:26.396] esp32_wifi_ev        WiFi STA: disconnected, reason 201; reconnecting
[Jun 27 23:51:26.403] mgos_wifi_on_change_ Wifi: disconnected

when i turn the AP back on, there's no reaction from the ESP, it just keeps looping, no new wifi messages appear.

so, the question is: is calling wifi_connect() the right thing to do if i want station to stay connected with the same configuration?

[rojer]

i should add that this used to work way back when, i remember the device deifnitely reconnected to AP after it reappeared. i had to add this explicit esp_wifi_connect() call, but otherwise it worked.

[TimXia]

@rojer We have fixed a few bugs about WiFi connection recently. Please use the latest IDF to check if this problem still exist. Thanks.

[HubbyGitter]

The 201 phenomenon, as far as my observations go, is independent of an AP disappearing. It happens also when the ESP32 disconnects and tries to reconnect.

In my case, it's not an infinite loop though, but I fall back to stopping and restarting WiFi. It takes a number of times until the connect will work.

Try the latest IDF update; in my case it seems to have improved things a little bit, but it's under observation.

@TimXia Thank you for bringing the update to our attention.

[rojer]

@TimXia still the same on latest master (90f1d42).

@HubbyGitter right, i don't stop and restart wifi, just keep calling esp_wifi_connect(). it definitely worked before. i might go to stop/start as a workaround for now.

[rojer]

found a workaround: if you call esp_wifi_connect() from a different task, it reconnects.
looks like it's not ok to call it from within the same task that delivered SYSTEM_EVENT_STA_DISCONNECTED.

[heyinling]

@rojer could you plz provide you AP model?

[rojer]

@heyinling it's a Nexus 5X android phone, portable hotspot AP.

but that's not the reason anyway. see above: the reason is that esp_wifi_connect() cannot be invoked from the event task.

[heyinling]

I see. I also call esp_wifi_connect when recv disconnect event in event task. My test result is that this issue only happened on specific APs.

Is your reproduce step as follow:

1. switch off hotspot on phone
2. wait ESP32 disconnect
3. switch on hotspot again, check if ESP32 reconnect succeed

It would also be helpful if you can help provide Android version of your phone. we'll try to reproduce this bug.

[rojer]

@heyinling that's exactly what i did. no, ESP32 does not reconnect after AP comes back - as long as esp_wifi_connect() is invoked on the same task as the one delivered the event.
android version is 7.1.2

you can see my workaround in the commit above. this fixes the problem.

[rojer]

ok, i got to the bottom of the issue.
it was on my side: i was installing handler via the wifi_init_config_t.event_handler, which is invoked on the wifi task, it seems. i moved all my event handling activities to the system event handler, and the issue is gone (since esp_send_event transfers control to the system event task).
sorry for the false alarm.
however, it would be nice to have a note added here:

typedef struct {
    system_event_handler_t event_handler;          /**< WiFi event handler */
   ...
}

about this potential pitfall. or just remove it altogether and force users to handle events on the system handler.

[HubbyGitter]

Good for you. I reconnect from my stat machine task, not from any other context. Actually, I make all wifi API calls from a single task which is "mine". Still, it takes several 201s before the connect succeeds.

But we have a different thread for that.

[Resultfactory]

@rojer To clarify, you set your own eventhandler function? and now you use the system event handler set with esp_event_loop_init?
We also tried to call esp_wifi_connect() in another task, however that did not solve our disconnect loop

[rojer]

@Resultfactory yes, i used to set wifi_init_config_t.event_handler which runs on wifi task, now i let them be transferred to the system event task and handle them there.

[vseven]

@rojer - Is it possible to post your code? I'm having a very similiar issue with WiFi.reconnect not working and I also am calling it from the STA_DISCONNECT.

[apeiris]

I believe ESP works only on 2.4G networks.. so if your network is 5G.. try connecting to 2.4g network ssid