WiFi WPA3 加密方式讲解

一、什么是 WPA3 加密方式

WPA3(Wi-Fi Protected Access 3,第三代Wi-Fi访问保护)是Wi-Fi联盟组织于2018年发布的新一代Wi-Fi(WiFi)加密协议,它对WPA2进行了改进,增加了许多新的功能,为用户和Wi-Fi网络之间的数据传输提供更加强大的加密保护。根据Wi-Fi网络的用途和安全需求不同,WPA3分为WPA3个人版、WPA3企业版以及针对开放性Wi-Fi网络的OWE认证。

二、常见 WiFi 加密方式对比

常见的WiFi加密方式包括WEP、‌WPA/WPA2、‌WPA-PSK/WPA2-PSK、‌WPA3,‌它们各有特点,‌适用于不同的安全需求和应用场景。‌

WEP (Wired Equivalent Privacy) 是一种较早的加密方式,‌但在2003年已被WPA加密淘汰,‌主要因为其存在多个安全弱点,‌并且与现代无线路由设备的技术标准不兼容,‌影响了传输速率。‌

WPA (Wi-Fi Protected Access) / WPA2 enterprise是一种企业级安全的加密类型,‌需要安装Radius服务器进行认证,‌适用于对安全性有较高要求的企业环境。‌普通用户由于不需要Radius服务器认证,‌一般不使用此种加密方式。‌

WPA-PSK (Pre-Shared Key)/ WPA2-PSK 是现在广泛使用的加密类型,‌设置简单且相对安全。‌它支持两种加密算法:‌TKIP和AES。‌AES算法相比TKIP提供了更好的安全性和更快的无线网络传输速率。‌

WPA3 是最新的加密技术,‌提供了更高级别的安全性,‌支持“Wi-Fi增强开放”技术,‌增强了公共Wi-Fi的连接安全,‌防止暴力破解,‌减少流量监听风险,‌并简化了安全配置过程。‌

三、如何使用 WPA3 加密方式

ESP8266 下面使用方法如下:

  1. menuconfig 中需要 enable WPA3-psk在这里插入图片描述

  2. wifi config 中需要加上 .pmf_cfg.capable=true, 如下:

 wifi_pmf_config_t pmf_cfg = {0};

    wifi_config_t wifi_config = {
        .sta = {
            .ssid = EXAMPLE_ESP_WIFI_SSID,
            .password = EXAMPLE_ESP_WIFI_PASS,
            .pmf_cfg.capable=true
        },
    };

使用 RTOS SDK 下面 station 示例修改做的测试:
在这里插入图片描述

ESP32 使用起来会比较简单, 只需要 menuconfig 中 enable WPA3-psk 即可, 默认情况下是开启的。
在这里插入图片描述

使用 station 例程测试结果如下:
在这里插入图片描述

四、WPA3 问题相关分享

Q1、如果在 menuconfig 中将 WiFi scan auth mode threshold 设置为 WPA2/WPA3 PSK 时, 为什么连接不上 WPA2 加密方式的路由, 只能连接上 WPA3 或者 WPA2/WPA3 加密方式的路由?
在这里插入图片描述
这个是因为 authmode threshold 排序是这样的, OPEN < WEP < WPA_PSK < OWE < WPA2_PSK = WPA_WPA2_PSK < WAPI_PSK < WPA3_PSK = WPA2_WPA3_PSK = DPP, 也就是说 WPA2_WPA3_PSK 会以 WPA3_PSK 作为 authmode threshold 的, 所以此时无法连接上 WPA2 加密方式的路由。

/* Strength of authmodes */
/* OPEN < WEP < WPA_PSK < OWE < WPA2_PSK = WPA_WPA2_PSK < WAPI_PSK < WPA3_PSK = WPA2_WPA3_PSK = DPP */
typedef enum {
    WIFI_AUTH_OPEN = 0,         /**< authenticate mode : open */
    WIFI_AUTH_WEP,              /**< authenticate mode : WEP */
    WIFI_AUTH_WPA_PSK,          /**< authenticate mode : WPA_PSK */
    WIFI_AUTH_WPA2_PSK,         /**< authenticate mode : WPA2_PSK */
    WIFI_AUTH_WPA_WPA2_PSK,     /**< authenticate mode : WPA_WPA2_PSK */
    WIFI_AUTH_ENTERPRISE,       /**< authenticate mode : WiFi EAP security */
    WIFI_AUTH_WPA2_ENTERPRISE = WIFI_AUTH_ENTERPRISE,  /**< authenticate mode : WiFi EAP security */
    WIFI_AUTH_WPA3_PSK,         /**< authenticate mode : WPA3_PSK */
    WIFI_AUTH_WPA2_WPA3_PSK,    /**< authenticate mode : WPA2_WPA3_PSK */
    WIFI_AUTH_WAPI_PSK,         /**< authenticate mode : WAPI_PSK */
    WIFI_AUTH_OWE,              /**< authenticate mode : OWE */
    WIFI_AUTH_WPA3_ENT_192,     /**< authenticate mode : WPA3_ENT_SUITE_B_192_BIT */
    WIFI_AUTH_WPA3_EXT_PSK,     /**< this authentication mode will yield same result as WIFI_AUTH_WPA3_PSK and not recommended to be used. It will be deprecated in future, please use WIFI_AUTH_WPA3_PSK instead. */
    WIFI_AUTH_WPA3_EXT_PSK_MIXED_MODE, /**< this authentication mode will yield same result as WIFI_AUTH_WPA3_PSK and not recommended to be used. It will be deprecated in future, please use WIFI_AUTH_WPA3_PSK instead.*/
    WIFI_AUTH_DPP,              /**< authenticate mode : DPP */
    WIFI_AUTH_MAX
} wifi_auth_mode_t;

Q2. 使用 ESP32C6 芯片, 连接华为凌霄路由器会特别慢, 有时需要 10 多秒
对应日志如下:

