SDK-NRF-v3.0.2: nRF7002 freeze on transmissions

Question

Hello, We are using a nrf7002 for wifi only alongside a nrf5340 host MCU on a custom board. We are testing the wifi connection using the sample `nrf/samples/wifi/shell`, with the following configuration: # # Copyright (c) 2022 Nordic Semiconductor ASA # # SPDX-License-Identifier: LicenseRef-Nordic-5-Clause # CONFIG_WIFI=y CONFIG_WIFI_NRF70=y # WPA supplicant CONFIG_WIFI_NM_WPA_SUPPLICANT=y CONFIG_NET_L2_WIFI_SHELL=y # Networking CONFIG_NETWORKING=y CONFIG_NET_SOCKETS=y CONFIG_NET_LOG=y CONFIG_NET_IPV6=y CONFIG_NET_IPV4=y CONFIG_NET_UDP=y CONFIG_NET_TCP=y CONFIG_NET_DHCPV4=y CONFIG_DNS_RESOLVER=y CONFIG_NET_STATISTICS=y CONFIG_NET_STATISTICS_WIFI=y CONFIG_NET_STATISTICS_USER_API=y CONFIG_NET_PKT_RX_COUNT=8 CONFIG_NET_PKT_TX_COUNT=8 # Below section is the primary contributor to SRAM and is currently # tuned for performance, but this will be revisited in the future. CONFIG_NET_BUF_RX_COUNT=16 CONFIG_NET_BUF_TX_COUNT=16 CONFIG_NRF70_RX_NUM_BUFS=16 CONFIG_NRF70_MAX_TX_AGGREGATION=4 CONFIG_NET_TC_TX_COUNT=1 CONFIG_NET_IF_UNICAST_IPV6_ADDR_COUNT=4 CONFIG_NET_IF_MCAST_IPV6_ADDR_COUNT=5 CONFIG_NET_MAX_CONTEXTS=5 CONFIG_NET_CONTEXT_SYNC_RECV=y CONFIG_INIT_STACKS=y CONFIG_NET_L2_ETHERNET=y CONFIG_NET_SHELL=y # Memories CONFIG_MAIN_STACK_SIZE=5200 CONFIG_SHELL_STACK_SIZE=5400 CONFIG_NET_TX_STACK_SIZE=4096 CONFIG_NET_RX_STACK_SIZE=4096 # Debugging CONFIG_STACK_SENTINEL=y CONFIG_DEBUG_COREDUMP=y CONFIG_DEBUG_COREDUMP_BACKEND_LOGGING=y CONFIG_DEBUG_COREDUMP_MEMORY_DUMP_MIN=y CONFIG_SHELL_CMDS_RESIZE=n CONFIG_WIFI_NM_WPA_SUPPLICANT_LOG_LEVEL_DBG=y CONFIG_WIFI_LOG_LEVEL_DBG=y CONFIG_NET_IF_LOG_LEVEL_DBG=y CONFIG_WIFI_NRF70_LOG_LEVEL_DBG=y CONFIG_NRF_WIFI_RPU_RECOVERY_DEBUG=y CONFIG_WIFI_NRF70_BUSLIB_LOG_LEVEL_DBG=y CONFIG_LOG_BUFFER_SIZE=16384 # Kernel options CONFIG_ENTROPY_GENERATOR=y CONFIG_REBOOT=y # Logging CONFIG_LOG=y CONFIG_PRINTK=y CONFIG_SHELL=y CONFIG_SHELL_GETOPT=y CONFIG_DEVICE_SHELL=y CONFIG_POSIX_CLOCK=y CONFIG_DATE_SHELL=y CONFIG_NET_CONFIG_AUTO_INIT=n CONFIG_POSIX_API=y CONFIG_WIFI_CREDENTIALS=y CONFIG_FLASH=y CONFIG_FLASH_PAGE_LAYOUT=y CONFIG_FLASH_MAP=y CONFIG_NVS=y CONFIG_SETTINGS=y CONFIG_SETTINGS_NVS=y # printing of scan results puts pressure on queues in new locking # design in net_mgmt. So, use a higher timeout for a crowded # environment. CONFIG_NET_MGMT_EVENT_QUEUE_TIMEOUT=5000 CONFIG_NET_SOCKETS_POLL_MAX=12 CONFIG_NET_MGMT_EVENT_QUEUE_SIZE=16 Communication with the wifi chip over QSPI works on boot, and we can do a wifi scan and see the output. Getting wifi statistics works as well. However, whenever a TX command is used (wifi connection, wifi scan -t active, etc), the wifi chip seems to freeze/halt. Please see the attached log from a `wifi connect` attempt. Fullscreen connection_fail.txt Download uart:~$ wifi connect -s OnePlusAP -p xxxx -b 2 -k 1 [00:00:50.621,734] wpa_supp: wpa_printf_impl: Calling wpa_cli: remove_network, argc: 2 [00:00:50.630,584] wpa_supp: wpa_printf_impl: argv[0]: remove_network [00:00:50.638,031] wpa_supp: wpa_printf_impl: argv[1]: all [00:00:50.644,805] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'REMOVE_NETWORK all' [00:00:50.654,846] wpa_supp: wpa_printf_impl: CTRL_IFACE: REMOVE_NETWORK all [00:00:50.663,238] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'ADD_NETWORK' [00:00:50.672,668] wpa_supp: wpa_printf_impl: CTRL_IFACE: ADD_NETWORK [00:00:50.680,328] wpa_supp: wpa_printf_impl: Received len: 26, msg_len:26 - CTRL-EVENT-NETWORK-ADDED 0->END [00:00:50.691,284] wpa_supp: wpa_printf_impl: NET added: 0 [00:00:50.697,723] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:50.706,359] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:50.713,500] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:50.719,787] wpa_supp: wpa_printf_impl: argv[2]: ssid [00:00:50.726,348] wpa_supp: wpa_printf_impl: argv[3]: "OnePlusAP" [00:00:50.733,856] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:50.744,171] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='ssid' [00:00:50.753,051] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=11): [REMOVED] [00:00:50.763,000] wpa_supp: wpa_printf_impl: ssid - hexdump_ascii(len=9): [00:00:50.770,812] wpa_supp: _wpa_hexdump_ascii: 4f 6e 65 50 6c 75 73 41 50 |OnePlusA P [00:00:50.785,736] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:50.794,342] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:50.801,483] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:50.807,769] wpa_supp: wpa_printf_impl: argv[2]: scan_ssid [00:00:50.814,758] wpa_supp: wpa_printf_impl: argv[3]: 1 [00:00:50.821,380] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:50.831,695] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='scan_ssid' [00:00:50.841,003] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=1): [REMOVED] [00:00:50.850,860] wpa_supp: wpa_printf_impl: scan_ssid=1 (0x1) [00:00:50.857,910] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:50.866,516] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:50.873,657] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:50.879,974] wpa_supp: wpa_printf_impl: argv[2]: key_mgmt [00:00:50.886,840] wpa_supp: wpa_printf_impl: argv[3]: NONE [00:00:50.893,737] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:50.904,052] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='key_mgmt' [00:00:50.913,299] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=4): [REMOVED] [00:00:50.923,156] wpa_supp: wpa_printf_impl: key_mgmt: 0x4 [00:00:50.929,840] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:50.938,446] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:50.945,587] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:50.951,873] wpa_supp: wpa_printf_impl: argv[2]: ieee80211w [00:00:50.958,953] wpa_supp: wpa_printf_impl: argv[3]: 0 [00:00:50.965,576] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:50.975,891] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='ieee80211w' [00:00:50.985,290] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=1): [REMOVED] [00:00:50.995,147] wpa_supp: wpa_printf_impl: ieee80211w=0 (0x0) [00:00:51.002,410] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 17 [00:00:51.011,108] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:51.018,249] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:51.024,566] wpa_supp: wpa_printf_impl: argv[2]: scan_freq [00:00:51.031,555] wpa_supp: wpa_printf_impl: argv[3]: 2412 [00:00:51.038,085] wpa_supp: wpa_printf_impl: argv[4]: 2417 [00:00:51.044,647] wpa_supp: wpa_printf_impl: argv[5]: 2422 [00:00:51.051,177] wpa_supp: wpa_printf_impl: argv[6]: 2427 [00:00:51.057,739] wpa_supp: wpa_printf_impl: argv[7]: 2432 [00:00:51.064,270] wpa_supp: wpa_printf_impl: argv[8]: 2437 [00:00:51.070,831] wpa_supp: wpa_printf_impl: argv[9]: 2442 [00:00:51.077,392] wpa_supp: wpa_printf_impl: argv[10]: 2447 [00:00:51.084,014] wpa_supp: wpa_printf_impl: argv[11]: 2452 [00:00:51.090,637] wpa_supp: wpa_printf_impl: argv[12]: 2457 [00:00:51.097,290] wpa_supp: wpa_printf_impl: argv[13]: 2462 [00:00:51.103,912] wpa_supp: wpa_printf_impl: argv[14]: 2467 [00:00:51.110,565] wpa_supp: wpa_printf_impl: argv[15]: 2472 [00:00:51.117,187] wpa_supp: wpa_printf_impl: argv[16]: 2484 [00:00:51.124,237] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:51.134,552] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='scan_freq' [00:00:51.143,859] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=69): [REMOVED] [00:00:51.154,022] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:51.162,628] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:51.169,769] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:51.176,055] wpa_supp: wpa_printf_impl: argv[2]: proto [00:00:51.182,708] wpa_supp: wpa_printf_impl: argv[3]: RSN [00:00:51.189,483] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:51.199,798] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='proto' [00:00:51.208,770] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=3): [REMOVED] [00:00:51.218,627] wpa_supp: wpa_printf_impl: proto: 0x2 [00:00:51.225,067] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:51.233,673] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:51.240,814] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:51.247,100] wpa_supp: wpa_printf_impl: argv[2]: psk [00:00:51.253,570] wpa_supp: wpa_printf_impl: argv[3]: "xxxx" [00:00:51.261,413] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:51.271,728] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='psk' [00:00:51.280,517] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=15): [REMOVED] [00:00:51.290,496] wpa_supp: wpa_printf_impl: PSK (ASCII passphrase) - hexdump_ascii(len=13): [REMOVED] [00:00:53.779,022] wpa_supp: wpa_printf_impl: PSK (from passphrase) - hexdump(len=32): [REMOVED] [00:00:53.788,970] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:53.797,576] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:53.804,718] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:53.811,004] wpa_supp: wpa_printf_impl: argv[2]: key_mgmt [00:00:53.817,901] wpa_supp: wpa_printf_impl: argv[3]: WPA-PSK [00:00:53.825,042] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:53.835,357] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='key_mgmt' [00:00:53.844,604] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=7): [REMOVED] [00:00:53.854,461] wpa_supp: wpa_printf_impl: key_mgmt: 0x2 [00:00:53.861,145] wpa_supp: wpa_printf_impl: Calling wpa_cli: set_network, argc: 4 [00:00:53.869,750] wpa_supp: wpa_printf_impl: argv[0]: set_network [00:00:53.876,892] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:53.883,178] wpa_supp: wpa_printf_impl: argv[2]: ieee80211w [00:00:53.890,258] wpa_supp: wpa_printf_impl: argv[3]: 1 [00:00:53.896,881] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SET_NETWORK [REMOVED]' [00:00:53.907,165] wpa_supp: wpa_printf_impl: CTRL_IFACE: SET_NETWORK id=0 name='ieee80211w' [00:00:53.916,564] wpa_supp: wpa_printf_impl: CTRL_IFACE: value - hexdump_ascii(len=1): [REMOVED] [00:00:53.926,452] wpa_supp: wpa_printf_impl: ieee80211w=1 (0x1) [00:00:53.933,563] wpa_supp: wpa_printf_impl: Calling wpa_cli: enable_network, argc: 2 [00:00:53.942,413] wpa_supp: wpa_printf_impl: argv[0]: enable_network [00:00:53.949,829] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:53.956,451] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'ENABLE_NETWORK 0' [00:00:53.966,308] wpa_supp: wpa_printf_impl: CTRL_IFACE: ENABLE_NETWORK id=0 [00:00:53.974,456] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 0.000000 sec [00:00:53.983,581] wpa_supp: wpa_printf_impl: wlan0: State: DISCONNECTED -> SCANNING [00:00:53.992,309] wpa_supp: wpa_printf_impl: Scan SSID - hexdump_ascii(len=9): [00:00:54.000,549] wpa_supp: _wpa_hexdump_ascii: 4f 6e 65 50 6c 75 73 41 50 |OnePlusA P [00:00:54.015,380] wpa_supp: wpa_printf_impl: wlan0: Include wildcard SSID in the scan request [00:00:54.025,115] wpa_supp: wpa_printf_impl: wlan0: Add radio work 'scan'@0x2004f138 [00:00:54.033,966] wpa_supp: wpa_printf_impl: wlan0: First radio work item in the queue - schedule start immediately [00:00:54.045,684] wpa_supp: wpa_printf_impl: wlan0: Starting radio work 'scan'@0x2004f138 after 0.011688 second wait [00:00:54.057,678] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:00:54.066,955] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:00:54.073,913] wifi_nrf_bus: : RDSR2 = 0x1 [00:00:54.080,108] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:54.086,273] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:54.092,559] wpa_supp: wpa_printf_impl: Calling wpa_cli: select_network, argc: 2 [00:00:54.093,566] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:54.107,666] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:54.114,074] wpa_supp: wpa_printf_impl: argv[0]: select_network [00:00:54.115,020] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 0 sent to RPU [00:00:54.122,528] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:00:54.131,072] wpa_supp: wpa_printf_impl: wpa_drv_zep_scan2: Scan requested - scan timeout 35 seconds [00:00:54.140,930] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 257 received from UMAC [00:00:54.161,621] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 257 processed [00:00:54.170,867] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:00:54.180,725] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 received from UMAC [00:00:54.190,765] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Command 0 -> status 0 [00:00:54.200,195] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 processed [00:00:54.209,472] wifi_supplicant: event_socket_handler: Passing message 47 to wpa_supplicant [00:00:54.219,055] wpa_supp: wpa_printf_impl: wlan0: Event SCAN_STARTED (47) received [00:00:54.227,935] wpa_supp: wpa_printf_impl: wlan0: Own scan request started a scan in 0.076355 seconds [00:00:54.238,586] wpa_supp: wpa_printf_impl: Received len: 24, msg_len:24 - CTRL-EVENT-SCAN-STARTED ->END [00:00:54.249,328] wpa_supp: wpa_printf_impl: argv[1]: 0 [00:00:54.255,889] wpa_supp: wpa_printf_impl: wlan0: Control interface command 'SELECT_NETWORK 0' [00:00:54.265,747] wpa_supp: wpa_printf_impl: CTRL_IFACE: SELECT_NETWORK id=0 [00:00:54.273,895] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 0.000000 sec [00:00:54.283,020] wpa_supp: wpa_printf_impl: wlan0: Already scanning - Reschedule the incoming scan req [00:00:54.293,518] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 1.000000 sec Connection requested [00:00:54.986,846] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:00:54.996,002] wifi_nrf_bus: : RDSR2 = 0x1 [00:00:55.004,394] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.012,725] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.022,247] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.030,578] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.039,611] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:00:55.051,635] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 259 received from UMAC [00:00:55.064,025] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 259 processed [00:00:55.075,469] wifi_supplicant: event_socket_handler: Passing message 3 to wpa_supplicant [00:00:55.087,158] wpa_supp: wpa_printf_impl: wlan0: Event SCAN_RESULTS (3) received [00:00:55.098,114] wpa_supp: wpa_printf_impl: wlan0: Scan completed in 0.870178 seconds [00:00:55.109,313] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:00:55.120,605] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:00:55.129,791] wifi_nrf_bus: : RDSR2 = 0x1 [00:00:55.138,153] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.146,484] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.156,005] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.164,306] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:55.173,400] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 1 sent to RPU [00:00:55.184,204] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:00:55.196,228] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 260 received from UMAC [00:00:55.208,618] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 260 processed [00:00:55.220,062] wpa_supp: wpa_printf_impl: Sorted scan results [00:00:55.229,370] wpa_supp: wpa_printf_impl: de:76:06:70:00:3a ssid=OnePlusAP freq=2462 qual=0 noise=-89~ level=-46 snr=43* flags=0xb age=502 est=65000 [00:00:55.247,741] wpa_supp: wpa_printf_impl: IEs - hexdump(len=218): 00 09 4f 6e 65 50 6c 75 73 41 50 01 08 82 84 8b 96 0c 12 18 24 03 01 0b 05 04 01 02 00 00 32 04 30 48 [00:00:55.279,174] wpa_supp: wpa_printf_impl: Beacon IEs - hexdump(len=218): 00 09 4f 6e 65 50 6c 75 73 41 50 01 08 82 84 8b 96 0c 12 18 24 03 01 0b 05 04 01 02 00 00 32 00 [00:00:55.309,112] wpa_supp: wpa_printf_impl: wlan0: BSS: Start scan result update 1 [00:00:55.320,281] wpa_supp: wpa_printf_impl: wlan0: BSS: Add new id 0 BSSID de:76:06:70:00:3a SSID 'OnePlusAP' freq 2462 [00:00:55.334,533] wpa_supp: wpa_printf_impl: BSS: last_scan_res_used=1/32 [00:00:55.344,604] wpa_supp: wpa_printf_impl: wlan0: New scan results available (own=1 ext=0) [00:00:55.356,475] wpa_supp: wpa_printf_impl: wlan0: Radio work 'scan'@0x2004f138 done in 1.310791 seconds [00:00:55.369,384] wpa_supp: wpa_printf_impl: wlan0: radio_work_free('scan'@0x2004f138): num_active_works --> 0 [00:00:55.382,690] wpa_supp: wpa_printf_impl: wlan0: Scan results matching the currently selected network [00:00:55.395,568] wpa_supp: wpa_printf_impl: unknown vendor specific information element ignored (vendor OUI 00:0c:e7 len=7) [00:00:55.410,095] wpa_supp: wpa_printf_impl: wlan0: MLD: No Multi-Link element [00:00:55.420,684] wpa_supp: wpa_printf_impl: wlan0: 0: de:76:06:70:00:3a freq=2462 level=-46 snr=43 est_throughput=65000 [00:00:55.434,875] wpa_supp: wpa_printf_impl: wlan0: Selecting BSS from priority group 0 [00:00:55.446,319] wpa_supp: wpa_printf_impl: wlan0: 0: de:76:06:70:00:3a ssid='OnePlusAP' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-46 freq=2462 [00:00:55.463,012] wpa_supp: wpa_printf_impl: wlan0: selected based on RSN IE [00:00:55.473,632] wpa_supp: wpa_printf_impl: unknown vendor specific information element ignored (vendor OUI 00:0c:e7 len=7) [00:00:55.488,159] wpa_supp: wpa_printf_impl: wlan0: MLD: No Multi-Link element [00:00:55.498,718] wpa_supp: wpa_printf_impl: wlan0: selected BSS de:76:06:70:00:3a ssid='OnePlusAP' [00:00:55.511,596] wpa_supp: wpa_printf_impl: wlan0: Considering connect request: reassociate: 1 selected: de:76:06:70:00:3a bssid: 00:00:00:00:00:00 pending: 00:00:00:8 [00:00:55.536,407] wpa_supp: wpa_printf_impl: wlan0: Request association with de:76:06:70:00:3a [00:00:55.548,339] wpa_supp: wpa_printf_impl: wlan0: No ongoing scan/p2p-scan found to abort [00:00:55.559,997] wpa_supp: wpa_printf_impl: wlan0: Add radio work 'sme-connect'@0x2004b980 [00:00:55.571,685] wpa_supp: wpa_printf_impl: wlan0: First radio work item in the queue - schedule start immediately [00:00:55.585,571] wpa_supp: wpa_printf_impl: wlan0: Starting AP scan for wildcard SSID [00:00:55.596,893] wpa_supp: wpa_printf_impl: wlan0: Add radio work 'scan'@0x2004f230 [00:00:55.607,971] wpa_supp: wpa_printf_impl: Received len: 40, msg_len:40 - CTRL-EVENT-BSS-ADDED 0 de:76:06:70:00:3a->END [00:00:55.622,314] wpa_supp: wpa_printf_impl: Received len: 24, msg_len:24 - CTRL-EVENT-SCAN-RESULTS ->END [00:00:55.635,345] wpa_supp: wpa_printf_impl: wlan0: Starting radio work 'sme-connect'@0x2004b980 after 0.063629 second wait [00:00:55.649,780] wpa_supp: wpa_printf_impl: wlan0: WPA: clearing own WPA/RSN IE [00:00:55.660,430] wpa_supp: wpa_printf_impl: wlan0: RSN: clearing own RSNXE [00:00:55.670,715] wpa_supp: wpa_printf_impl: wlan0: Automatic auth_alg selection: 0x1 [00:00:55.681,854] wpa_supp: wpa_printf_impl: wlan0: RSN: using IEEE 802.11i/D9.0 [00:00:55.692,565] wpa_supp: wpa_printf_impl: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2 [00:00:55.706,756] wpa_supp: wpa_printf_impl: wlan0: WPA: Selected mgmt group cipher 32 [00:00:55.717,956] wpa_supp: wpa_printf_impl: wlan0: WPA: clearing AP WPA IE [00:00:55.728,363] wpa_supp: wpa_printf_impl: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00 [00:00:55.744,964] wpa_supp: wpa_printf_impl: wlan0: WPA: clearing AP RSNXE [00:00:55.755,126] wpa_supp: wpa_printf_impl: wlan0: RSN: Clearing AP RSNE Override element [00:00:55.766,693] wpa_supp: wpa_printf_impl: wlan0: RSN: Clearing AP RSNE Override 2 element [00:00:55.778,411] wpa_supp: wpa_printf_impl: wlan0: RSN: Clearing AP RSNXE Override element [00:00:55.790,100] wpa_supp: wpa_printf_impl: wlan0: WPA: AP group 0x10 network profile group 0x18; available group 0x10 [00:00:55.804,199] wpa_supp: wpa_printf_impl: wlan0: WPA: using GTK CCMP [00:00:55.814,147] wpa_supp: wpa_printf_impl: wlan0: WPA: AP pairwise 0x10 network profile pairwise 0x18; available pairwise 0x10 [00:00:55.829,010] wpa_supp: wpa_printf_impl: wlan0: WPA: using PTK CCMP [00:00:55.838,958] wpa_supp: wpa_printf_impl: wlan0: WPA: AP key_mgmt 0x2 network profile key_mgmt 0x2; available key_mgmt 0x2 [00:00:55.853,546] wpa_supp: wpa_printf_impl: wlan0: WPA: using KEY_MGMT WPA-PSK [00:00:55.864,227] wpa_supp: wpa_printf_impl: wlan0: WPA: AP mgmt_group_cipher 0x20 network profile mgmt_group_cipher 0x0; available mgmt_group_cipher 0x0 [00:00:55.881,286] wpa_supp: wpa_printf_impl: wlan0: WPA: not using MGMT group cipher [00:00:55.892,456] wpa_supp: wpa_printf_impl: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 8c 00 [00:00:55.909,851] wpa_supp: wpa_printf_impl: RSN: Set own RSNXE default - hexdump(len=0): [00:00:55.921,386] wpa_supp: wpa_printf_impl: PSK (set in config) - hexdump(len=32): [REMOVED] [00:00:55.933,166] wpa_supp: wpa_printf_impl: WPA: Set PMK based on external data - hexdump(len=32): [REMOVED] [00:00:55.946,380] wpa_supp: wpa_printf_impl: RRM: Determining whether RRM can be used - device support: 0x50 [00:00:55.959,442] wpa_supp: wpa_printf_impl: RRM: No RRM in network [00:00:55.969,055] wpa_supp: wpa_printf_impl: wlan0: Cancelling scan request [00:00:55.979,400] wpa_supp: wlan0: SME: Trying to authenticate with de:76:06:70:00:3a (SSID='OnePlusAP' freq=2462 MHz) [00:00:55.993,438] wpa_supp: wpa_printf_impl: wlan0: State: SCANNING -> AUTHENTICATING [00:00:56.005,096] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:00:56.016,693] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:00:56.025,848] wifi_nrf_bus: : RDSR2 = 0x1 [00:00:56.034,240] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.042,572] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.052,093] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.060,424] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.070,800] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 2 sent to RPU [00:00:56.081,481] wifi_nrf: nrf_wifi_wpa_supp_authenticate: nrf_wifi_wpa_supp_authenticate:Authentication request sent successfully [00:00:56.096,771] wpa_supp: wpa_printf_impl: Received len: 83, msg_len:83 - SME: Trying to authenticate with de:76:06:70:00:3a (SSID='OnePlusAP' freq=2462 MHz)->END [00:00:56.439,453] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:00:56.448,608] wifi_nrf_bus: : RDSR2 = 0x1 [00:00:56.457,000] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.465,332] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.474,853] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.483,184] wifi_nrf_bus: : RDSR1 = 0x6 [00:00:56.492,187] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:00:56.504,241] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 received from UMAC [00:00:56.516,479] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Command 2 -> status 0 [00:00:56.528,076] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 processed [00:01:01.096,679] wpa_supp: wpa_printf_impl: wlan0: SME: Authentication timeout [00:01:01.107,299] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:01:01.118,591] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:01.127,746] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:01.136,138] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.144,470] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.153,961] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.162,261] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.171,051] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 4 sent to RPU [00:01:01.181,823] wpa_supp: wpa_printf_impl: wlan0: Radio work 'sme-connect'@0x2004b980 done in 5.546448 seconds [00:01:01.195,343] wpa_supp: wpa_printf_impl: wlan0: radio_work_free('sme-connect'@0x2004b980): num_active_works --> 0 [00:01:01.209,350] wpa_supp: wlan0: Added BSSID de:76:06:70:00:3a into ignore list, ignoring for 10 seconds [00:01:01.222,381] wpa_supp: wpa_printf_impl: wlan0: Consecutive connection failures: 1 --> request scan in 100 ms [00:01:01.235,961] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 0.100000 sec [00:01:01.247,192] wpa_supp: wpa_printf_impl: wlan0: State: AUTHENTICATING -> DISCONNECTED [00:01:01.258,911] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:01:01.270,324] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:01.279,479] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:01.287,872] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.296,203] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.305,725] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.314,025] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.323,638] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 21 sent to RPU [00:01:01.334,594] wpa_supp: wpa_printf_impl: wlan0: Starting radio work 'scan'@0x2004f230 after 5.726623 second wait [00:01:01.348,785] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:01:01.360,260] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:01.369,415] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:01.377,807] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.386,138] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.395,629] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.403,930] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:01.413,543] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 0 sent to RPU [00:01:01.424,255] wpa_supp: wpa_printf_impl: wpa_drv_zep_scan2: Scan requested - scan timeout 35 seconds [00:01:01.437,103] wpa_supp: wpa_printf_impl: Received len: 71, msg_len:71 - Added BSSID de:76:06:70:00:3a into ignore list, ignoring for 10 seconds->END [00:01:01.454,162] wpa_supp: wpa_printf_impl: wlan0: Already scanning - Reschedule the incoming scan req [00:01:01.466,857] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 1.000000 sec [00:01:02.174,072] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:02.183,258] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:02.191,650] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:02.199,981] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:02.209,503] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:02.217,834] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:02.227,081] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:01:02.239,166] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 267 received from UMAC [00:01:02.251,373] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 267 processed [00:01:02.478,149] wpa_supp: wpa_printf_impl: wlan0: Already scanning - Reschedule the incoming scan req [00:01:02.490,844] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 1.000000 sec [00:01:03.502,166] wpa_supp: wpa_printf_impl: wlan0: Already scanning - Reschedule the incoming scan req [00:01:03.514,862] wpa_supp: wpa_printf_impl: wlan0: Setting scan request: 1.000000 sec [00:01:04.177,703] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:04.186,889] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:04.195,281] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.203,613] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.213,134] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.221,466] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.232,116] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:01:04.244,232] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 264 received from UMAC [00:01:04.256,591] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 264 processed [00:01:04.268,035] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:01:04.280,090] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 received from UMAC [00:01:04.292,297] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Command 21 -> status -2 [00:01:04.304,107] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 processed [00:01:04.315,551] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:01:04.327,606] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 257 received from UMAC [00:01:04.339,874] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 257 processed [00:01:04.351,318] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_sys_fmac_event_callback: Event type 3 recd [00:01:04.363,342] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 received from UMAC [00:01:04.375,579] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Command 0 -> status 0 [00:01:04.387,207] wifi_nrf: zep_shim_pr_dbg: umac_event_ctrl_process: Event 292 processed [00:01:04.398,651] wifi_supplicant: event_socket_handler: Passing message 11 to wpa_supplicant [00:01:04.410,461] wpa_supp: wpa_printf_impl: wlan0: Event DEAUTH (11) received [00:01:04.420,959] wpa_supp: wpa_printf_impl: wlan0: Deauthentication notification [00:01:04.431,732] wpa_supp: wpa_printf_impl: wlan0: * reason 3 (DEAUTH_LEAVING) locally_generated=1 [00:01:04.444,183] wpa_supp: wpa_printf_impl: wlan0: * address 00:18:07:01:6d:08 [00:01:04.454,864] wpa_supp: wpa_printf_impl: Deauthentication frame IE(s) - hexdump(len=0): [NULL] [00:01:04.467,132] wpa_supp: wpa_printf_impl: wlan0: Auto connect enabled: try to reconnect (wps=0/0 wpa_state=0) [00:01:04.480,590] wpa_supp: wpa_printf_impl: wlan0: Do not request new immediate scan [00:01:04.491,699] wpa_supp: wpa_printf_impl: wlan0: WPA: Clear old PMK and PTK [00:01:04.502,502] wpa_supp: wpa_printf_impl: wlan0: Disconnect event - remove keys [00:01:04.513,366] wpa_supp: wpa_printf_impl: wlan0: State: DISCONNECTED -> DISCONNECTED [00:01:04.524,932] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:01:04.536,346] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:04.545,501] wifi_nrf_bus: : RDSR2 = 0x1 [00:01:04.553,894] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.562,225] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.571,746] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.580,078] wifi_nrf_bus: : RDSR1 = 0x6 [00:01:04.590,179] wifi_nrf: zep_shim_pr_dbg: umac_cmd_cfg: Command 21 sent to RPU [00:01:04.601,104] wpa_supp: wpa_printf_impl: wlan0: State: DISCONNECTED -> SCANNING [00:01:04.612,030] wpa_supp: wpa_printf_impl: Scan SSID - hexdump_ascii(len=9): [00:01:04.622,467] wpa_supp: _wpa_hexdump_ascii: 4f 6e 65 50 6c 75 73 41 50 |OnePlusA P [00:01:04.639,465] wpa_supp: wpa_printf_impl: wlan0: Include wildcard SSID in the scan request [00:01:04.651,336] wpa_supp: wlan0: Reject scan trigger since one is already pending [00:01:04.662,292] wpa_supp: wlan0: Failed to initiate AP scan [00:01:04.671,600] wpa_supp: wpa_printf_impl: wlan0: State: SCANNING -> DISCONNECTED [00:01:04.682,800] wifi_nrf: zep_shim_pr_dbg: nrf_wifi_hal_ctrl_cmd_send: caller 0x5e4cd [00:01:04.694,244] wifi_nrf_bus: rpu_wrsr2: Written 0x1 to WRSR2 [00:01:04.703,399] wifi_nrf_bus:

Sebastian Petersen · Accepted Answer

Hello Simon, 
 We figured out the source of the error. The output voltage for VBAT was very unstable under an oscillospoce with a PK-PK of 700mV around an RMS of 3.3V. Since the current draw was larger than expected the resulting voltage drop and oscillations would drop the VBAT voltage under 2.9V at some points during transmissions. We experienced a plain old brown out in this case. Thank you for you time, we have resolved the issue.