DHCP Timeout

[thp2023]

I am attempting to run a throughput test using the nrf7002 DK as the client and the Rhode & Schwarz CMW 500 Connectivity Tester (The tester can emulate a router). I am using the sr_coex example in the sdk-nrf repo. During the test, I see in the logs the following error message:

<err> coex: wait_for_next_event: Timeout waiting for Wi-Fi DHCP -> -11

According to the Rhode & Schwarz tester, the nrf7002 DK was given an IP address but according to the board, it never received an IP address. I have tested the board with my local router, and it was able to receive an IP address with no error and the test will finish. 

I have posted a picture that shows the WIFI settings for the Rhode &Schwarz tester and in the the DUT/UE Info box, it shows that the nrf7002 DK was given an IP address, but when checking the logs from the nrf board, it fails at 'Waiting for WiFI DHCP'

[00:00:00.273,895] <inf> wifi_nrf: qspi_init: QSPI freq = 24 MHz


[00:00:00.273,925] <inf> wifi_nrf: qspi_init: QSPI latency = 1

[00:00:00.281,402] <inf> wifi_nrf: zep_shim_pr_info: wifi_nrf_fmac_fw_load: LMAC patches loaded


[00:00:00.292,266] <inf> wifi_nrf: zep_shim_pr_info: wifi_nrf_fmac_fw_load: LMAC boot check passed

[00:00:00.295,227] <inf> wifi_nrf: zep_shim_pr_info: wifi_nrf_fmac_fw_load: UMAC patches loaded


[00:00:00.306,030] <inf> wifi_nrf: zep_shim_pr_info: wifi_nrf_fmac_fw_load: UMAC boot check passed


[00:00:00.327,880] <inf> wifi_nrf: zep_shim_pr_info: RPU LPM type: HW

*** Booting Zephyr OS build v3.2.99-ncs2 ***

[00:00:00.442,596] <inf> net_config: net_config_init_by_iface: Initializing network

[00:00:00.442,626] <inf> net_config: check_interface: Waiting interface 1 (0x20001bc0) to be up...

[00:00:00.442,626] <inf> net_config: setup_dhcpv4: Running dhcpv4 client...

[00:00:00.443,542] <inf> coex: main: Starting nrf7002dk_nrf5340_cpuapp with CPU frequency: 128 MHz

[00:00:00.443,664] <inf> wpa_supp: wpa_printf_impl: z_wpas_start: 385 Starting wpa_supplicant thread with debug level: 3

[00:00:00.443,756] <inf> wpa_supp: wpa_printf_impl: Successfully initialized wpa_supplicant

[00:00:01.443,603] <inf> coex: main: test_wlan = 1 and test_ble = 0

[00:00:01.443,603] <inf> wifi_nrf: nrf_wifi_config_sr_switch: GPIO P1.10 set to 0

[00:00:01.462,738] <inf> coex: wifi_connect: Connection requested

[00:00:01.462,738] <inf> coex: wait_for_next_event: Waiting for Wi-Fi Connection

[00:00:05.783,294] <inf> wpa_supp: wpa_printf_impl: wlan0: SME: Trying to authenticate with 00:01:02:03:04:05 (SSID='CMW-AP' freq=2412 MHz)

[00:00:05.785,491] <inf> wifi_nrf: wifi_nrf_wpa_supp_authenticate: wifi_nrf_wpa_supp_authenticate:Authentication request sent successfully

[00:00:06.041,442] <inf> wpa_supp: wpa_printf_impl: wlan0: Trying to associate with 00:01:02:03:04:05 (SSID='CMW-AP' freq=2412 MHz)

[00:00:06.046,600] <inf> wifi_nrf: wifi_nrf_wpa_supp_associate: wifi_nrf_wpa_supp_associate: Association request sent successfully

[00:00:06.056,732] <inf> wpa_supp: wpa_printf_impl: wlan0: Associated with 00:01:02:03:04:05

[00:00:06.056,884] <inf> wpa_supp: wpa_printf_impl: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:01:02:03:04:05 completed [id=0 id_str=]

[00:00:06.060,943] <inf> coex: handle_wifi_connect_result: Connected

[00:00:06.061,065] <inf> wpa_supp: wpa_printf_impl: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0

[00:00:06.066,192] <inf> coex: cmd_wifi_status: Status: successful

[00:00:06.066,192] <inf> coex: cmd_wifi_status: ==================

[00:00:06.066,223] <inf> coex: cmd_wifi_status: State: ASSOCIATED

[00:00:06.066,223] <inf> coex: cmd_wifi_status: Interface Mode: STATION

[00:00:06.066,253] <inf> coex: cmd_wifi_status: Link Mode: WIFI 3 (802.11g)

[00:00:06.066,253] <inf> coex: cmd_wifi_status: SSID: CMW-AP                          


[00:00:06.066,284] <inf> coex: cmd_wifi_status: BSSID: 00:01:02:03:04:05

[00:00:06.066,284] <inf> coex: cmd_wifi_status: Band: 2.4GHz

[00:00:06.066,284] <inf> coex: cmd_wifi_status: Channel: 1

[00:00:06.066,284] <inf> coex: cmd_wifi_status: Security: OPEN

[00:00:06.066,314] <inf> coex: cmd_wifi_status: MFP: Disable

[00:00:06.066,314] <inf> coex: cmd_wifi_status: RSSI: -82

[00:00:06.066,375] <inf> coex: wait_for_next_event: Got Wi-Fi Connection

[00:00:06.066,406] <inf> coex: wait_for_next_event: Waiting for Wi-Fi DHCP

[00:00:16.066,467] <err> coex: wait_for_next_event: Timeout waiting for Wi-Fi DHCP -> -11

 

[Marte Myrvold]

Hi,

Are you setting the correct security option in prj.conf? You must set one of these:

# Below configs need to be modified based on security
# CONFIG_STA_KEY_MGMT_NONE=y
# CONFIG_STA_KEY_MGMT_WPA2=y
# CONFIG_STA_KEY_MGMT_WPA2_256=y
# CONFIG_STA_KEY_MGMT_WPA3=y

From your log, I see that security is set to OPEN (CONFIG_STA_KEY_MGMT_NONE). This is the default configuration when none of the above are selected.

Best regards,
Marte

[thp2023]

The access point did not have security configured during the test which is why I didn't set any security configuration. In the logs, it shows that a wifi connection was established, so the security config should be correct. I did try setting the access point with WPA2 personal and I got the same error 'Timeout waiting for Wifi DHCP -> -11'

[Marte Myrvold]

Hi,

Is the DHCP server enabled on the CMW500?

Have you tested with other Wi-Fi versions or only 802.11g (Wi-Fi 3)?

Best regards,
Marte

[thp2023]

I can confirm the DHCP server is enabled on the CMW500. I can see on the CMW500 it gave the nrf board an IPv4 address. I tested 802.11 ac and that didn't work

[Marte Myrvold]

Hi,

This might be related to this issue: https://github.com/zephyrproject-rtos/zephyr/issues/55781, where some APs are not conforming to bootp/DHCP RFC.

Can you get a sniffer trace of the traffic that shows the DHCP process?

Best regards,
Marte