[TW#24959] Android phone unable to obtain IP in APSTA mode from ESP32

[amuzyche]

When we run ESP32 in the AP+STA mode. We are have facing a problem.

In the AP+STA mode, the ESP correctly connects to access point and also starts as an access point.

When we connect to the ESP access point using iPhone. We are also able to connect to it using Android phone (Pptv king 7 with Android 5.1, Xiaomi Mi 6 with Android 8.0).

However, when we try to connect Android phone (Xiaomi Redmi Note 4 with Android version 7.0), it gets stuck in the "Obtaining IP address" phase and finally ends up with an "Authentication error". On the ESP side, it correctly detects that the phone has connected but fails to allocate IP.

We have tried to restore factory settings on the phone. We have also tried to erase NVS data (and also erase entire flash!) of the ESP32. But the problem persists.

We use Espressif IoT Development Framework: v3.2-dev-362-g1c7a8b3b

We have produced the following logs with an open wifi configuration.

Pptv king 7 log:

13:27:00.762> [0;32mI (73054) tasks: SR:2168 [0m
13:27:07.191> I (79474) wifi: n:1 1, o:1 0, ap:1 1, sta:1 0, prof:1
13:27:07.191> I (79474) wifi: station: 70:0b:c0:a6:08:7f join, AID=1, bgn, 40U
13:27:07.191> D (79484) event: SYSTEM_EVENT_AP_STACONNECTED, mac:70:0b:c0:a6:08:7f, aid:1[0m
13:27:07.191> [0;32mI (79484) init: WiFi hdl: 15[0m
13:27:08.682> [0;32mI (81004) tcpip_adapter: softAP assign IP to station,IP is: 192.168.1.2[0m
13:27:08.682> D (81004) event: SYSTEM_EVENT_AP_STAIPASSIGNED[0m
13:27:08.682> [0;32mI (81004) init: WiFi hdl: 17[0m
13:27:09.182> [0;32mI (81474) azure: OK[0m
13:27:09.182> [0;32mI (81484) azure: SSL server wait for client ......[0m
13:27:10.747> [0;32mI (83054) tasks: SR:2166 [0m
13:27:12.680> [0;32mI (85004) azure: Client connected...[0m

Xiaomi Redmi Note 4 log:

13:18:50.436> I (70883) wifi: n:1 0, o:1 0, ap:1 1, sta:1 0, prof:1
13:18:50.436> I (70883) wifi: station: 50:8f:4c:47:ad:bf join, AID=1, bgn, 20
13:18:50.436> D (70883) event: SYSTEM_EVENT_AP_STACONNECTED, mac:50:8f:4c:47:ad:bf, aid:1[0m
13:18:50.436> [0;32mI (70883) init: WiFi hdl: 15[0m
13:18:51.560> I (72013) wifi: n:1 0, o:1 0, ap:1 1, sta:1 0, prof:1
13:18:51.560> I (72013) wifi: station: 50:8f:4c:47:ad:bf join, AID=1, bgn, 20
13:18:51.560> D (72013) event: SYSTEM_EVENT_AP_STACONNECTED, mac:50:8f:4c:47:ad:bf, aid:1[0m
13:18:51.560> [0;32mI (72013) init: WiFi hdl: 15[0m
13:18:51.622> [0;32mI (72073) tasks: SR:2122 [0m
13:19:01.592> [0;32mI (82073) tasks: SR:2123 [0m
13:19:07.838> I (88333) wifi: n:1 0, o:1 0, ap:1 1, sta:1 0, prof:1
13:19:07.908> I (88333) wifi: station: 50:8f:4c:47:ad:bf join, AID=1, bgn, 20
13:19:07.908> D (88343) event: SYSTEM_EVENT_AP_STACONNECTED, mac:50:8f:4c:47:ad:bf, aid:1[0m
13:19:07.908> [0;32mI (88343) init: WiFi hdl: 15[0m
13:19:07.908> -> 10:19:07 PINGREQ
13:19:07.908> 
13:19:07.978> <- 10:19:07 PINGRESP
13:19:07.978> 
13:19:11.585> [0;32mI (92073) tasks: SR:2124 [0m
13:19:21.571> [0;32mI (102073) tasks: SR:2123 [0m
13:19:27.932> -> 10:19:27 PINGREQ
13:19:27.932> 
13:19:31.617> [0;32mI (112073) tasks: SR:2123 [0m
13:19:32.177> I (112653) wifi: n:1 0, o:1 0, ap:1 1, sta:1 0, prof:1
13:19:32.177> I (112653) wifi: station: 50:8f:4c:47:ad:bf join, AID=1, bgn, 20
13:19:32.177> I (112653) wifi: state: run -> auth (6c0)
13:19:32.177> I (112653) wifi: pm stop, total sleep time: 100026683 us / 110673919 us
13:19:32.177> 
13:19:32.177> I (112663) wifi: n:1 0, o:1 0, ap:1 1, sta:1 0, prof:1
13:19:32.244> D (112663) event: SYSTEM_EVENT_AP_STACONNECTED, mac:50:8f:4c:47:ad:bf, aid:1[0m
13:19:32.244> [0;32mI (112673) init: WiFi hdl: 15[0m
13:19:32.244> D (112673) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:UNIT_city_guest, ssid_len:15, bssid:c8:b5:ad:c8:73:82, reason:6[0m
13:19:32.244> V (112683) event: enter default callback[0m
13:19:32.244> V (112693) tcpip_adapter: check: local, if=0 fn=0x40100c54
13:19:32.244> [0m
13:19:32.244> D (112693) tcpip_adapter: if0 start ip lost tmr: enter[0m
13:19:32.244> D (112703) tcpip_adapter: if0 start ip lost tmr: interval=120[0m
13:19:32.244> V (112703) tcpip_adapter: call api in lwip: ret=0x0, give sem[0m
13:19:32.244> V (112713) tcpip_adapter: check: remote, if=0 fn=0x40100c54
13:19:32.244> [0m
13:19:32.244> V (112723) event: exit default callback[0m
13:19:32.244> [0;32mI (112723) init: WiFi hdl: 5[0m
13:19:32.244> iothub_client_sample_mqtt has gotten quit message, call DoWork 3 more time to complete final sending...

[zhangyanjiaoesp]

@amuzyche I have reproduced your problem, and I will reply you as soon as I find the root cause.

[amuzyche]

@zhangyanjiaoesp Thank you for your prompt reply, how will apply executed changes, will it be hotfix, or sdk update?

[zhangyanjiaoesp]

It will be sdk update

[asimpl3]

Dear @zhangyanjiaoesp , i'm reaching out to check the progress with issue solving?

If it's possible can you give us estimate fixing time ?

[zhangyanjiaoesp]

@asimpl3 this week will fix this bug

[amuzyche]

Dear, @zhangyanjiaoesp , we really hope to solve this problem. What terms can we get a solution? Thank you.

[zhangyanjiaoesp]

@asimpl3 @amuzyche
you can use the latest IDF to test, the commit ID for this solution is:
commit 020ade6

[vkoutny]

This again/still doesn't work on current master (577f8d8) or v3.2 branch (47dea73) - but it indeed does work on commit 020ade6.

For me I can reproduce this with just the trivial softap example code (no mixed sta/ap), with old (android 4.1.2) samsung phone.

Could you please re-check what happened to the fix?

(I can provide logs/wifi sniff if needed)

EDIT: hmm, in my case it even works one commit before this fix (802fc72) - so my issue must be caused by something else.. let's create a new issue then.