[TW#28251] Some phones can't connect to WPA SoftAP since f874b52f

[vkoutny]

This is a similar problem to #2273 - with ESP32 in SoftAP-only mode (using examples/wifi/getting_started/softAP), connection from some phones is not possible - the phone is unable to get an IP address from ESP32.

I can reproduce this on current master (577f8d8) as well as v3.2 release, using old Samsung Galaxy Ace 2, running Android 4.1.2; works as expected from several other Android (7/8) phones or a Linux laptop.

The ESP32 console shows this:

I (9546) wifi: ap recv assoc/reassoc request
I (9546) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (9546) wifi: bss=0x3ffb9f1c, resp=16 join
I (9546) wifi: station: 20:d3:90:9e:b4:2a join, AID=1, bgn, 20
I (9556) wifi: join success, ap send assoc response
W (9566) event: unexpected system event 63!
E (9566) event: mismatch or invalid event, id=63
E (9566) event: default event handler failed!

(this is with verbose logging enabled already..)

To compare, a working phone logs:

I (96626) wifi: ap recv assoc/reassoc request
I (96626) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (96626) wifi: bss=0x3ffbabb0, resp=16 join
I (96626) wifi: station: c8:d7:b0:99:fa:1e join, AID=1, bgn, 20
I (96636) wifi: join success, ap send assoc response
W (96646) event: unexpected system event 63!
E (96646) event: mismatch or invalid event, id=63
E (96646) event: default event handler failed!
D (96676) event: SYSTEM_EVENT_AP_STACONNECTED, mac:c8:d7:b0:99:fa:1e, aid:1
I (96676) wifi softAP: station:c8:d7:b0:99:fa:1e join, AID=1
dhcps: send_offer>>udp_sendto result 0
I (97076) tcpip_adapter: softAP assign IP to station,IP is: 192.168.4.2
D (97076) event: SYSTEM_EVENT_AP_STAIPASSIGNED

ie, SYSTEM_EVENT_AP_STACONNECTED is missing.

Originally I though this is the same issue as #2273, but testing some different git revisions shows it is not the same - in my case, this phone can connect normally even before the fix for #2273; it just stopped working somewhere later.

I was able to git-bisect this issue to this commit:

commit f874b52
Author: Liu Zhi Fu liuzhifu@espressif.com
Date: Wed Nov 21 12:53:04 2018 +0800

esp32: fix some wifi bugs

Fix some WiFi bugs:
1. Enable RX BAR
2. Fix the bug that ESP32 AP negotiates with iphone to 11g
3. Fix the bug that ESP32 STA has ap_loss because CMCC AP contains two SSID

The phone can connect normally when switching to WIFI_AUTH_OPEN; WPA/WPA2/WPA+WPA2 modes are all broken.

From the wifi sniff I can see the phone finishes 4-way handshake normally and starts sending DHCP requests; but it looks like ESP32 ignores the 4/4 message from phone for some reason since it re-sends 3/4 every few seconds.

Could you please check what changes introduced in f874b52 could be causing this issue?

[vkoutny]

Wifi sniff: sniff-old-bad-filter.pcapng.gz

[liuzfesp]

HI @vkoutny, I think this is a bug caused by the commit you mentioned. Could you help to check whether the patch can fix your issue or not? Steps to get the patch:

1. git clone https://github.com/liuzfesp/wifi_patch_for_customer.git
2. git checkout bugfix/issue438
3. cd wifi_patch_for_customer/438 and get the wifi lib github_wifi_lib_for_debug.tar.gz
4. Copy the wifi lib in github_wifi_lib_for_debug.tar.gz to your IDF $IDF_PATH/components/esp32/lib
5. make clean && make
6. Check wether the problem is solved or not

We need about 1 week to merge the patch into GitHub.

[vkoutny]

Hi @liuzfesp, thanks for quick response - but this repo seems to be empty right now:

$ git clone https://github.com/liuzfesp/wifi_patch_for_customer.git
Cloning into 'wifi_patch_for_customer.git'...
warning: You appear to have cloned an empty repository.

[liuzfesp]

@vkoutny please try again.

[vkoutny]

Unfortunately it still doesn't work - same output as before:

V (756) event: exit default callback
I (6236) wifi: ap recv assoc/reassoc request
I (6236) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (6236) wifi: bss=0x3ffb9f1c, resp=16 join
I (6236) wifi: station: 20:d3:90:9e:b4:2a join, AID=1, bgn, 20
I (6246) wifi: join success, ap send assoc response
W (6246) event: unexpected system event 63!
E (6256) event: mismatch or invalid event, id=63
E (6256) event: default event handler failed!
I (36886) wifi: ap recv deauth/disassoc from sta 20:d3:90:9e:b4:2a, reason:8

Is it maybe possible to get a version of libs with more debug logs to see what is happening?

[liuzfesp]

Hi @vkoutny could you check whether your wifi firmware version is b13bf0b or not?

[vkoutny]

yes it is:
I (376) wifi: wifi firmware version: b13bf0b

[liuzfesp]

OK, the commit ID looks no problem. @vkoutny, could you help to do a test:
Disable AMPDU via: make menuconfig => Components => Wi-Fi => Disable "WiFi AMPDU TX" and "WiFi AMPDU RX", then build and check the result

[vkoutny]

Disabling AMPDU RX/TX options does help - without these options the phone connects as expected.

(it works even without your patched libs, ie, with: wifi firmware version: 6b44342)

[liuzfesp]

So it a bug related to software BAR handling, we have a fix for it. Will merge it into IDF this week or next week.

[mnlipp]

I have I (482) wifi: wifi firmware version: 8d14c33. In my case enabling/disabling "WiFi AMPDU TX" and "WiFi AMPDU RX" dos not make a difference. Independent of the setting, one phone does not work, another phone and a tablet do work.

[liuzfesp]

Hi @mnlipp, could you let me know the phone type and OS version of the phone?

[mnlipp]

LG (d802) Android 7.1.2 Lineageos 14.1-20180919.

[mnlipp]

Update: I've upgraded to LineageOS 15.1-20190113-NIGHTLY-d802. At first there had been no change. However, I found that there was a notification. Opening it, it presented the option "to keep the connection despite it has no internet connection". After I had checked this, loading of the "welcome" page from the ESP32 AP continued.

I cannot tell if this is specific to LineageOS 15.1 or if I have simply overlooked the notification before in LineageOS 14.1.

I have only thought of this just now: one of the devices -- a tablet -- where things have worked from the beginning also runs LineageOS 14.1. But this device being a tablet, Android had no better option than to use the WiFi connection, while on the LG phone, Android can prefer the mobile network (with internet access) over the ESP32 AP that does not provide internet access. Actually, I could verify this assumption by switching off the mobile network on the phone. Once I had done this, it connected to the ESP32 AP immediately as expected.

So, sorry for the noise. I hadn't been aware of this (my phone's) behavior.

