一、什么是 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 下面使用方法如下:
-
menuconfig 中需要 enable WPA3-psk
-
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 之后, 复测多次之后并未出现连接失败的情况。