[17:04:33:330]D (1701) wifi:filter: set rx policy=0
[17:04:33:344]D (1701) nvs: nvs_get sta.phybw 1
[17:04:33:344]I (1701) wifi:mode : sta (40:4c:ca:4b:d2:98)
[17:04:33:344]I (1711) wifi:enable tsf
[17:04:33:344]D (1711) wifi:filter: set rx policy=1
[17:04:33:344]D (1711) wifi:connect status 0 -> 0
[17:04:33:360]D (1721) event: running post WIFI_EVENT:40 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:33:371]D (1731) event: running post WIFI_EVENT:2 with handler 0x42018b48 and context 0x40823d04 on loop 0x40822be4
[17:04:33:371]D (1741) wifi_init_default: wifi_start esp-netif:0x40823b08 event-id2
[17:04:33:389]D (1741) wifi_init_default: WIFI mac address: 40 4c ca 4b d2 98
[17:04:33:389]D (1751) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x42014300
[17:04:33:400]D (1761) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:33:404]D (1761) esp_netif_handlers: esp_netif action has started with netif0x40823b08 from event_id=2
[17:04:33:404]D (1771) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x4201509e
[17:04:33:420]D (1781) esp_netif_lwip: esp_netif_start_api 0x40823b08
[17:04:33:420]D (1781) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x40823b08
[17:04:33:425]D (1791) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:33:426]D (1791) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:33:438]D (1801) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:33:449]D (1811) event: running post WIFI_EVENT:2 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:33:449]D (1821) wifi:Start wifi connect
[17:04:33:449]D (1821) wifi:connect status 0 -> 0
[17:04:33:460]D (1821) wifi:connect chan=0
[17:04:33:460]D (1821) wifi:first chan=1
[17:04:33:460]D (1831) wifi:connect status 0 -> 1
[17:04:33:460]D (1831) wifi:filter: set rx policy=3
[17:04:33:477]D (1831) wifi:clear scan ap list
[17:04:33:478]D (1841) wifi:start scan: type=0x50f, priority=2, cb=0x4203a688, arg=0x0, ss_state=0x1, time=1455768, index=0
[17:04:33:483]D (1851) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
[17:04:33:483]I (1851) wifi station: wifi_init_sta finished.
[17:04:33:495]D (1861) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:33:495]I (1861) wifi:(mac)omc_ul_mu_data_disable_rx:1
[17:04:33:510]I (1871) wifi:(phy)ppe_thresholds_present:0, nominal_packet_padding:2
[17:04:33:517]I (1871) wifi:(phy)dcm tx(constellation:1, nss:0), dcm rx(constellation:1, nss:0)
[17:04:33:517]I (1881) wifi:(phy)rx_mcs_map:0xfffa(for_1_ss:2), tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1
[17:04:33:533]I (1891) wifi:(opr)len:7, TWT Required:0, VHT Operation Present:0, 6GHz Info Present:0, Co-Hosted BSS:0, Basic MCS and NSS:0xfffc
[17:04:33:537]I (1901) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1022(32704 us), ER-SU-Disable:0
[17:04:33:555]I (1911) wifi:(opr)len:7, BSS Color:7, disabled:0, Partial BSS Color:0
[17:04:33:555]I (1921) wifi:(spr)len:3, ctrl:0x5, PSR Disallowed:1, Non-SRG OBSS PD SR Disallowed:0
[17:04:33:560]I (1921) wifi:(spr)len:3, ctrl:0x5, Non-SRG Offset Present:1, SRG Info Present:0
[17:04:33:573]I (1931) wifi:(spr)Non-SRG OBSS PD Max Offset:0, PD:-82(dB)
[17:04:33:573]I (1941) wifi:(uora)len:2, EOCWMin:2, EOCWMax:5
[17:04:33:573]D (1941) wpa: rsn_ie - hexdump(len=26):
[17:04:33:589]D (1941) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:33:589]D (1951) wpa: 00 0f ac 02 00 0f ac 08 8c 00 
[17:04:33:592]D (1961) wifi:profile match: ss_state=0x7
[17:04:33:592]D (1961) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:33:592]D (1971) wifi:profile match: ss_state=0x7
[17:04:33:605]D (1971) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:33:606]D (1981) wifi:profile match: ss_state=0x7
[17:04:33:618]D (1981) wifi:scan end: arg=0x0, status=0, ss_state=0x7
[17:04:33:618]D (1981) wifi:find first mathched ssid, scan done
[17:04:33:627]D (1991) wifi:filter: set rx policy=4
[17:04:33:627]D (1991) wifi:first chan=1
[17:04:33:627]D (1991) wifi:handoff_cb: status=0
[17:04:33:627]D (2001) wifi:ap found, mac=62:16:1b:88:83:c2
[17:04:33:638]D (2001) wifi:new_bss=0x4081a5e8, cur_bss=0x0, new_chan=<1,0>, cur_chan=1
[17:04:33:638]D (2011) wifi:filter: set rx policy=5
[17:04:33:651]D (2011) wpa: WPA: set AP RSNXE - hexdump(len=0):
[17:04:33:651]I (2021) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:33:666]D (2021) wifi:connect_op: status=0, auth=9, cipher=3 
[17:04:33:667]I (2031) wifi:(connect)dot11_authmode:0x6, pairwise_cipher:0x3, group_cipher:0x3
[17:04:33:673]D (2031) wpa: RSN: PMKSA cache search - network_ctx=0x0 try_opportunistic=0
[17:04:33:673]D (2041) wpa: RSN: Search for BSSID 62:16:1b:88:83:c2
[17:04:33:682]D (2051) wpa: RSN: No PMKSA cache entry found
[17:04:33:682]D (2051) wifi:auth mode is not none
[17:04:33:696]D (2051) wifi:connect_bss: auth=1, reconnect=0
[17:04:33:696]I (2061) wifi:state: init -> auth (b0)
[17:04:33:696]D (2061) wpa: SAE: Selecting supported ECC group 19
[17:04:33:712]D (2071) intr_alloc: Connected src 75 to int 13 (cpu 0)
[17:04:33:712]D (2081) wpa: SAE: password - hexdump(len=8):
[17:04:33:712]D (2081) wpa: 31 71 32 77 33 65 34 72 
[17:04:33:715]D (2081) wpa: SAE: PWE derivation - addr1=40:4c:ca:4b:d2:98 addr2=62:16:1b:88:83:c2
[17:04:33:728]D (2091) gdma: new group (0) at 0x4082dcd4
[17:04:33:728]D (2091) gdma: new pair (0,0) at 0x4082dbe8
[17:04:33:728]D (2101) gdma: new tx channel (0,0) at 0x4082dc9c
[17:04:33:741]D (2101) gdma: new rx channel (0,0) at 0x4082dd4c
[17:04:33:741]D (2111) gdma: tx channel (0,0), (1:16) bytes aligned, burst enabled
[17:04:33:756]D (2111) gdma: rx channel (0,0), (1:16) bytes aligned, burst disabled
[17:04:33:929]D (2301) wpa: SAE: PWE - hexdump(len=64):
[17:04:33:930]D (2301) wpa: 48 86 50 07 7d a4 d3 65 2a d6 23 2f b3 2f 1f 24 
[17:04:33:938]D (2301) wpa: 4d ec 09 92 0c 51 67 39 7b 06 c4 6e cb 49 55 5d 
[17:04:33:939]D (2311) wpa: b0 e0 31 df 8e 81 40 4a 15 4b 15 8f 83 55 a9 aa 
[17:04:33:959]D (2311) wpa: 94 53 3d 1d 0b 75 20 e0 ba 16 aa bc e3 5c 45 d8 
[17:04:33:960]D (2321) intr_alloc: Connected src 73 to int 14 (cpu 0)
[17:04:33:978]D (2341) wpa: SAE: own commit-scalar - hexdump(len=32):
[17:04:33:978]D (2341) wpa: 73 00 a6 de 56 29 65 a0 f1 20 3f 32 f4 31 58 7d 
[17:04:33:978]D (2341) wpa: c5 ba a7 3d da f6 0c b6 5d 28 1a c4 32 36 e5 39 
[17:04:34:000]D (2341) wpa: SAE: own commit-element(x) - hexdump(len=32):
[17:04:34:000]D (2351) wpa: 24 37 5f e9 84 b9 d1 a4 cd 2c 0c 47 a9 e4 fe 5d 
[17:04:34:000]D (2351) wpa: db c8 71 41 e8 fd a3 16 c1 0b 72 02 c4 35 0d 6a 
[17:04:34:001]D (2361) wpa: SAE: own commit-element(y) - hexdump(len=32):
[17:04:34:025]D (2371) wpa: e8 9f d3 9b aa 92 8d 80 88 2e e9 7b df a9 cb 49 
[17:04:34:026]D (2371) wpa: 6e 53 52 0c 04 ff 8e e6 fb cf f9 1f f5 88 97 bc 
[17:04:34:026]D (2381) wifi:start 1s AUTH timer
[17:04:34:042]D (2381) wifi:clear scan ap list
[17:04:38:004]D (6381) wifi:auth timeout
[17:04:38:012]I (6381) wifi:state: auth -> init (200)
[17:04:38:012]D (6381) wifi:stop beacon and connect timers
[17:04:38:012]D (6381) wifi:connect status 1 -> 4
[17:04:38:012]D (6381) wifi:reason: auth expire(2)
[17:04:38:023]D (6391) wifi:add bssid 62:16:1b:88:83:c2 to blacklist, cnt=0
[17:04:38:023]D (6391) wifi:stop CSA timer
[17:04:38:033]D (6391) wifi:remove 62:16:1b:88:83:c2 from rc list
[17:04:38:033]I (6401) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:38:033]D (6411) wifi:filter: set rx policy=8
[17:04:38:044]D (6411) wpa: ELOOP: wpa_sm_notify_disassoc:2257 called to remove timer handler=0x4206c270, removed count=0
[17:04:38:056]D (6421) wpa: WPA: Clear old PMK and PTK
[17:04:38:056]D (6421) wifi:Send disconnect event, reason=2, AP number=0
[17:04:38:067]D (6431) event: running post WIFI_EVENT:5 with handler 0x42018902 and context 0x40823d94 on loop 0x40822be4
[17:04:38:078]D (6441) esp_netif_handlers: esp_netif action disconnected with netif0x40823b08 from event_id=5
[17:04:38:080]D (6451) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x42015638
[17:04:38:089]D (6451) esp_netif_lwip: esp_netif_down_api esp_netif:0x40823b08
[17:04:38:100]D (6461) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x40823b08
[17:04:38:100]D (6471) esp_netif_lwip: if0x40823b08 start ip lost tmr: interval=120
[17:04:38:113]D (6471) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:38:113]D (6481) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:38:124]D (6491) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:38:133]D (6491) event: running post WIFI_EVENT:5 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:38:133]D (6501) wifi:Start wifi connect
[17:04:38:134]D (6501) wifi:connect status 4 -> 0
[17:04:38:145]D (6511) wifi:connect chan=0
[17:04:38:145]D (6511) wifi:first chan=1
[17:04:38:145]D (6511) wifi:connect status 0 -> 1
[17:04:38:145]D (6521) wifi:filter: set rx policy=3
[17:04:38:159]D (6521) wifi:clear scan ap list
[17:04:38:159]D (6521) wifi:start scan: type=0x50f, priority=2, cb=0x4203a688, arg=0x0, ss_state=0x1, time=6140412, index=0
[17:04:38:168]D (6531) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
[17:04:38:168]I (6541) wifi station: retry to connect to the AP
[17:04:38:178]I (6541) wifi station: connect to the AP fail
[17:04:38:189]D (6541) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:38:189]D (6551) wifi:find the 62:16:1b:88:83:c2 in blacklist.
[17:04:38:189]
[17:04:38:195]D (6571) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:38:204]D (6571) wifi:find the 62:16:1b:88:83:c2 in blacklist.
[17:04:38:204]
[17:04:38:297]D (6661) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:297]D (6661) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
[17:04:38:404]D (6781) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:419]D (6781) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
[17:04:38:545]D (6901) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:545]D (6901) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
[17:04:38:653]D (7021) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:654]D (7021) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
[17:04:38:777]D (7141) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:777]D (7141) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
[17:04:38:901]D (7261) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:38:901]D (7261) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
[17:04:39:025]D (7381) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:025]D (7381) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
[17:04:39:134]D (7501) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:134]D (7501) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
[17:04:39:259]D (7621) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:259]D (7621) wifi:perform scan: ss_state=0x9, chan<10,0>, dur<0,120>
[17:04:39:387]D (7741) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:387]D (7741) wifi:perform scan: ss_state=0x9, chan<11,0>, dur<0,120>
[17:04:39:509]D (7861) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:510]D (7861) wifi:perform scan: ss_state=0x9, chan<12,0>, dur<360,360>
[17:04:39:868]D (8221) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:39:868]D (8221) wifi:perform scan: ss_state=0x9, chan<13,0>, dur<360,360>
[17:04:40:227]D (8591) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:40:227]D (8591) wifi:perform scan: ss_state=0x9, chan<14,0>, dur<360,360>
[17:04:40:573]D (8951) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:40:573]D (8951) wifi:filter: set rx policy=4
[17:04:40:573]D (8951) wifi:first chan=1
[17:04:40:584]D (8951) wifi:handoff_cb: status=0
[17:04:40:584]D (8951) wifi:clear blacklist
[17:04:40:584]D (8951) wifi:clear rc list
[17:04:40:584]D (8951) wifi:clear blacklist
[17:04:40:593]D (8961) wifi:Send disconnect event, reason=205
[17:04:40:605]D (8961) wpa: ELOOP: wpa_sm_notify_disassoc:2257 called to remove timer handler=0x4206c270, removed count=0
[17:04:40:605]D (8971) wpa: WPA: Clear old PMK and PTK
[17:04:40:605]D (8971) wifi:connect status 1 -> 3
[17:04:40:615]D (8981) wifi:disable connect timer
[17:04:40:615]D (8981) wifi:clear scan ap list
[17:04:40:620]D (8981) event: running post WIFI_EVENT:5 with handler 0x42018902 and context 0x40823d94 on loop 0x40822be4
[17:04:40:631]D (8991) esp_netif_handlers: esp_netif action disconnected with netif0x40823b08 from event_id=5
[17:04:40:645]D (9001) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x42015638
[17:04:40:645]D (9011) esp_netif_lwip: esp_netif_down_api esp_netif:0x40823b08
[17:04:40:661]D (9021) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x40823b08
[17:04:40:661]D (9021) esp_netif_lwip: if0x40823b08 start ip lost tmr: already started
[17:04:40:665]D (9031) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:40:675]D (9041) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:40:675]D (9041) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:40:688]D (9051) event: running post WIFI_EVENT:5 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:40:689]D (9061) wifi:Start wifi connect
[17:04:40:699]D (9061) wifi:connect status 3 -> 0
[17:04:40:699]D (9061) wifi:connect chan=0
[17:04:40:699]D (9071) wifi:first chan=1
[17:04:40:699]D (9071) wifi:connect status 0 -> 1
[17:04:40:709]D (9071) wifi:filter: set rx policy=3
[17:04:40:709]D (9081) wifi:clear scan ap list
[17:04:40:723]D (9081) wifi:start scan: type=0x50f, priority=2, cb=0x4203a688, arg=0x0, ss_state=0x1, time=8697202, index=0
[17:04:40:723]D (9091) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
[17:04:40:733]I (9091) wifi station: retry to connect to the AP
[17:04:40:733]I (9101) wifi station: connect to the AP fail
[17:04:40:743]D (9101) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:40:743]I (9111) wifi:(mac)omc_ul_mu_data_disable_rx:1
[17:04:40:754]I (9111) wifi:(phy)ppe_thresholds_present:0, nominal_packet_padding:2
[17:04:40:759]I (9121) wifi:(phy)dcm tx(constellation:1, nss:0), dcm rx(constellation:1, nss:0)
[17:04:40:770]I (9131) wifi:(phy)rx_mcs_map:0xfffa(for_1_ss:2), tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1
[17:04:40:784]I (9141) wifi:(opr)len:7, TWT Required:0, VHT Operation Present:0, 6GHz Info Present:0, Co-Hosted BSS:0, Basic MCS and NSS:0xfffc
[17:04:40:795]I (9151) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1022(32704 us), ER-SU-Disable:0
[17:04:40:795]I (9161) wifi:(opr)len:7, BSS Color:7, disabled:0, Partial BSS Color:0
[17:04:40:804]I (9161) wifi:(spr)len:3, ctrl:0x5, PSR Disallowed:1, Non-SRG OBSS PD SR Disallowed:0
[17:04:40:804]I (9171) wifi:(spr)len:3, ctrl:0x5, Non-SRG Offset Present:1, SRG Info Present:0
[17:04:40:820]I (9181) wifi:(spr)Non-SRG OBSS PD Max Offset:0, PD:-82(dB)
[17:04:40:820]I (9181) wifi:(uora)len:2, EOCWMin:2, EOCWMax:5
[17:04:40:820]D (9191) wpa: rsn_ie - hexdump(len=26):
[17:04:40:834]D (9191) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:40:834]D (9201) wpa: 00 0f ac 02 00 0f ac 08 8c 00 
[17:04:40:834]D (9201) wifi:profile match: ss_state=0x7
[17:04:40:842]D (9211) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:40:842]D (9211) wifi:profile match: ss_state=0x7
[17:04:40:856]D (9221) wifi:scan end: arg=0x0, status=0, ss_state=0x7
[17:04:40:856]D (9221) wifi:find first mathched ssid, scan done
[17:04:40:856]D (9231) wifi:filter: set rx policy=4
[17:04:40:865]D (9231) wifi:first chan=1
[17:04:40:865]D (9231) wifi:handoff_cb: status=0
[17:04:40:865]D (9231) wifi:ap found, mac=62:16:1b:88:83:c2
[17:04:40:876]D (9241) wifi:new_bss=0x4081a5e8, cur_bss=0x0, new_chan=<1,0>, cur_chan=1
[17:04:40:883]D (9241) wifi:filter: set rx policy=5
[17:04:40:883]D (9251) wpa: WPA: set AP RSNXE - hexdump(len=0):
[17:04:40:893]I (9251) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:40:894]D (9261) wifi:connect_op: status=0, auth=9, cipher=3 
[17:04:40:904]I (9261) wifi:(connect)dot11_authmode:0x6, pairwise_cipher:0x3, group_cipher:0x3
[17:04:40:905]D (9271) wpa: RSN: PMKSA cache search - network_ctx=0x0 try_opportunistic=0
[17:04:40:915]D (9281) wpa: RSN: Search for BSSID 62:16:1b:88:83:c2
[17:04:40:915]D (9281) wpa: RSN: No PMKSA cache entry found
[17:04:40:916]D (9291) wifi:auth mode is not none
[17:04:40:926]D (9291) wifi:connect_bss: auth=1, reconnect=0
[17:04:40:926]I (9291) wifi:state: init -> auth (b0)
[17:04:40:942]D (9301) wpa: SAE: Selecting supported ECC group 19
[17:04:40:942]D (9311) wpa: SAE: password - hexdump(len=8):
[17:04:40:942]D (9311) wpa: 31 71 32 77 33 65 34 72 
[17:04:40:955]D (9311) wpa: SAE: PWE derivation - addr1=40:4c:ca:4b:d2:98 addr2=62:16:1b:88:83:c2
[17:04:41:128]D (9501) wpa: SAE: PWE - hexdump(len=64):
[17:04:41:128]D (9501) wpa: 48 86 50 07 7d a4 d3 65 2a d6 23 2f b3 2f 1f 24 
[17:04:41:139]D (9501) wpa: 4d ec 09 92 0c 51 67 39 7b 06 c4 6e cb 49 55 5d 
[17:04:41:139]D (9511) wpa: b0 e0 31 df 8e 81 40 4a 15 4b 15 8f 83 55 a9 aa 
[17:04:41:158]D (9511) wpa: 94 53 3d 1d 0b 75 20 e0 ba 16 aa bc e3 5c 45 d8 
[17:04:41:158]D (9531) wpa: SAE: own commit-scalar - hexdump(len=32):
[17:04:41:169]D (9531) wpa: 36 ae 8a 07 1f 16 ff fc ea 93 8a cb b0 4d 78 d4 
[17:04:41:183]D (9531) wpa: ee 76 84 b1 16 46 0f 22 b5 ed 8f 38 c3 ec e3 09 
[17:04:41:183]D (9541) wpa: SAE: own commit-element(x) - hexdump(len=32):
[17:04:41:194]D (9551) wpa: a5 bb 1f 53 f0 b8 30 be 83 86 ea aa 53 d1 b3 51 
[17:04:41:194]D (9551) wpa: 91 a3 22 2b 79 0e f5 15 7a 0f 3b 50 2f 63 e5 46 
[17:04:41:203]D (9561) wpa: SAE: own commit-element(y) - hexdump(len=32):
[17:04:41:203]D (9561) wpa: 39 b2 3b b5 67 5d 83 f1 24 cd 1f 51 55 d8 10 7f 
[17:04:41:215]D (9571) wpa: 55 92 53 63 56 a5 a7 2f a3 15 ac 94 a4 6a 55 d6 
[17:04:41:215]D (9571) wifi:start 1s AUTH timer
[17:04:41:215]D (9581) wifi:clear scan ap list
[17:04:41:290]D (9661) wifi:recv auth: seq=1, status=0
[17:04:41:290]D (9661) wpa: SAE: Peer commit-scalar - hexdump(len=32):
[17:04:41:303]D (9671) wpa: d3 20 ef 7d 96 f3 80 5e bf 3c 13 96 bf 79 e4 8d 
[17:04:41:303]D (9671) wpa: 45 09 78 d5 a4 de cb 64 f0 2e f4 0b f6 35 26 ca 
[17:04:41:312]D (9671) wpa: SAE: Peer commit-element(x) - hexdump(len=32):
[17:04:41:312]D (9681) wpa: 35 71 c8 3e 0b 71 3a 5a 26 fc e1 64 ff e6 46 0e 
[17:04:41:324]D (9691) wpa: aa 21 f8 2a 8b 40 4c ec 88 07 fd 3a 95 46 44 b3 
[17:04:41:324]D (9691) wpa: SAE: Peer commit-element(y) - hexdump(len=32):
[17:04:41:337]D (9701) wpa: d8 7c 8c 89 8f 11 6e 1f 52 99 c2 bd 60 57 ec b0 
[17:04:41:353]D (9701) wpa: 4a 91 24 bd 6e 51 80 95 70 af fb 58 c9 03 fe 42 
[17:04:41:353]D (9711) wpa: SAE: Possible elements at the end of the frame - hexdump(len=0):
[17:04:41:372]D (9751) wpa: SAE: k - hexdump(len=32):
[17:04:41:372]D (9751) wpa: e2 ff 88 bc 84 42 b4 3c 17 bd c5 74 1d d3 7a b3 
[17:04:41:384]D (9751) wpa: f7 cb d5 fb 01 28 b5 bc c2 53 d4 10 8e db 1c 64 
[17:04:41:384]D (9751) wpa: SAE: salt for keyseed derivation - hexdump(len=32):
[17:04:41:395]D (9761) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:41:406]D (9761) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:41:406]D (9771) wpa: SAE: keyseed - hexdump(len=32):
[17:04:41:406]D (9771) wpa: 7d bd 58 2c 08 79 76 17 6d 8a 12 24 ea 92 93 bc 
[17:04:41:417]D (9781) wpa: 47 51 af bf f3 57 4a e3 b7 a0 72 82 74 50 56 d1 
[17:04:41:422]D (9791) wpa: SAE: PMKID - hexdump(len=16):
[17:04:41:422]D (9791) wpa: 09 cf 79 85 b6 0a 80 5a a9 cf 9e 62 6f c7 5d 62 
[17:04:41:434]D (9801) wpa: SAE: KCK - hexdump(len=32):
[17:04:41:434]D (9801) wpa: 8a 91 d6 f2 f8 14 1b aa ab a7 6d 7e aa 42 b7 0f 
[17:04:41:444]D (9811) wpa: 4e db 9e ab 14 0e dc 1a 6d 27 5a 52 8c de 0b 2a 
[17:04:41:444]D (9811) wpa: SAE: PMK - hexdump(len=32):
[17:04:41:458]D (9821) wpa: 46 9b 5b 4f f0 5d 0f 8c 8d f7 e0 99 65 82 15 82 
[17:04:41:458]D (9821) wpa: 85 86 dd 27 fd 4a 93 d0 22 59 30 a8 0f 86 eb bd 
[17:04:41:467]D (9841) wifi:recv auth: seq=2, status=0
[17:04:41:467]D (9841) wpa: SAE: peer-send-confirm 65535
[17:04:41:480]D (9841) wpa: ELOOP: pmksa_cache_set_expiration:76 called to remove timer handler=0x42071fe8, removed count=0
[17:04:41:484]D (9851) wpa: ELOOP: Added one timer from pmksa_cache_set_expiration:85 to call 0x42071fe8, current order=0
[17:04:41:495]D (9861) wpa: RSN: Added PMKSA cache entry for 62:16:1b:88:83:c2 network_ctx=0x0
[17:04:41:495]I (9861) wifi:state: auth -> assoc (0)
[17:04:41:507]D (9881) wifi:recv assoc: type=0x10
[17:04:41:507]I (9881) wifi:Association refused temporarily, comeback time 1000 (TUs)
[17:04:41:525]D (9881) wpa: WPA: Association event - clear replay counter
[17:04:41:525]D (9881) wpa: WPA: Clear old PTK
[17:04:42:539]I (10901) wifi:state: assoc -> assoc (0)
[17:04:42:539]D (10911) wifi:recv assoc: type=0x10
[17:04:42:552]E (10911) wifi:Association refused temporarily, comeback time 4294967266 (TUs) too long, max allowed 5000 (TUs)
[17:04:42:558]I (10921) wifi:state: assoc -> init (d010)
[17:04:42:558]D (10921) wifi:stop beacon and connect timers
[17:04:42:558]D (10921) wifi:connect status 1 -> 4
[17:04:42:568]D (10931) wifi:add bssid 62:16:1b:88:83:c2 to blacklist, cnt=0
[17:04:42:568]D (10931) wifi:stop CSA timer
[17:04:42:568]D (10941) wifi:remove 62:16:1b:88:83:c2 from rc list
[17:04:42:579]I (10941) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:42:579]D (10951) wifi:filter: set rx policy=8
[17:04:42:590]D (10951) wifi:reason: assoc comeback time too long(208)
[17:04:42:590]D (10961) wifi:Send disconnect event, reason=208, AP number=0
[17:04:42:601]D (10961) wpa: WPA: Association event - clear replay counter
[17:04:42:601]D (10971) wpa: WPA: Clear old PTK
[17:04:42:614]D (10971) event: running post WIFI_EVENT:5 with handler 0x42018902 and context 0x40823d94 on loop 0x40822be4
[17:04:42:627]D (10981) esp_netif_handlers: esp_netif action disconnected with netif0x40823b08 from event_id=5
[17:04:42:627]D (10991) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x42015638
[17:04:42:635]D (11001) esp_netif_lwip: esp_netif_down_api esp_netif:0x40823b08
[17:04:42:635]D (11001) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x40823b08
[17:04:42:647]D (11011) esp_netif_lwip: if0x40823b08 start ip lost tmr: already started
[17:04:42:660]D (11021) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:42:660]D (11021) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:42:667]D (11031) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:42:679]D (11031) event: running post WIFI_EVENT:5 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:42:679]D (11041) wifi:Start wifi connect
[17:04:42:679]D (11051) wifi:connect status 4 -> 0
[17:04:42:679]D (11051) wifi:connect chan=0
[17:04:42:693]D (11051) wifi:first chan=1
[17:04:42:693]D (11061) wifi:connect status 0 -> 1
[17:04:42:694]D (11061) wifi:filter: set rx policy=3
[17:04:42:700]D (11061) wifi:clear scan ap list
[17:04:42:700]D (11071) wifi:start scan: type=0x50f, priority=2, cb=0x4203a688, arg=0x0, ss_state=0x1, time=10684649, index=0
[17:04:42:712]D (11081) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
[17:04:42:722]D (11081) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:42:722]D (11091) wifi:find the 62:16:1b:88:83:c2 in blacklist.
[17:04:42:722]
[17:04:42:736]I (11091) wifi station: retry to connect to the AP
[17:04:42:736]I (11101) wifi station: connect to the AP fail
[17:04:42:752]D (11091) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:42:752]D (11111) wifi:find the 62:16:1b:88:83:c2 in blacklist.
[17:04:42:752]
[17:04:42:806]D (11181) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:42:814]D (11181) wifi:find the 62:16:1b:88:83:c2 in blacklist.
[17:04:42:814]
[17:04:42:845]D (11201) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:42:845]D (11201) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
[17:04:42:952]D (11321) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:42:952]D (11321) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
[17:04:43:090]D (11441) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:090]D (11441) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
[17:04:43:201]D (11561) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:201]D (11561) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
[17:04:43:334]D (11681) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:334]D (11681) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
[17:04:43:455]D (11801) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:456]D (11811) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
[17:04:43:557]D (11931) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:557]D (11931) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
[17:04:43:684]D (12051) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:684]D (12051) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
[17:04:43:806]D (12171) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:806]D (12171) wifi:perform scan: ss_state=0x9, chan<10,0>, dur<0,120>
[17:04:43:934]D (12291) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:43:934]D (12291) wifi:perform scan: ss_state=0x9, chan<11,0>, dur<0,120>
[17:04:44:059]D (12411) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:44:060]D (12411) wifi:perform scan: ss_state=0x9, chan<12,0>, dur<360,360>
[17:04:44:410]D (12771) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:44:410]D (12771) wifi:perform scan: ss_state=0x9, chan<13,0>, dur<360,360>
[17:04:44:768]D (13131) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:44:769]D (13131) wifi:perform scan: ss_state=0x9, chan<14,0>, dur<360,360>
[17:04:45:119]D (13491) wifi:scan end: arg=0x0, status=0, ss_state=0x3
[17:04:45:119]D (13491) wifi:filter: set rx policy=4
[17:04:45:119]D (13491) wifi:first chan=1
[17:04:45:129]D (13491) wifi:handoff_cb: status=0
[17:04:45:129]D (13491) wifi:clear blacklist
[17:04:45:129]D (13501) wifi:clear rc list
[17:04:45:156]D (13501) wifi:clear blacklist
[17:04:45:156]D (13501) wifi:Send disconnect event, reason=205
[17:04:45:156]D (13511) wpa: RSN: Flush PMKSA cache entry for 62:16:1b:88:83:c2
[17:04:45:156]D (13511) wpa: RSN: PMKSA cache entry free_cb: 62:16:1b:88:83:c2 reason=0
[17:04:45:164]D (13521) wpa: ELOOP: wpa_sm_notify_disassoc:2257 called to remove timer handler=0x4206c270, removed count=0
[17:04:45:164]D (13531) wpa: WPA: Clear old PMK and PTK
[17:04:45:172]D (13531) wifi:connect status 1 -> 3
[17:04:45:172]D (13541) wifi:disable connect timer
[17:04:45:172]D (13541) wifi:clear scan ap list
[17:04:45:187]D (13541) event: running post WIFI_EVENT:5 with handler 0x42018902 and context 0x40823d94 on loop 0x40822be4
[17:04:45:200]D (13551) esp_netif_handlers: esp_netif action disconnected with netif0x40823b08 from event_id=5
[17:04:45:201]D (13561) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x42015638
[17:04:45:204]D (13571) esp_netif_lwip: esp_netif_down_api esp_netif:0x40823b08
[17:04:45:217]D (13571) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x40823b08
[17:04:45:218]D (13581) esp_netif_lwip: if0x40823b08 start ip lost tmr: already started
[17:04:45:229]D (13591) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:45:232]D (13591) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:45:232]D (13601) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:45:247]D (13611) event: running post WIFI_EVENT:5 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:45:258]D (13621) wifi:Start wifi connect
[17:04:45:258]D (13621) wifi:connect status 3 -> 0
[17:04:45:258]D (13621) wifi:connect chan=0
[17:04:45:258]D (13631) wifi:first chan=1
[17:04:45:266]D (13631) wifi:connect status 0 -> 1
[17:04:45:267]D (13631) wifi:filter: set rx policy=3
[17:04:45:267]D (13641) wifi:clear scan ap list
[17:04:45:278]D (13641) wifi:start scan: type=0x50f, priority=2, cb=0x4203a688, arg=0x0, ss_state=0x1, time=13257455, index=0
[17:04:45:291]D (13651) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
[17:04:45:291]I (13651) wifi station: retry to connect to the AP
[17:04:45:299]I (13661) wifi station: connect to the AP fail
[17:04:45:299]D (13661) wifi:rsn valid: gcipher=3 ucipher=3 akm=9 mac=62:16:1b:88:83:c2
[17:04:45:310]I (13671) wifi:(mac)omc_ul_mu_data_disable_rx:1
[17:04:45:310]I (13681) wifi:(phy)ppe_thresholds_present:0, nominal_packet_padding:2
[17:04:45:324]I (13681) wifi:(phy)dcm tx(constellation:1, nss:0), dcm rx(constellation:1, nss:0)
[17:04:45:345]I (13691) wifi:(phy)rx_mcs_map:0xfffa(for_1_ss:2), tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1
[17:04:45:345]I (13701) wifi:(opr)len:7, TWT Required:0, VHT Operation Present:0, 6GHz Info Present:0, Co-Hosted BSS:0, Basic MCS and NSS:0xfffc
[17:04:45:355]I (13711) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1022(32704 us), ER-SU-Disable:0
[17:04:45:355]I (13721) wifi:(opr)len:7, BSS Color:7, disabled:0, Partial BSS Color:0
[17:04:45:370]I (13731) wifi:(spr)len:3, ctrl:0x5, PSR Disallowed:1, Non-SRG OBSS PD SR Disallowed:0
[17:04:45:370]I (13731) wifi:(spr)len:3, ctrl:0x5, Non-SRG Offset Present:1, SRG Info Present:0
[17:04:45:379]I (13741) wifi:(spr)Non-SRG OBSS PD Max Offset:0, PD:-82(dB)
[17:04:45:379]I (13751) wifi:(uora)len:2, EOCWMin:2, EOCWMax:5
[17:04:45:389]D (13751) wpa: rsn_ie - hexdump(len=26):
[17:04:45:389]D (13751) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:45:399]D (13761) wpa: 00 0f ac 02 00 0f ac 08 8c 00 
[17:04:45:399]D (13761) wifi:profile match: ss_state=0x7
[17:04:45:399]D (13771) wifi:scan end: arg=0x0, status=0, ss_state=0x7
[17:04:45:412]D (13771) wifi:find first mathched ssid, scan done
[17:04:45:418]D (13781) wifi:filter: set rx policy=4
[17:04:45:418]D (13781) wifi:first chan=1
[17:04:45:418]D (13781) wifi:handoff_cb: status=0
[17:04:45:418]D (13791) wifi:ap found, mac=62:16:1b:88:83:c2
[17:04:45:435]D (13791) wifi:new_bss=0x4081a5e8, cur_bss=0x0, new_chan=<1,0>, cur_chan=1
[17:04:45:435]D (13801) wifi:filter: set rx policy=5
[17:04:45:440]D (13801) wpa: WPA: set AP RSNXE - hexdump(len=0):
[17:04:45:440]I (13811) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:45:449]D (13811) wifi:connect_op: status=0, auth=9, cipher=3 
[17:04:45:449]I (13821) wifi:(connect)dot11_authmode:0x6, pairwise_cipher:0x3, group_cipher:0x3
[17:04:45:468]D (13821) wpa: RSN: PMKSA cache search - network_ctx=0x0 try_opportunistic=0
[17:04:45:475]D (13831) wpa: RSN: Search for BSSID 62:16:1b:88:83:c2
[17:04:45:475]D (13841) wpa: RSN: No PMKSA cache entry found
[17:04:45:475]D (13841) wifi:auth mode is not none
[17:04:45:485]D (13841) wifi:connect_bss: auth=1, reconnect=0
[17:04:45:485]I (13851) wifi:state: init -> auth (b0)
[17:04:45:485]D (13851) wpa: SAE: Selecting supported ECC group 19
[17:04:45:497]D (13861) wpa: SAE: password - hexdump(len=8):
[17:04:45:497]D (13861) wpa: 31 71 32 77 33 65 34 72 
[17:04:45:519]D (13861) wpa: SAE: PWE derivation - addr1=40:4c:ca:4b:d2:98 addr2=62:16:1b:88:83:c2
[17:04:45:682]D (14061) wpa: SAE: PWE - hexdump(len=64):
[17:04:45:682]D (14061) wpa: 48 86 50 07 7d a4 d3 65 2a d6 23 2f b3 2f 1f 24 
[17:04:45:696]D (14061) wpa: 4d ec 09 92 0c 51 67 39 7b 06 c4 6e cb 49 55 5d 
[17:04:45:696]D (14061) wpa: b0 e0 31 df 8e 81 40 4a 15 4b 15 8f 83 55 a9 aa 
[17:04:45:709]D (14071) wpa: 94 53 3d 1d 0b 75 20 e0 ba 16 aa bc e3 5c 45 d8 
[17:04:45:713]D (14091) wpa: SAE: own commit-scalar - hexdump(len=32):
[17:04:45:728]D (14091) wpa: 1d ae d2 91 9f d1 aa a3 c6 f6 c6 90 37 2c 33 17 
[17:04:45:728]D (14091) wpa: 9d 20 30 e3 f6 b2 7c 8a 30 60 40 7b 00 2b ef 2e 
[17:04:45:735]D (14091) wpa: SAE: own commit-element(x) - hexdump(len=32):
[17:04:45:744]D (14101) wpa: 34 87 88 3d 84 ab 55 11 69 35 13 a3 d6 92 ca f6 
[17:04:45:744]D (14111) wpa: f5 f8 75 27 4b 9f f6 ff da 92 86 bf 47 ea 2e cd 
[17:04:45:762]D (14111) wpa: SAE: own commit-element(y) - hexdump(len=32):
[17:04:45:762]D (14121) wpa: 64 10 53 9b 4d 36 a9 f9 d7 6e af a6 50 10 5a 7c 
[17:04:45:782]D (14121) wpa: da 7d fc 18 ce bc ae 0d 63 74 b7 6b 48 8c 1d 7e 
[17:04:45:782]D (14131) wifi:start 1s AUTH timer
[17:04:45:782]D (14131) wifi:clear scan ap list
[17:04:45:848]D (14221) wifi:recv auth: seq=1, status=0
[17:04:45:848]D (14221) wpa: SAE: Peer commit-scalar - hexdump(len=32):
[17:04:45:860]D (14221) wpa: 27 c4 a2 62 ff 0f 84 0a 0c a0 27 5c df 27 56 01 
[17:04:45:865]D (14231) wpa: d0 a7 68 f0 7e 31 30 8a 84 3c de 6c 2d 7e ff 8d 
[17:04:45:865]D (14231) wpa: SAE: Peer commit-element(x) - hexdump(len=32):
[17:04:45:876]D (14241) wpa: 06 db 02 d1 82 c5 17 a2 95 10 0c 2c d5 2a fd 1b 
[17:04:45:889]D (14251) wpa: a8 18 c8 b7 b7 5e bd 69 77 f9 09 22 de 0c b9 05 
[17:04:45:889]D (14251) wpa: SAE: Peer commit-element(y) - hexdump(len=32):
[17:04:45:898]D (14261) wpa: c3 5a b6 97 ec fa d2 57 0b e7 b9 88 66 c5 0f f0 
[17:04:45:898]D (14261) wpa: 54 52 d6 74 c1 47 55 ae aa 19 86 e0 e7 ce 05 ae 
[17:04:45:908]D (14271) wpa: SAE: Possible elements at the end of the frame - hexdump(len=0):
[17:04:45:940]D (14311) wpa: SAE: k - hexdump(len=32):
[17:04:45:940]D (14311) wpa: b7 73 7c 24 ca 7b e3 72 14 90 05 39 20 27 56 eb 
[17:04:45:946]D (14311) wpa: 0b 97 90 0e 10 8d 61 fe 65 47 a6 40 1e bd f8 ad 
[17:04:45:947]D (14311) wpa: SAE: salt for keyseed derivation - hexdump(len=32):
[17:04:45:954]D (14321) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:45:970]D (14321) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:45:970]D (14331) wpa: SAE: keyseed - hexdump(len=32):
[17:04:45:979]D (14341) wpa: 31 1e d0 b6 4c f5 4f 9f 17 df 52 53 51 f5 a1 04 
[17:04:45:979]D (14341) wpa: 15 9e ae c7 23 59 a9 ae fb ca db 69 57 5f 8f 56 
[17:04:45:979]D (14351) wpa: SAE: PMKID - hexdump(len=16):
[17:04:45:988]D (14351) wpa: 45 73 74 f4 9e e1 2e ad d3 96 ed ed 16 53 89 19 
[17:04:45:988]D (14361) wpa: SAE: KCK - hexdump(len=32):
[17:04:45:999]D (14361) wpa: 83 d4 31 ab e4 76 f7 9b cb ac 9b 2e f9 81 d2 92 
[17:04:46:008]D (14371) wpa: aa f4 61 88 fd 1d eb 9f c9 4d a3 61 d2 1a 50 2b 
[17:04:46:008]D (14371) wpa: SAE: PMK - hexdump(len=32):
[17:04:46:015]D (14381) wpa: 75 0b cb 64 27 70 31 b1 9f fd 99 ce 58 0a f4 47 
[17:04:46:015]D (14381) wpa: cb 4f cd d9 f1 fb 29 7f ca 80 4a 22 24 18 8b 02 
[17:04:46:029]D (14401) wifi:recv auth: seq=2, status=0
[17:04:46:029]D (14401) wpa: SAE: peer-send-confirm 0
[17:04:46:039]D (14401) wpa: ELOOP: pmksa_cache_set_expiration:76 called to remove timer handler=0x42071fe8, removed count=1
[17:04:46:049]D (14411) wpa: ELOOP: Added one timer from pmksa_cache_set_expiration:85 to call 0x42071fe8, current order=0
[17:04:46:061]D (14421) wpa: RSN: Added PMKSA cache entry for 62:16:1b:88:83:c2 network_ctx=0x0
[17:04:46:061]I (14431) wifi:state: auth -> assoc (0)
[17:04:46:079]D (14451) wifi:recv assoc: type=0x10
[17:04:46:088]I (14451) wifi:Extended Capabilities length:8, subtype:0x10, 62:16:1b:88:83:c2, Operating mode notification Support
[17:04:46:088]D (14451) wifi:set max rate: from <rate=0, phy=5, sig=0> to <rate=86, phy=5 sig=0>
[17:04:46:096]D (14461) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
[17:04:46:096]D (14461) wifi:filter: set rx policy=6
[17:04:46:109]I (14471) wifi:state: assoc -> run (10)
[17:04:46:109]I (14471) wifi:(he)ppe_thresholds_present:0, nominal_packet_padding(rx:2, cfg:2)
[17:04:46:118]I (14481) wifi:(trc)phytype:CBW20-SGI, snr:59, maxRate:86, highestRateIdx:0
[17:04:46:140]I (14491) wifi:(trc)rate(S-MCS7, schedIdx:0), ampdu(rate:S-MCS7, schedIdx(0, stop:8)), snr:59, ampduState:wait operational
[17:04:46:141]I (14501) wifi:ifidx:0, rssi:-39, nf:-98, phytype(0x3, CBW20-SGI), phymode(0x5, 11ax), max_rate:860, he:1
[17:04:46:142]I (14511) wifi:max ampdu length exponent:3(65535 bytes), mmss:0(no restriction)
[17:04:46:153]D (14511) wifi:start 10s connect timer for 4 way handshake
[17:04:46:153]D (14521) wpa: WPA: Association event - clear replay counter
[17:04:46:166]D (14521) wpa: WPA: Clear old PTK
[17:04:46:167]D (14531) wpa: IEEE 802.1X RX: version=2 type=3 length=117
[17:04:46:167]D (14531) wpa:   EAPOL-Key type=2
[17:04:46:173]D (14541) wpa:   key_info 0x88 (ver=0 keyidx=0 rsvd=0 Pairwise Ack)
[17:04:46:173]D (14541) wpa:   key_length=16 key_data_length=0
[17:04:46:186]D (14551) wpa:   replay_counter - hexdump(len=8):
[17:04:46:194]D (14551) wpa: 00 00 00 00 00 00 00 01 
[17:04:46:194]D (14561) wpa:   key_nonce - hexdump(len=32):
[17:04:46:201]D (14561) wpa: 10 cd 37 8c 28 4d 25 62 69 cf 37 3e 31 00 76 ca 
[17:04:46:201]D (14571) wpa: 31 ee 90 ae 48 67 fe 90 61 59 2c 88 de 3d 97 e9 
[17:04:46:202]D (14571) wpa:   key_iv - hexdump(len=16):
[17:04:46:216]D (14581) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:46:216]D (14581) wpa:   key_rsc - hexdump(len=8):
[17:04:46:226]D (14591) wpa: 00 00 00 00 00 00 00 00 
[17:04:46:226]D (14591) wpa:   key_id (reserved) - hexdump(len=8):
[17:04:46:235]D (14601) wpa: 00 00 00 00 00 00 00 00 
[17:04:46:235]D (14601) wpa:   key_mic - hexdump(len=16):
[17:04:46:236]D (14601) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:46:246]D (14611) wpa: WPA 1/4-Way Handshake
[17:04:46:247]D (14611) wpa: RSN: msg 1/4 key data - hexdump(len=0):
[17:04:46:257]D (14621) wpa: WPA: Renewed SNonce - hexdump(len=32):
[17:04:46:258]D (14621) wpa: b7 71 24 93 e5 cd 78 21 cb 50 7e 4d 53 28 b8 b3 
[17:04:46:268]D (14631) wpa: d6 6e 03 68 ed 7a cf e4 a0 77 47 f6 cc 40 97 11 
[17:04:46:268]D (14641) wpa: WPA: PTK derivation - A1=40:4c:ca:4b:d2:98 A2=62:16:1b:88:83:c2
[17:04:46:269]
[17:04:46:278]D (14641) wpa: WPA: PTK - hexdump(len=48):
[17:04:46:279]D (14651) wpa: fa 1a db d9 87 78 d5 07 90 9a 28 69 4c 97 68 77 
[17:04:46:291]D (14651) wpa: 6a cb d3 51 9d 82 1f 3f e2 98 d5 ad de 54 0d f6 
[17:04:46:291]D (14661) wpa: 1c a2 f4 eb 03 1a d2 98 0c 2b 3e 09 d6 79 57 99 
[17:04:46:309]D (14661) wpa: WPA: KCK - hexdump(len=16):
[17:04:46:309]D (14671) wpa: fa 1a db d9 87 78 d5 07 90 9a 28 69 4c 97 68 77 
[17:04:46:314]D (14681) wpa: WPA: KEK - hexdump(len=16):
[17:04:46:314]D (14681) wpa: 6a cb d3 51 9d 82 1f 3f e2 98 d5 ad de 54 0d f6 
[17:04:46:325]D (14691) wpa: WPA: TK - hexdump(len=16):
[17:04:46:325]D (14691) wpa: 1c a2 f4 eb 03 1a d2 98 0c 2b 3e 09 d6 79 57 99 
[17:04:46:339]D (14701) wpa: WPA Send EAPOL-Key 2/4
[17:04:46:339]D (14701) wpa: WPA: KCK - hexdump(len=16):
[17:04:46:339]D (14701) wpa: fa 1a db d9 87 78 d5 07 90 9a 28 69 4c 97 68 77 
[17:04:46:348]D (14711) wpa: WPA: Derived Key MIC - hexdump(len=16):
[17:04:46:348]D (14711) wpa: 51 67 4d 3c 36 98 4c 5f c7 39 6a c8 57 8d e6 94 
[17:04:46:357]D (14721) wpa: 2/4 txcb, flags=0, txfail 0
[17:04:46:358]D (14731) wpa: IEEE 802.1X RX: version=2 type=3 length=183
[17:04:46:369]D (14731) wpa:   EAPOL-Key type=2
[17:04:46:369]D (14731) wpa:   key_info 0x13c8 (ver=0 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
[17:04:46:380]D (14741) wpa:   key_length=16 key_data_length=88
[17:04:46:380]D (14751) wpa:   replay_counter - hexdump(len=8):
[17:04:46:392]D (14751) wpa: 00 00 00 00 00 00 00 02 
[17:04:46:392]D (14761) wpa:   key_nonce - hexdump(len=32):
[17:04:46:402]D (14761) wpa: 10 cd 37 8c 28 4d 25 62 69 cf 37 3e 31 00 76 ca 
[17:04:46:402]D (14771) wpa: 31 ee 90 ae 48 67 fe 90 61 59 2c 88 de 3d 97 e9 
[17:04:46:402]D (14771) wpa:   key_iv - hexdump(len=16):
[17:04:46:417]D (14781) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[17:04:46:417]D (14781) wpa:   key_rsc - hexdump(len=8):
[17:04:46:425]D (14791) wpa: 00 00 00 00 00 00 00 00 
[17:04:46:425]D (14791) wpa:   key_id (reserved) - hexdump(len=8):
[17:04:46:435]D (14801) wpa: 00 00 00 00 00 00 00 00 
[17:04:46:435]D (14801) wpa:   key_mic - hexdump(len=16):
[17:04:46:436]D (14801) wpa: 73 67 2e cb ff 84 15 47 ee a9 17 36 ef d5 34 6a 
[17:04:46:446]D (14811) wpa: RSN: encrypted key data - hexdump(len=88):
[17:04:46:446]D (14811) wpa: 0e f9 be ae 20 17 49 07 ef 39 d9 ef da 54 1e 15 
[17:04:46:457]D (14821) wpa: 21 57 e7 21 50 a7 5a b2 d9 5b b7 f5 6c 60 fd 3d 
[17:04:46:469]D (14831) wpa: c3 f8 ba ba a5 b3 01 2e fc 1a 65 31 d0 b8 6b a4 
[17:04:46:469]D (14831) wpa: a3 c8 82 26 3b b8 4d 67 67 c0 0f d5 94 26 33 6d 
[17:04:46:478]D (14841) wpa: f7 7b 3b e4 8e 23 a9 c7 88 51 07 e2 77 00 d3 03 
[17:04:46:479]D (14841) wpa: e6 75 78 96 f9 e5 7e 2a 
[17:04:46:490]D (14851) wpa: WPA: decrypted EAPOL-Key key data - hexdump(len=80):
[17:04:46:492]D (14861) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:46:500]D (14861) wpa: 00 0f ac 02 00 0f ac 08 8c 00 dd 16 00 0f ac 01 
[17:04:46:502]D (14871) wpa: 01 00 71 4f b1 92 f9 51 36 15 05 f9 c4 30 c9 ad 
[17:04:46:513]D (14871) wpa: 71 96 dd 1c 00 0f ac 09 04 00 00 00 00 00 00 00 
[17:04:46:514]D (14881) wpa: 09 1a f2 51 a7 cc 4a 42 4c f7 88 d3 d0 7c d7 18 
[17:04:46:525]D (14881) wpa: WPA 3/4-Way Handshake
[17:04:46:526]D (14891) wpa: WPA: RSN IE in EAPOL-Key - hexdump(len=26):
[17:04:46:536]D (14891) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:46:536]D (14901) wpa: 00 0f ac 02 00 0f ac 08 8c 00 
[17:04:46:547]D (14901) wpa: WPA: GTK in EAPOL-Key - hexdump(len=24):
[17:04:46:547]D (14911) wpa: dd 16 00 0f ac 01 01 00 71 4f b1 92 f9 51 36 15 
[17:04:46:547]D (14921) wpa: 05 f9 c4 30 c9 ad 71 96 
[17:04:46:557]D (14921) wpa: WPA: IGTK in EAPOL-Key - hexdump(len=30):
[17:04:46:557]D (14931) wpa: dd 1c 00 0f ac 09 04 00 00 00 00 00 00 00 09 1a 
[17:04:46:572]D (14931) wpa: f2 51 a7 cc 4a 42 4c f7 88 d3 d0 7c d7 18 
[17:04:46:572]D (14941) wpa: WPA: IE KeyData - hexdump(len=80):
[17:04:46:579]D (14941) wpa: 30 18 01 00 00 0f ac 04 01 00 00 0f ac 04 02 00 
[17:04:46:579]D (14951) wpa: 00 0f ac 02 00 0f ac 08 8c 00 dd 16 00 0f ac 01 
[17:04:46:590]D (14951) wpa: 01 00 71 4f b1 92 f9 51 36 15 05 f9 c4 30 c9 ad 
[17:04:46:603]D (14961) wpa: 71 96 dd 1c 00 0f ac 09 04 00 00 00 00 00 00 00 
[17:04:46:606]D (14971) wpa: 09 1a f2 51 a7 cc 4a 42 4c f7 88 d3 d0 7c d7 18 
[17:04:46:606]D (14971) wpa: WPA: RSC - hexdump(len=8):
[17:04:46:607]D (14981) wpa: 00 00 00 00 00 00 00 00 
[17:04:46:617]D (14981) wpa: RSN: received GTK in pairwise handshake - hexdump(len=18):
[17:04:46:624]D (14991) wpa: 01 00 71 4f b1 92 f9 51 36 15 05 f9 c4 30 c9 ad 
[17:04:46:624]D (14991) wpa: 71 96 
[17:04:46:635]D (14991) wpa: WPA: IGTK keyid 4 pn 000000000000
[17:04:46:635]D (15001) wpa: WPA: IGTK - hexdump(len=16):
[17:04:46:635]D (15001) wpa: 09 1a f2 51 a7 cc 4a 42 4c f7 88 d3 d0 7c d7 18 
[17:04:46:647]D (15011) wpa: tx 4/4 txcb_flags=8192
[17:04:46:647]D (15011) wpa: WPA Send EAPOL-Key 4/4
[17:04:46:657]D (15021) wpa: WPA: KCK - hexdump(len=16):
[17:04:46:657]D (15021) wpa: fa 1a db d9 87 78 d5 07 90 9a 28 69 4c 97 68 77 
[17:04:46:668]D (15031) wpa: WPA: Derived Key MIC - hexdump(len=16):
[17:04:46:668]D (15031) wpa: 40 25 e0 1c d4 70 ee 45 30 4a 42 bd 45 ba 49 fb 
[17:04:46:668]D (15041) wpa: WPA: Installing PTK to the driver.
[17:04:46:684]D (15041) wpa: WPA: Group Key - hexdump(len=16):
[17:04:46:684]D (15051) wpa: 71 4f b1 92 f9 51 36 15 05 f9 c4 30 c9 ad 71 96 
[17:04:46:684]D (15051) wpa: WPA: Judge GTK: (keyidx=1 len=16).
[17:04:46:695]D (15061) wpa: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16).
[17:04:46:695]D (15071) wpa: WPA: RSC - hexdump(len=6):
[17:04:46:706]D (15071) wpa: 00 00 00 00 00 00 
[17:04:46:706]D (15071) wpa: WPA: Key negotiation completed with 62:16:1b:88:83:c2 [PTK=CCMP GTK=CCMP]
[17:04:46:706]
[17:04:46:718]I (15081) wifi:(extcap)mbssid:0, enhanced_mbssid_advertise:0, complete_nontxbssid_profiles:0, twt_responder: 0
[17:04:46:728]I (15091) wifi:connected with HUAWEI-Q6, aid = 4, channel 1, BW20, bssid = 62:16:1b:88:83:c2
[17:04:46:745]I (15101) wifi:cipher(pairwise:0x3, group:0x3), pmf:1, security:WPA3-SAE, phy:11ax, rssi:-39
[17:04:46:745]D (15111) wifi:remove all except 62:16:1b:88:83:c2 from rc list
[17:04:46:745]D (15111) wifi:clear blacklist
[17:04:46:746]D (15121) nvs: nvs_set sta.chan 1 1
[17:04:46:757]D (15131) nvs: nvs_set_blob sta.apinfo 700
[17:04:46:757]D (15131) wifi:filter: set rx policy=7
[17:04:46:757]I (15131) wifi:pm start, type: 1, itwt_start:0
[17:04:46:757]
[17:04:46:770]I (15131) wifi:pm start, type:1, aid:0x4, trans-BSSID:62:16:1b:88:83:c2, BSSID[5]:0xc2, mbssid(max-indicator:0, index:0), he:1
[17:04:46:778]I (15141) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
[17:04:46:793]I (15151) wifi:set rx beacon pti, rx_bcn_pti: 10, bcn_timeout: 25000, mt_pti: 10, mt_time: 10000
[17:04:46:794]D (15161) wifi:Send sta connected event
[17:04:46:802]D (15161) wifi:connect status 1 -> 5
[17:04:46:816]I (15171) wifi:[ADDBA]TX addba request, tid:0, dialogtoken:1, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
[17:04:46:817]I (15181) wifi:[ADDBA]TX addba request, tid:7, dialogtoken:2, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x20)
[17:04:46:823]I (15191) wifi:[ADDBA]TX addba request, tid:5, dialogtoken:3, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
[17:04:46:834]D (15201) wifi:obss scan is disabled
[17:04:46:834]D (15201) wifi:start obss scan: obss scan is stopped
[17:04:46:848]I (15211) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[17:04:46:848]D (15211) wifi:mms: 0->0
[17:04:46:848]D (15211) wifi:mms: 0->0
[17:04:46:857]I (15221) wifi:[ADDBA]RX addba response, status:0, tid:0/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
[17:04:46:868]D (15231) event: running post WIFI_EVENT:4 with handler 0x4201891a and context 0x40823d64 on loop 0x40822be4
[17:04:46:897]I (15231) wifi:[ADDBA]RX addba response, status:0, tid:7/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
[17:04:46:897]D (15251) esp_netif_handlers: esp_netif action connected with netif0x40823b08 from event_id=4
[17:04:46:898]D (15251) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x420155c2
[17:04:46:903]I (15261) wifi:[ADDBA]RX addba response, status:0, tid:5/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
[17:04:46:903]D (15271) esp_netif_lwip: esp_netif_up_api esp_netif:0x40823b08
[17:04:46:913]D (15281) esp_netif_lwip: check: local, if=0x40823b08 fn=0x42015ae0
[17:04:46:923]D (15281) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x40823b08
[17:04:46:928]D (15291) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:46:929]D (15291) esp_netif_lwip: check: remote, if=0x40823b08 fn=0x420153fe
[17:04:46:942]D (15301) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x40823b08
[17:04:46:943]D (15311) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x40823b08
[17:04:46:952]D (15311) esp_netif_lwip: if0x40823b08 start ip lost tmr: already started
[17:04:46:953]D (15321) esp_netif_lwip: starting dhcp client
[17:04:46:967]D (15331) esp_netif_lwip: call api in lwip: ret=0x0, give sem
[17:04:46:984]D (15331) event: running post WIFI_EVENT:4 with handler 0x42009e54 and context 0x4082cd94 on loop 0x40822be4
[17:04:47:000]D (15381) wifi:mms: 0->0
[17:04:47:108]D (15481) wifi:mms: 0->0
[17:04:47:215]D (15581) wifi:mms: 0->0
[17:04:47:510]D (15891) wifi:mms: 0->0
[17:04:47:617]D (15991) wifi:mms: 0->0
[17:04:47:952]D (16331) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x40823b8c
[17:04:47:965]D (16331) esp_netif_lwip: if0x40823b08 ip changed=1
[17:04:47:965]D (16331) event: running post IP_EVENT:0 with handler 0x4201886a and context 0x40823dd8 on loop 0x40822be4
[17:04:47:984]D (16341) wifi_init_default: Got IP wifi default handler entered
[17:04:47:984]D (16341) esp_netif_handlers: esp_netif action got_ip with netif0x40823b08 from event_id=0
[17:04:47:995]I (16351) esp_netif_handlers: sta ip: 192.168.3.74, mask: 255.255.255.0, gw: 192.168.3.1
[17:04:47:995]D (16361) event: running post IP_EVENT:0 with handler 0x42009e54 and context 0x4082cdb4 on loop 0x40822be4
[17:04:48:007]I (16371) wifi station: got ip:192.168.3.74
[17:04:48:036]I (16371) wifi station: connected to ap SSID:HUAWEI-Q6 password:1q2w3e4r
[17:04:48:036]I (16381) main_task: Returned from app_main()


