WiFi STA fail to connect in enterprise AP.
Posted: Wed Jul 15, 2020 4:53 pm
Hello guys, I need some help with "enterprise" WiFis.
With my home wifi or mobile AP (hosted from galaxy s8), esp32 always can connect correctly and get dhcp ip. However, here in my job (enterprise wifi), esp32 fail to connect OR fail to get DHCP or connect sucessfully. (random)
Please, help me to find WHY (or solution) to solve this problem. I have enabled all wifi log from menuconfig to help debug:
1. Here, ESP32 can connect to WiFi and receive DHCP sucessfully.
2. Here, ESP32 can't connect to AP
3. Here, ESP32 can connect to WiFi but can't get IP DHCP.
With my home wifi or mobile AP (hosted from galaxy s8), esp32 always can connect correctly and get dhcp ip. However, here in my job (enterprise wifi), esp32 fail to connect OR fail to get DHCP or connect sucessfully. (random)
Please, help me to find WHY (or solution) to solve this problem. I have enabled all wifi log from menuconfig to help debug:
1. Here, ESP32 can connect to WiFi and receive DHCP sucessfully.
Code: Select all
I (3367) wifi: mode : sta (3c:71:bf:6e:a9:fc) + softAP (3c:71:bf:6e:a9:fd)
I (3374) wifi: filter: set rx policy=9
I (3377) wifi: ht20 freq=2412, chan=1
I (3384) wifi: Start wifi disconnect
I (3384) wifi: connect step 0 -> 0, status=0, err_time=0
I (3389) wifi: connect status 0 -> 0, step=0, err_time=0
I (3394) wifi: filter: set rx policy=8
I (3397) wifi: clear blacklist
I (3400) wifi: Start wifi connect
I (3403) wifi: connect step 0 -> 0, status=0, err_time=0
I (3408) wifi: connect chan=0
I (3411) wifi: nvs=0, ssid=SISTEL CONVIDADO, channel=255
I (3416) wifi: ssid=SISTEL CONVIDADO match nvs 0, channel=255
I (3421) wifi: first chan=1
I (3424) wifi: connect status 0 -> 1, step=0, err_time=0
I (3429) wifi: connect step 0 -> 1, status=1, err_time=0
I (3434) wifi: filter: set rx policy=3
I (3437) wifi: clear scan ap list
I (3440) wifi: start scan: type=0x50f, priority=2, cb=0x40126b98, arg=0x0, ss_state=0x1, time=239108, index=0
0x40126b98: cnx_start_handoff_cb at ??:?
I (3450) wifi: inter_channel_timeout: arg=0x0, ss_state=0x1
I (3455) wifi: perform scan: ss_state=0x9, chan<1,0>, dur<100,150>
I (3461) wifi: change: chan<1,0>, dur<100,150>
I (3465) wifi: enter start op, arg=0x3ffb5878
I (3469) wifi: scan operation: state=0x3, chan<1,0>, arg=0x3ffb5878, status=0
I (3476) wifi: scan specific ssid=SISTEL CONVIDADO
I (3481) wifi: start min timer
I (3484) wifi: start max timer
I (3636) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (3637) wifi: back home chan=<1,0>, current chan=<1,0>
I (3637) wifi: start scan timer
I (3668) wifi: oper_channel: arg=0x0 time=467114
I (3669) wifi: perform scan: ss_state=0x9, chan<2,0>, dur<100,150>
I (3669) wifi: change: chan<2,0>, dur<100,150>
I (3672) wifi: ht20 freq=2417, chan=2
I (3676) wifi: enter start op, arg=0x3ffb5878
I (3679) wifi: scan operation: state=0x3, chan<2,0>, arg=0x3ffb5878, status=0
I (3686) wifi: scan specific ssid=SISTEL CONVIDADO
I (3691) wifi: start min timer
I (3693) wifi: start max timer
I (3793) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (3794) wifi: back home chan=<1,0>, current chan=<2,0>
I (3794) wifi: ht20 freq=2412, chan=1
I (3796) wifi: start scan timer
I (3829) wifi: oper_channel: arg=0x0 time=627390
I (3829) wifi: perform scan: ss_state=0x9, chan<3,0>, dur<100,150>
I (3829) wifi: change: chan<3,0>, dur<100,150>
I (3832) wifi: ht20 freq=2422, chan=3
I (3836) wifi: enter start op, arg=0x3ffb5878
I (3840) wifi: scan operation: state=0x3, chan<3,0>, arg=0x3ffb5878, status=0
I (3846) wifi: scan specific ssid=SISTEL CONVIDADO
I (3851) wifi: start min timer
I (3854) wifi: start max timer
I (3954) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (3954) wifi: back home chan=<1,0>, current chan=<3,0>
I (3954) wifi: ht20 freq=2412, chan=1
I (3956) wifi: start scan timer
I (3989) wifi: oper_channel: arg=0x0 time=787722
I (3989) wifi: perform scan: ss_state=0x9, chan<4,0>, dur<100,150>
I (3989) wifi: change: chan<4,0>, dur<100,150>
I (3992) wifi: ht20 freq=2427, chan=4
I (3996) wifi: enter start op, arg=0x3ffb5878
I (4000) wifi: scan operation: state=0x3, chan<4,0>, arg=0x3ffb5878, status=0
I (4007) wifi: scan specific ssid=SISTEL CONVIDADO
I (4011) wifi: start min timer
I (4014) wifi: start max timer
I (4114) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4114) wifi: back home chan=<1,0>, current chan=<4,0>
I (4114) wifi: ht20 freq=2412, chan=1
I (4117) wifi: start scan timer
I (4150) wifi: oper_channel: arg=0x0 time=948243
I (4150) wifi: perform scan: ss_state=0x9, chan<5,0>, dur<100,150>
I (4150) wifi: change: chan<5,0>, dur<100,150>
I (4153) wifi: ht20 freq=2432, chan=5
I (4157) wifi: enter start op, arg=0x3ffb5878
I (4160) wifi: scan operation: state=0x3, chan<5,0>, arg=0x3ffb5878, status=0
I (4167) wifi: scan specific ssid=SISTEL CONVIDADO
I (4172) wifi: start min timer
I (4175) wifi: start max timer
I (4275) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4275) wifi: back home chan=<1,0>, current chan=<5,0>
I (4275) wifi: ht20 freq=2412, chan=1
I (4277) wifi: start scan timer
I (4310) wifi: oper_channel: arg=0x0 time=1108530
I (4310) wifi: perform scan: ss_state=0x9, chan<6,0>, dur<100,150>
I (4310) wifi: change: chan<6,0>, dur<100,150>
I (4313) wifi: ht20 freq=2437, chan=6
I (4317) wifi: enter start op, arg=0x3ffb5878
I (4321) wifi: scan operation: state=0x3, chan<6,0>, arg=0x3ffb5878, status=0
I (4328) wifi: scan specific ssid=SISTEL CONVIDADO
I (4332) wifi: start min timer
I (4335) wifi: start max timer
I (4435) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4435) wifi: back home chan=<1,0>, current chan=<6,0>
I (4435) wifi: ht20 freq=2412, chan=1
I (4438) wifi: start scan timer
I (4470) wifi: oper_channel: arg=0x0 time=1268908
I (4470) wifi: perform scan: ss_state=0x9, chan<7,0>, dur<100,150>
I (4470) wifi: change: chan<7,0>, dur<100,150>
I (4474) wifi: ht20 freq=2442, chan=7
I (4477) wifi: enter start op, arg=0x3ffb5878
I (4481) wifi: scan operation: state=0x3, chan<7,0>, arg=0x3ffb5878, status=0
I (4488) wifi: scan specific ssid=SISTEL CONVIDADO
I (4493) wifi: start min timer
I (4495) wifi: start max timer
I (4595) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4595) wifi: back home chan=<1,0>, current chan=<7,0>
I (4596) wifi: ht20 freq=2412, chan=1
I (4598) wifi: start scan timer
I (4631) wifi: oper_channel: arg=0x0 time=1429287
I (4631) wifi: perform scan: ss_state=0x9, chan<8,0>, dur<100,150>
I (4631) wifi: change: chan<8,0>, dur<100,150>
I (4634) wifi: ht20 freq=2447, chan=8
I (4638) wifi: enter start op, arg=0x3ffb5878
I (4642) wifi: scan operation: state=0x3, chan<8,0>, arg=0x3ffb5878, status=0
I (4648) wifi: scan specific ssid=SISTEL CONVIDADO
I (4653) wifi: start min timer
I (4656) wifi: start max timer
I (4756) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4756) wifi: back home chan=<1,0>, current chan=<8,0>
I (4756) wifi: ht20 freq=2412, chan=1
I (4758) wifi: start scan timer
I (4791) wifi: oper_channel: arg=0x0 time=1589684
I (4791) wifi: perform scan: ss_state=0x9, chan<9,0>, dur<100,150>
I (4791) wifi: change: chan<9,0>, dur<100,150>
I (4794) wifi: ht20 freq=2452, chan=9
I (4798) wifi: enter start op, arg=0x3ffb5878
I (4802) wifi: scan operation: state=0x3, chan<9,0>, arg=0x3ffb5878, status=0
I (4809) wifi: scan specific ssid=SISTEL CONVIDADO
I (4813) wifi: start min timer
I (4816) wifi: start max timer
I (4916) wifi: scan end: arg=0x0, status=0, ss_state=0x3
I (4916) wifi: back home chan=<1,0>, current chan=<9,0>
I (4916) wifi: ht20 freq=2412, chan=1
I (4919) wifi: start scan timer
I (4951) wifi: oper_channel: arg=0x0 time=1750074
I (4952) wifi: perform scan: ss_state=0x9, chan<10,0>, dur<100,150>
I (4952) wifi: change: chan<10,0>, dur<100,150>
I (4955) wifi: ht20 freq=2457, chan=10
I (4959) wifi: enter start op, arg=0x3ffb5878
I (4963) wifi: scan operation: state=0x3, chan<10,0>, arg=0x3ffb5878, status=0
I (4970) wifi: scan specific ssid=SISTEL CONVIDADO
I (4974) wifi: start min timer
I (4977) wifi: start max timer
I (4984) wifi: profile match: ss_state=0x7
I (4984) wifi: scan histroy table is not full yet, add
I (4988) wifi: add ssid=SISTEL CONVIDADO, chan=11 to scan history
I (5023) wifi: profile match: ss_state=0x7
I (5023) wifi: update scan history ssid=SISTEL CONVIDADO, channel=11
I (5126) wifi: profile match: ss_state=0x7
I (5126) wifi: update scan history ssid=SISTEL CONVIDADO, channel=11
I (5130) wifi: scan end: arg=0x0, status=0, ss_state=0x7
I (5130) wifi: find first mathched ssid, scan done
I (5134) wifi: back home chan=<1,0>, current chan=<10,0>
I (5139) wifi: ht20 freq=2412, chan=1
I (5143) wifi: filter: set rx policy=4
I (5146) wifi: first chan=1
I (5148) wifi: scan_done: arg=0x0, status=0, cur_time=1947153, scan_id=128, scan state=0
I (5156) wifi: call scan_done cb, arg=0x0
I (5160) wifi: handoff_cb: status=0
I (5163) wifi: best bss has set.
I (5166) wifi: ap found, mac=8a:8a:20:f1:62:51
I (5170) wifi: bssid=8a:8a:20:f1:62:51, LR=0
I (5174) wifi: new_bss=0x3ffb39b0, cur_bss=0x0, new_chan=<11,0>, cur_chan=1
I (5181) wifi: filter: set rx policy=5
I (5184) wifi: ap channel adjust o:1,1 n:11,2
I (5189) wifi: new:<11,0>, old:<1,0>, ap:<11,2>, sta:<11,0>, prof:1
I (5195) wifi: ht20 freq=2462, chan=11
I (5198) wifi: connect_op: status=0, auth=5, cipher=3
I (5203) wifi: auth mode is not none
I (5772) wifi: connect_bss: auth=1, reconnect=0
I (5772) wifi: state: init -> auth (b0)
I (5772) wifi: start 1s AUTH timer
I (5772) wifi: clear scan ap list
I (5779) wifi: recv auth: seq=2, status=0
I (5780) wifi: state: auth -> assoc (0)
I (5782) wifi: restart connect 1s timer for assoc
I (5794) wifi: recv assoc: type=0x10
I (5794) wifi: filter: set rx policy=6
I (5794) wifi: state: assoc -> run (10)
I (5797) wifi: start 10s connect timer for 4 way handshake
I (5802) wifi: wpa_psk start
I (5805) wifi: wpa_psk handle succeed
I (5813) wifi: wpa_psk start
I (5814) wifi: wpa_psk handle succeed
I (5816) wifi: connected with SISTEL CONVIDADO, channel 11, bssid = 8a:8a:20:f1:62:51
I (5821) wifi: remove all except 8a:8a:20:f1:62:51 from rc list
I (5827) wifi: clear blacklist
I (5830) wifi: filter: set rx policy=7
I (5833) wifi: pm start, type: 1
I (5837) wifi: Send sta connected event
I (5840) wifi: connect status 1 -> 5, step=1, err_time=0
I (8920) event: sta ip: 192.168.5.78, mask: 255.255.255.0, gw: 192.168.5.1
Code: Select all
I (3310) wifi: mode : sta (3c:71:bf:6e:a9:fc) + softAP (3c:71:bf:6e:a9:fd)
I (3317) wifi: filter: set rx policy=9
I (3320) wifi: ht20 freq=2412, chan=1
I (3327) wifi: Start wifi disconnect
I (3327) wifi: connect step 0 -> 0, status=0, err_time=0
I (3332) wifi: connect status 0 -> 0, step=0, err_time=0
I (3337) wifi: filter: set rx policy=8
I (3340) wifi: clear blacklist
I (3343) wifi: Start wifi connect
I (3346) wifi: connect step 0 -> 0, status=0, err_time=0
I (3351) wifi: connect chan=0
I (3354) wifi: nvs=0, ssid=SISTEL CONVIDADO, channel=255
I (3359) wifi: ssid=SISTEL CONVIDADO match nvs 0, channel=255
I (3364) wifi: first chan=1
I (3367) wifi: connect status 0 -> 1, step=0, err_time=0
I (3372) wifi: connect step 0 -> 1, status=1, err_time=0
I (3377) wifi: filter: set rx policy=3
I (3380) wifi: clear scan ap list
I (3383) wifi: start scan: type=0x50f, priority=2, cb=0x40126b98, arg=0x0, ss_state=0x1, time=239534, index=0
0x40126b98: cnx_start_handoff_cb at ??:?
I (3393) wifi: inter_channel_timeout: arg=0x0, ss_state=0x1
I (3398) wifi: perform scan: ss_state=0x9, chan<1,0>, dur<100,150>
I (3404) wifi: change: chan<1,0>, dur<100,150>
I (3408) wifi: enter start op, arg=0x3ffb5878
I (3412) wifi: scan operation: state=0x3, chan<1,0>, arg=0x3ffb5878, status=0
I (3419) wifi: scan specific ssid=SISTEL CONVIDADO
I (3424) wifi: start min timer
I (3427) wifi: start max timer
I (3461) wifi: profile match: ss_state=0x7
I (3461) wifi: scan histroy table is not full yet, add
I (3461) wifi: add ssid=SISTEL CONVIDADO, chan=1 to scan history
I (3563) wifi: profile match: ss_state=0x7
I (3563) wifi: update scan history ssid=SISTEL CONVIDADO, channel=1
I (3579) wifi: scan end: arg=0x0, status=0, ss_state=0x7
I (3580) wifi: find first mathched ssid, scan done
I (3580) wifi: back home chan=<1,0>, current chan=<1,0>
I (3583) wifi: filter: set rx policy=4
I (3586) wifi: first chan=1
I (3589) wifi: scan_done: arg=0x0, status=0, cur_time=445029, scan_id=128, scan state=0
I (3597) wifi: call scan_done cb, arg=0x0
I (3600) wifi: handoff_cb: status=0
I (3604) wifi: best bss has set.
I (3607) wifi: ap found, mac=0e:ec:da:b4:03:70
I (3611) wifi: bssid=0e:ec:da:b4:03:70, LR=0
I (3615) wifi: new_bss=0x3ffb39b0, cur_bss=0x0, new_chan=<1,0>, cur_chan=1
I (3621) wifi: filter: set rx policy=5
I (3625) wifi: sta/ap in the same channel, but ap is ht40, use ht40
I (3631) wifi: new:<1,1>, old:<1,0>, ap:<1,1>, sta:<1,0>, prof:1
I (3636) wifi: ht40u freq=2422, chan=1
I (3640) wifi: connect_op: status=0, auth=5, cipher=3
I (3645) wifi: auth mode is not none
I (4214) wifi: connect_bss: auth=1, reconnect=0
I (4214) wifi: state: init -> auth (b0)
I (4214) wifi: start 1s AUTH timer
I (4214) wifi: clear scan ap list
I (5214) wifi: auth timeout
I (5215) wifi: state: auth -> init (200)
I (5215) wifi: connect step 1 -> 4, status=1, err_time=1
I (5215) wifi: stop beacon/connect timer
I (5218) wifi: reason: auth expire(2)
I (5222) wifi: add bssid 0e:ec:da:b4:03:70 to blacklist, cnt=0
I (5227) wifi: stop CSA timer
I (5230) wifi: remove 0e:ec:da:b4:03:70 from rc list
I (5235) wifi: new:<1,0>, old:<1,1>, ap:<1,1>, sta:<1,0>, prof:1
I (5240) wifi: ht20 freq=2412, chan=1
I (5244) wifi: filter: set rx policy=8
I (5247) wifi: Send disconnect event, reason=2, AP number=0
//Fail to connect in WiFi (over 40seg)
Code: Select all
I (3351) wifi: mode : sta (3c:71:bf:6e:a9:fc) + softAP (3c:71:bf:6e:a9:fd)
I (3358) wifi: filter: set rx policy=9
I (3361) wifi: ht20 freq=2412, chan=1
I (3368) wifi: Start wifi disconnect
I (3368) wifi: connect step 0 -> 0, status=0, err_time=0
I (3373) wifi: connect status 0 -> 0, step=0, err_time=0
I (3378) wifi: filter: set rx policy=8
I (3381) wifi: clear blacklist
I (3384) wifi: Start wifi connect
I (3387) wifi: connect step 0 -> 0, status=0, err_time=0
I (3392) wifi: connect chan=0
I (3395) wifi: nvs=0, ssid=SISTEL CONVIDADO, channel=255
I (3400) wifi: ssid=SISTEL CONVIDADO match nvs 0, channel=255
I (3405) wifi: first chan=1
I (3408) wifi: connect status 0 -> 1, step=0, err_time=0
I (3413) wifi: connect step 0 -> 1, status=1, err_time=0
I (3418) wifi: filter: set rx policy=3
I (3421) wifi: clear scan ap list
I (3424) wifi: start scan: type=0x50f, priority=2, cb=0x40126b98, arg=0x0, ss_state=0x1, time=239086, index=0
0x40126b98: cnx_start_handoff_cb at ??:?
I (3434) wifi: inter_channel_timeout: arg=0x0, ss_state=0x1
I (3439) wifi: perform scan: ss_state=0x9, chan<1,0>, dur<100,150>
I (3445) wifi: change: chan<1,0>, dur<100,150>
I (3449) wifi: enter start op, arg=0x3ffb5878
I (3453) wifi: scan operation: state=0x3, chan<1,0>, arg=0x3ffb5878, status=0
I (3460) wifi: scan specific ssid=SISTEL CONVIDADO
I (3465) wifi: start min timer
I (3468) wifi: start max timer
I (3477) wifi: profile match: ss_state=0x7
I (3478) wifi: scan histroy table is not full yet, add
I (3479) wifi: add ssid=SISTEL CONVIDADO, chan=1 to scan history
I (3485) wifi: profile match: ss_state=0x7
I (3489) wifi: update scan history ssid=SISTEL CONVIDADO, channel=1
I (3579) wifi: profile match: ss_state=0x7
I (3580) wifi: update scan history ssid=SISTEL CONVIDADO, channel=1
I (3620) wifi: scan end: arg=0x0, status=0, ss_state=0x7
I (3621) wifi: find first mathched ssid, scan done
I (3621) wifi: back home chan=<1,0>, current chan=<1,0>
I (3624) wifi: filter: set rx policy=4
I (3627) wifi: first chan=1
I (3630) wifi: scan_done: arg=0x0, status=0, cur_time=444622, scan_id=128, scan state=0
I (3638) wifi: call scan_done cb, arg=0x0
I (3641) wifi: handoff_cb: status=0
I (3645) wifi: best bss has set.
I (3648) wifi: ap found, mac=0e:ec:da:b4:03:70
I (3652) wifi: bssid=0e:ec:da:b4:03:70, LR=0
I (3656) wifi: new_bss=0x3ffb39b0, cur_bss=0x0, new_chan=<1,0>, cur_chan=1
I (3662) wifi: filter: set rx policy=5
I (3666) wifi: sta/ap in the same channel, but ap is ht40, use ht40
I (3672) wifi: new:<1,1>, old:<1,0>, ap:<1,1>, sta:<1,0>, prof:1
I (3678) wifi: ht40u freq=2422, chan=1
I (3681) wifi: connect_op: status=0, auth=5, cipher=3
I (3686) wifi: auth mode is not none
I (4255) wifi: connect_bss: auth=1, reconnect=0
I (4255) wifi: state: init -> auth (b0)
I (4255) wifi: start 1s AUTH timer
I (4255) wifi: clear scan ap list
I (4264) wifi: recv auth: seq=2, status=0
I (4264) wifi: state: auth -> assoc (0)
I (4265) wifi: restart connect 1s timer for assoc
I (4270) wifi: recv auth: seq=2, status=0
I (4273) wifi: not auth state, ignore
I (4278) wifi: recv assoc: type=0x10
I (4280) wifi: filter: set rx policy=6
I (4283) wifi: state: assoc -> run (10)
I (4287) wifi: start 10s connect timer for 4 way handshake
I (4292) wifi: wpa_psk start
I (4295) wifi: wpa_psk handle succeed
I (4326) wifi: wpa_psk start
I (4327) wifi: wpa_psk handle succeed
I (4331) wifi: connected with SISTEL CONVIDADO, channel 1, bssid = 0e:ec:da:b4:03:70
I (4331) wifi: remove all except 0e:ec:da:b4:03:70 from rc list
I (4334) wifi: clear blacklist
I (4337) wifi: filter: set rx policy=7
I (4340) wifi: pm start, type: 1
I (4343) wifi: Send sta connected event
I (4347) wifi: connect status 1 -> 5, step=1, err_time=0
//Fail to get IP DHCP (over 40seg)