[PureTek-Innovations]

I have a similar problem with an Android 8.1.0 phone, this is a new error as the code worked perfectly with a copy of the ESP32 core downloaded on 17/12/2018

The error messages are:

E (49043) event: mismatch or invalid event, id=63
E (49043) event: default event handler failed!
dhcps: send_offer>>udp_sendto result 0

The webpage on 192.168.4.1 times out.

If I logon with a Windows 8.1 PC and open the page with Chrome, then it does load but is very very slow.

If I add the following line to the DNS server "dnsServer.start(DNS_PORT, "*", WiFi.softAPIP());" then when I logon with the phone I get a sign in dialogue box with opens the page perfectly but opening 192.168.4.1 from Chrome (or other browsers) times out.

I have tried the patch from @liuzfesp https://github.com/liuzfesp/wifi_patch_for_customer.git, it doesn't seem to help.

[PureTek-Innovations]

I just discovered that turning off mobile data makes the site load properly
But this wasn't a problem with earlier ESP32 Cores, I was running one downloaded on 17/12/2018 and I didn't have this problem.

[TimXia]

@vkoutny @mnlipp @PureTek-Innovations The issue has been solved. Please update IDF to check it.

[svicar]

Helo...I am beginer...I bought ESP32 and programed it with Arduino IDE. When I try connect my smartphone to ESP32 I have error on serial monitor
E (39382) event: mismatch or invalid event, id=63
E (39382) event: default event handler failed!
What I must do? Please describe to beginer what exactely to do, what tool to use.

Thankyou.

[berniv]