问题分析
日志里面可以看到,从 [17:04:33:651]I (2021) wifi🆕<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 开始, 到 [17:04:47:995]I (16351) esp_netif_handlers: sta ip: 192.168.3.74, mask: 255.255.255.0, gw: 192.168.3.1 获取到 ip , 耗时 13s 左右。
另外, 我们在日志中有频繁看到“Association refused temporarily” 的打印,这个打印导致连接时间加长了很多。

[17:04:41:495]I (9861) wifi:state: auth -> assoc (0)
[17:04:41:507]D (9881) wifi:recv assoc: type=0x10
[17:04:41:507]I (9881) wifi:Association refused temporarily, comeback time 1000 (TUs)
[17:04:41:525]D (9881) wpa: WPA: Association event - clear replay counter
[17:04:41:525]D (9881) wpa: WPA: Clear old PTK
[17:04:42:539]I (10901) wifi:state: assoc -> assoc (0)
[17:04:42:539]D (10911) wifi:recv assoc: type=0x10
[17:04:42:552]E (10911) wifi:Association refused temporarily, comeback time 4294967266 (TUs) too long, max allowed 5000 (TUs)
[17:04:42:558]I (10921) wifi:state: assoc -> init (d010)
[17:04:42:558]D (10921) wifi:stop beacon and connect timers
[17:04:42:558]D (10921) wifi:connect status 1 -> 4
[17:04:42:568]D (10931) wifi:add bssid 62:16:1b:88:83:c2 to blacklist, cnt=0
[17:04:42:568]D (10931) wifi:stop CSA timer
[17:04:42:568]D (10941) wifi:remove 62:16:1b:88:83:c2 from rc list
[17:04:42:579]I (10941) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[17:04:42:579]D (10951) wifi:filter: set rx policy=8
[17:04:42:590]D (10951) wifi:reason: assoc comeback time too long(208)

这个日志其实是跟路由器的 SA Query 机制有关, 一般来说, 当AP与客户端协商结果为使用保护管理帧功能时,AP将使用SA Query(Security Association Query,安全关联询问)机制增强客户端的安全连接。SA Query包括主动SA Query和被动SA Query, 这里对应的是 主动SA Query。
在这里插入图片描述
在这里插入图片描述

问题原因
路由器的行为是这样的, 在第一次模块 auth 的时候必然拒绝, 然后我们重新连接,重新发 probe request 包给路由器, 路由器 经常性的会回复一个特别大 comback time , 那我们原本的逻辑是将这个 comback time 缩短到 5s 之内, 然后再重新连接,所以重新连接的时间会比较长一些。
后续我们用手机做了下测试,发现连接时间会比我们的短一些, 抓包 发现手机第一次连接被路由器拒绝之后, 重新连接的时候会直接发 auth 包, 会跳过 probe request 的过程, 那我们就参考手机的行为做了一定优化: 第一次连接路由器必然回复 auth , 这个我们无法进行优化,第二次重连的时候, 我们将 probe request 阶段去掉了, 直接发 auth 包给路由器, 直到 auth 成功, 这部分一般来说 2s 左右就成功了, 再加上获取到 IP, 整个连接过程差不多是 5s 的时间。