TimXia, what did you correct? I have the same issue since 2 years with software-AP. With some old Android phone the occurence is less often than new phones.
I am using Arduino-ESP32, I would like to try the same correction as you have made into IDF, if you tell what are the corrections, I can make the same into Arduino-ESP32 core.
For information, the correction in sdkconfig.h (Disable "WiFi AMPDU TX" and "WiFi AMPDU RX) did not help.
Thank you!

[berniv]

I tried to run the example "WifiAccessPoint.ino", without any modification, and as soon as I try to connect, it prints the same error, but without panic and reset. The example finally works as it should.

This is the serial output:
ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1100
load:0x40078000,len:10088
load:0x40080400,len:6380
entry 0x400806a4

Configuring access point...
AP IP address: 192.168.4.1
Server started
E (12949) event: mismatch or invalid event, id=63
E (12949) event: default event handler failed!
dhcps: send_offer>>udp_sendto result 0

[TimXia]

@berniv We fix some connection issues. Could you please try the latest IDF simple wifi example to check it?

[svicar]

how to use IDF example??? I am using arduino IDE

[vkoutny]

@liuzfesp @TimXia Unfortunately even latest master (abea9e4) still doesn't work - but the behavior is a bit different now: the phone still doesn't get its DHCP lease, but disconnects after a few seconds and then retries:

V (739) event: exit default callback
I (8179) wifi: ap recv assoc/reassoc request
I (8179) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (8179) wifi: bss=0x3ffb9f24, resp=16 join
I (8179) wifi: station: 20:d3:90:9e:b4:2a join, AID=1, bgn, 20
I (8189) wifi: join success, ap send assoc response
I (12229) wifi: station: 20:d3:90:9e:b4:2a leave, AID = 1, bss_flags is 134242
I (12229) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (13869) wifi: ap recv assoc/reassoc request
I (13869) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (13869) wifi: bss=0x3ffbab9c, resp=16 join
I (13879) wifi: station: 20:d3:90:9e:b4:2a join, AID=1, bgn, 20
I (13879) wifi: join success, ap send assoc response
I (17909) wifi: station: 20:d3:90:9e:b4:2a leave, AID = 1, bss_flags is 134242
I (17909) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (19559) wifi: ap recv assoc/reassoc request
I (19559) wifi: new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1
I (19559) wifi: bss=0x3ffbab9c, resp=16 join
I (19559) wifi: station: 20:d3:90:9e:b4:2a join, AID=1, bgn, 20
I (19569) wifi: join success, ap send assoc response
I (23599) wifi: station: 20:d3:90:9e:b4:2a leave, AID = 1, bss_flags is 134242

Changing the AMPDU settings - disabling both RX/TX fixes the problem, disabling just the RX also fixes the problem - but disabling just TX does not fix the issue.

[devopsone]

Happens also on a Samsung Galaxy Note 3 (Android 5.0) and iPhone 6Plus (iOS 12.1.3)

[infotrino]

Thank you very much vkoutny.
I tried to disabled AMPDU RX as you informed:
...
wifi_init_config_t wifi_init_config = WIFI_INIT_CONFIG_DEFAULT();
wifi_init_config.ampdu_rx_enable = 0;
ESP_ERROR_CHECK(esp_wifi_init(&wifi_init_config));
...
and it works well with current stable ESP_IDF version.

Though I could connect to esp32 with latest version (today 2019,.02.03)+AMPDU enable,
I choose stable 3.1 version+AMPDU disabling.
Phone to esp32 connection is too delayed with (latest version+AMPDU enable).
I think esp-idf latest version may have some problem still.

[TimXia]

@vkoutny @devopsone @infotrino Sorry, I was thinking the fix was already merged into IDF but it hasn't. We will merge it soon.

[svicar]

What about fix if I use Arduino IDE? I tested several diferent development boards. When I use ESP32 as access point there is a problem with wifi connection on it.
E (39382) event: mismatch or invalid event, id=63
E (39382) event: default event handler failed!
Is there some solution?

Thank you

[TimXia]

@vkoutny @devopsone @infotrino The fix has been merged. Please update the IDF branch to check whether it works for you.

[TimXia]

@svicar Hristo has replied you in the email as follows:

This has been fixed in github master. You can install the github of the version by following the steps outlined here: https://github.com/espressif/arduino-esp32#installation-instructions
Make sure you uninstall it first from the board manager.

[svicar]

I instaled git
The error is not showing but the problem still rest. When the ESP is in AP mode. The smartphone is dropping wifi connection, there are problem with getting IP.
sometimes it show new error: dhcps: send_offer>>udp_sendto result 0

[liuzfesp]

HI @svicar I think the WiFi connection issue with ESP32 AP is fixed with IDF commit: de79835, we have merged this commit, but it seems still not automatically synced to github, it may still need 1 or 2 days before it can be synced to IDF github.

[themindfactory]

I get the same thing and when it crashes and reboots I also get almost immediately:
E (5472) wMifi: esf_buf: t=3 lM=28 max:8, alloc:8 noM eb, TXQ_BLOCK=0
E (5474) wifi: esf_buMf: t=3 l=28 max:8, Malloc:8 no eb, TXQ_BLMOCK=0
E (5475) wifi:M esf_buf: t=3 l=28 maMx:8, alloc:8 no eb, TMXQ_BLOCK=0

[vkoutny]

I can comment the original issue is fixed by commit de79835 - tested working on current master (1aa8e8d) as well as when the fix was merged (2c7f603).

(Note: this fix is not yet in the 3.2 release branch (8a69ffc) - if you have this issue just stick to master for now.)

Thanks for support, closing this issue.