目前完整的修复方案已经同步到 github release/v5.0 上了: https://github.com/espressif/esp-idf/commit/17bdbedcd2e1402e
具体详情可以参考下这个 MR,
https://gitlab.espressif.cn:6688/espressif/esp-idf/-/merge_requests/31733

Q3. 使用 ESP32C6 芯片,v5.2.2 版本, 使用 华为凌霄路由器 wps 配网失败概率高达 90%。

使用 wps demo 进行复现:
日志现象如下:

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x1c (SPI_FAST_FLASH_BOOT)
Saved PC:0x4080535a
SPIWP:0xee
mode:DIO, clock div:2
load:0x40875720,len:0x180c
load:0x4086c410,len:0xde0
load:0x4086e610,len:0x2e04
entry 0x4086c41a
[0;32mI (23) boot: ESP-IDF v5.2-dirty 2nd stage bootloader[0m
[0;32mI (23) boot: compile time Jun  5 2024 15:01:09[0m
[0;32mI (24) boot: chip revision: v0.0[0m
[0;32mI (26) boot.esp32c6: SPI Speed      : 80MHz[0m
[0;32mI (31) boot.esp32c6: SPI Mode       : DIO[0m
[0;32mI (36) boot.esp32c6: SPI Flash Size : 2MB[0m
[0;32mI (40) boot: Enabling RNG early entropy source...[0m
[0;32mI (46) boot: Partition Table:[0m
[0;32mI (49) boot: ## Label            Usage          Type ST Offset   Length[0m
[0;32mI (57) boot:  0 nvs              WiFi data        01 02 00009000 00006000[0m
[0;32mI (64) boot:  1 phy_init         RF data          01 01 0000f000 00001000[0m
[0;32mI (72) boot:  2 factory          factory app      00 00 00010000 00100000[0m
[0;32mI (79) boot: End of partition table[0m
[0;32mI (83) esp_image: segment 0: paddr=00010020 vaddr=42098020 size=21890h (137360) map[0m
[0;32mI (120) esp_image: segment 1: paddr=000318b8 vaddr=40800000 size=06760h ( 26464) load[0m
[0;32mI (127) esp_image: segment 2: paddr=00038020 vaddr=42000020 size=919b8h (596408) map[0m
[0;32mI (249) esp_image: segment 3: paddr=000c99e0 vaddr=40806760 size=11fe0h ( 73696) load[0m
[0;32mI (271) boot: Loaded app from partition at offset 0x10000[0m
[0;32mI (272) boot: Disabling RNG early entropy source...[0m
[0;32mI (283) cpu_start: Unicore app[0m
[0;33mW (292) clk: esp_perip_clk_init() has not been implemented yet[0m
[0;32mI (298) cpu_start: Pro cpu start user code[0m
[0;32mI (298) cpu_start: cpu freq: 160000000 Hz[0m
[0;32mI (299) cpu_start: Application information:[0m
[0;32mI (301) cpu_start: Project name:     wps_example[0m
[0;32mI (307) cpu_start: App version:      v5.2-dirty[0m
[0;32mI (312) cpu_start: Compile time:     Jun  5 2024 15:01:04[0m
[0;32mI (318) cpu_start: ELF file SHA256:  0a1f462a7...[0m
[0;32mI (323) cpu_start: ESP-IDF:          v5.2-dirty[0m
[0;32mI (328) cpu_start: Min chip rev:     v0.0[0m
[0;32mI (333) cpu_start: Max chip rev:     v0.99 [0m
[0;32mI (338) cpu_start: Chip rev:         v0.0[0m
[0;32mI (343) heap_init: Initializing. RAM available for dynamic allocation:[0m
[0;32mI (350) heap_init: At 4081D550 len 0005F0C0 (380 KiB): RAM[0m
[0;32mI (356) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM[0m
[0;32mI (362) heap_init: At 50000000 len 00003FE8 (15 KiB): RTCRAM[0m
[0;32mI (369) spi_flash: detected chip: generic[0m
[0;32mI (373) spi_flash: flash io: dio[0m
[0;33mW (377) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.[0m
[0;32mI (391) sleep: Configure to isolate all GPIO pins in sleep state[0m
[0;32mI (397) sleep: Enable automatic switching of GPIO sleep configuration[0m
[0;32mI (404) coexist: coex firmware version: 77cd7f8[0m
[0;32mI (410) coexist: coexist rom version 5b8dcfa[0m
[0;32mI (415) main_task: Started on CPU0[0m
[0;32mI (415) main_task: Calling app_main()[0m
[0;32mI (435) pp: pp rom version: 5b8dcfa[0m
[0;32mI (435) net80211: net80211 rom version: 5b8dcfa[0m
I (445) wifi:wifi driver task: 408263cc, prio:23, stack:6656, core=0
I (445) wifi:wifi firmware version: cc1dd81
I (445) wifi:wifi certification version: v7.0
I (445) wifi:config NVS flash: enabled
I (445) wifi:config nano formating: disabled
I (455) wifi:mac_version:HAL_MAC_ESP32AX_761,ut_version:N
I (455) wifi:Init data frame dynamic rx buffer num: 32
I (465) wifi:Init static rx mgmt buffer num: 5
I (465) wifi:Init management short buffer num: 32
I (465) wifi:Init dynamic tx buffer num: 32
I (475) wifi:Init static tx FG buffer num: 2
I (475) wifi:Init static rx buffer size: 1700
I (485) wifi:Init static rx buffer num: 10
I (485) wifi:Init dynamic rx buffer num: 32
[0;32mI (485) wifi_init: rx ba win: 6[0m
[0;32mI (495) wifi_init: tcpip mbox: 32[0m
[0;32mI (495) wifi_init: udp mbox: 6[0m
[0;32mI (505) wifi_init: tcp mbox: 6[0m
[0;32mI (505) wifi_init: tcp tx win: 5760[0m
[0;32mI (505) wifi_init: tcp rx win: 5760[0m
[0;32mI (515) wifi_init: tcp mss: 1440[0m
[0;32mI (515) wifi_init: WiFi IRAM OP enabled[0m
[0;32mI (525) wifi_init: WiFi RX IRAM OP enabled[0m
[0;32mI (525) phy_init: phy_version 230,c773401,Oct 30 2023,15:07:16[0m
W (575) wifi:(bf)761:0x600a7cac:0x01b4b4b0
W (575) wifi:(agc)0x600a7128:0xd210ea6e, min.avgNF:0xce->0xd2(dB), RCalCount:0x10e, min.RRssi:0xa6e(-89.12)
W (585) wifi:(TB)WDEV_PWR_TB_MCS0:19
W (585) wifi:(TB)WDEV_PWR_TB_MCS1:19
W (585) wifi:(TB)WDEV_PWR_TB_MCS2:19
W (595) wifi:(TB)WDEV_PWR_TB_MCS3:19
W (595) wifi:(TB)WDEV_PWR_TB_MCS4:19
W (595) wifi:(TB)WDEV_PWR_TB_MCS5:19
W (605) wifi:(TB)WDEV_PWR_TB_MCS6:18
W (605) wifi:(TB)WDEV_PWR_TB_MCS7:18
W (605) wifi:(TB)WDEV_PWR_TB_MCS8:17
W (615) wifi:(TB)WDEV_PWR_TB_MCS9:15
W (615) wifi:(TB)WDEV_PWR_TB_MCS10:15
W (615) wifi:(TB)WDEV_PWR_TB_MCS11:15
I (625) wifi:11ax coex: WDEVAX_PTI0(0x55777555), WDEVAX_PTI1(0x00003377).

I (625) wifi:mode : sta (60:55:f9:f6:03:74)
I (635) wifi:enable tsf
[0;32mI (635) example_wps: WIFI_EVENT_STA_START[0m
[0;32mI (635) example_wps: start wps...[0m
[0;32mI (735) main_task: Returned from app_main()[0m
W (13165) wifi:(itwt)itwt_stop_process!
I (13185) wifi:(mac)omc_ul_mu_data_disable_rx:1
I (13185) wifi:(phy)ppe_thresholds_present:0, nominal_packet_padding:2
I (13185) wifi:(phy)dcm tx(constellation:1, nss:0), dcm rx(constellation:1, nss:0)
I (13195) wifi:(phy)rx_mcs_map:0xfffa(for_1_ss:2), tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1
I (13205) wifi:(opr)len:7, TWT Required:0, VHT Operation Present:0, 6GHz Info Present:0, Co-Hosted BSS:0, Basic MCS and NSS:0xfffc
I (13215) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1022(32704 us), ER-SU-Disable:0
I (13225) wifi:(opr)len:7, BSS Color:7, disabled:0, Partial BSS Color:0
I (13235) wifi:(spr)len:3, ctrl:0x5, PSR Disallowed:1, Non-SRG OBSS PD SR Disallowed:0
I (13235) wifi:(spr)len:3, ctrl:0x5, Non-SRG Offset Present:1, SRG Info Present:0
I (13245) wifi:(spr)Non-SRG OBSS PD Max Offset:0, PD:-82(dB)
I (13255) wifi:(uora)len:2, EOCWMin:2, EOCWMax:5
I (13255) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (13265) wifi:(connect)dot11_authmode:0x6, pairwise_cipher:0x3, group_cipher:0x3
I (13265) wifi:state: init -> auth (b0)
I (17275) wifi:state: auth -> init (200)
I (17275) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[0;32mI (17275) example_wps: WIFI_EVENT_STA_DISCONNECTED[0m
[0;32mI (19685) example_wps: WIFI_EVENT_STA_DISCONNECTED[0m
I (19685) wifi:(mac)omc_ul_mu_data_disable_rx:1
I (19685) wifi:(phy)ppe_thresholds_present:0, nominal_packet_padding:2
I (19685) wifi:(phy)dcm tx(constellation:1, nss:0), dcm rx(constellation:1, nss:0)
I (19695) wifi:(phy)rx_mcs_map:0xfffa(for_1_ss:2), tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1
I (19705) wifi:(opr)len:7, TWT Required:0, VHT Operation Present:0, 6GHz Info Present:0, Co-Hosted BSS:0, Basic MCS and NSS:0xfffc
I (19715) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1022(32704 us), ER-SU-Disable:0
I (19725) wifi:(opr)len:7, BSS Color:7, disabled:0, Partial BSS Color:0
I (19735) wifi:(spr)len:3, ctrl:0x5, PSR Disallowed:1, Non-SRG OBSS PD SR Disallowed:0
I (19735) wifi:(spr)len:3, ctrl:0x5, Non-SRG Offset Present:1, SRG Info Present:0
I (19745) wifi:(spr)Non-SRG OBSS PD Max Offset:0, PD:-82(dB)
I (19755) wifi:(uora)len:2, EOCWMin:2, EOCWMax:5
I (19755) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (19765) wifi:(connect)dot11_authmode:0x6, pairwise_cipher:0x3, group_cipher:0x3
I (19765) wifi:state: init -> auth (b0)
I (19785) wifi:state: auth -> assoc (0)
I (19805) wifi:Association refused temporarily, comeback time 1000 (TUs)
I (20825) wifi:state: assoc -> assoc (0)
E (20835) wifi:Association refused temporarily, comeback time 4294967256 (TUs) too long, max allowed 5000 (TUs)
I (20835) wifi:state: assoc -> init (d010)
I (20845) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[0;32mI (20845) example_wps: WIFI_EVENT_STA_DISCONNECTED[0m
[0;32mI (20855) example_wps: Failed to connect![0m

问题原因: 可以看到日志里面在报“Association refused temporarily, comeback time 4294967256 (TUs) too long, max allowed 5000 (TUs)” , 可以看出与上面问题是一个原因, 但如果直接基于上述方案进行测试, 还是会有概率性的出现连接失败, 这个是因为代码中设置的连接失败次数只有 2次,而实际连接过程中, 会有概率性的出现连接多次才可以成功, 所以应用代码中还需要做如下修改:
将 examples/wifi/wps/main/wps.c 中 把#define MAX_RETRY_ATTEMPTS
2 这个宏改为5 之后, 复测多次之后并未出现连接失败的情况。

  • 21
    点赞
  • 30
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值