Websocket connection has timeout too frequently

[esmart-engineering]

I am evaluating the nRF7002's WiFi capabilities and starting off with the nRF52840DK + nRF7002EK and a project that connects to a socket and sends data. I've primarily used the Websocket Client example (NCS v2.9.1, zephyr/samples/net/sockets/websocket_client) though I mixed in some code from the WiFi station project to ensure I connect to my local WiFi first (NCS v2.9.1, nrf/samples/wifi/sta). The server socket is one I set up with a simple Python script that simply reports any data sent to it.

Functionally my code is working: able to connect to WiFi, connect to socket, and send some data. For sending data, I'm having it repeatedly call websocket_connect(); it will return with an error but my server still gets the data (which is acceptable at this time of evaluation).

However, once my code gets to the connect() call as part of connect_socket(), it will occasionally (roughly 50% of the time) timeout after the default 3sec. I modified it to repeatedly call connect() until it succeeds, and noticed it may take 2-3 tries to connect. But this means that it's taking almost 10sec at most just to simply connect to a socket.

Could you please help look into why this operation is taking so long? We've created custom boards with nRF for years, and recently also with nRF7002. While it was developed through Linux drivers and such rather than with NCS/VS-Code/etc., we determined it can connect to WiFi, connect to socket, and send a little data all comfortably in <10sec. So I'm expecting similar performance.

More info: I am using a Windows 11 machine, VS Code, & nRF Connect Extension. It was already mentioned earlier but we're also using NCS v2.9.1, nRF52840DK, and nRF7002EK.

--------------------------------------------------------

Note that I also tried one of Nordic's official networking samples - the HTTPS client one (NCS v2.9.1, nrf/samples/net/https_client). But I'm not able to proceed that far because it's unable to connect to my local WiFi.

• Made a build config
  • Board target: nrf52840dk/nrf52840
  • Config files: prj.conf, boards/native_sim.conf
    • Had to add native_sim.conf or else I would've had build errors
  • CMake arguments: -DSHIELD="nrf7002ek"
• Tried the build from above, but command line wouldn't respond to any user input, so I couldn't type in the "wifi_cred" command
• Then tried modifying prj.conf to have the static WiFi credentials, but it still wouldn't proceed past "Connecting to the network"

[Håkon Alseth]

Hi,

 

Functionally my code is working: able to connect to WiFi, connect to socket, and send some data. For sending data, I'm having it repeatedly call websocket_connect(); it will return with an error but my server still gets the data (which is acceptable at this time of evaluation).

However, once my code gets to the connect() call as part of connect_socket(), it will occasionally (roughly 50% of the time) timeout after the default 3sec. I modified it to repeatedly call connect() until it succeeds, and noticed it may take 2-3 tries to connect. But this means that it's taking almost 10sec at most just to simply connect to a socket.

Can you share logs and relevant code for this procedure?

Are you closing your sockets after use?

 

If you are already connected via a socket, you should not run connect() multiple times.

 

Note that I also tried one of Nordic's official networking samples - the HTTPS client one (NCS v2.9.1, nrf/samples/net/https_client).

This sample does not have support for the board combination that you're using:

https://docs.nordicsemi.com/bundle/ncs-latest/page/nrf/samples/net/https_client/README.html#requirements

 

Kind regards,

Håkon

[esmart-engineering]

I tested closing my socket after use but it did not help.

Here's the relevant code:

int sock4 = -1;

static int wifi_connect(void) { // same definition as WiFi station example }

static int wifi_shutdown(void)
{   // based off NCS v2.9.1 (nrf/samples/wifi/shutdown)
	int ret;
	struct net_if *iface = net_if_get_default();

	if (!net_if_is_admin_up(iface)) {
		return 0;
	}

	ret = net_if_down(iface);
	if (ret) {
		LOG_ERR("Cannot bring down iface (%d)", ret);
		return ret;
	}

	LOG_INF("Interface down");

	return 0;
}

int connect_to_server(void)
{   // based off Websocket client example
    
	struct sockaddr_in addr4;
	size_t amount;
	int ret = -1;

	LOG_INF("Try to open as client");
	while (ret < 0) {
		if (IS_ENABLED(CONFIG_NET_IPV4)) {
			ret = connect_socket(AF_INET, SERVER_ADDR4, SERVER_PORT,
						&sock4, (struct sockaddr *)&addr4,
						sizeof(addr4));
		}
		if (sock4 < 0 || ret < 0) {
			LOG_ERR("Cannot create HTTP connection.");
			k_sleep(K_SECONDS(1));
		}
	}
}

int send_data_to_server(void)
{   // based off Websocket client example

	/* Just an example how to set extra headers */
	const char *extra_headers[] = {
		"Origin: http://foobar\r\n",
		NULL
	};
	int websock4 = -1;
	int32_t timeout = 150;	// units [ms]

	if (sock4 >= 0 && IS_ENABLED(CONFIG_NET_IPV4)) {
		struct websocket_request req;

		memset(&req, 0, sizeof(req));

		req.host = SERVER_ADDR4;
		req.url = "/";
		req.optional_headers = extra_headers;
		req.cb = connect_cb;
		req.tmp_buf = temp_recv_buf_ipv4;
		req.tmp_buf_len = sizeof(temp_recv_buf_ipv4);

		websock4 = websocket_connect(sock4, &req, timeout, "IPv4");
		if (websock4 < 0) {
			LOG_ERR("Cannot connect to %s:%d (err %d)",
				SERVER_ADDR4, SERVER_PORT,
				websock4);
			// close(sock4);
		}
	}
	if (websock4 < 0) {
		LOG_ERR("No IPv4 connectivity");
		return -2;
	}
	LOG_INF("Websocket IPv4 %d", websock4);
}

int start_app(void)
{       // main() calls this; my main() has same definition as main() from WiFi station example
	LOG_INF("Static IP address (overridable): %s/%s -> %s",
		CONFIG_NET_CONFIG_MY_IPV4_ADDR,
		CONFIG_NET_CONFIG_MY_IPV4_NETMASK,
		CONFIG_NET_CONFIG_MY_IPV4_GW);
		
	while (1) {
	    wifi_connect();

		while (!context.connect_result) {
			cmd_wifi_status();
			k_sleep(K_MSEC(STATUS_POLLING_MS));
		}

		if (context.connected) {
			cmd_wifi_status();

			connect_to_server();
			
			// Send data multiple times
			for (uint8_t i = 0; i < 10; i ++) {
			    send_data_to_server();
			}
			
			// Close socket
			    // NOTE - didn't try with websock4, since I see "No IPv4 connectivity" log output
			if (sock4 >= 0) {
			    close(sock4);
			}

			wifi_shutdown();
			k_sleep(K_SECONDS(1));

			sys_poweroff();
		}
	}
}

Here's the log I get:

Fullscreen websocket_log.txt Download

[00:00:00.507,476] <inf> wifi_nrf_bus: SPIM spi@4002f000: freq = 8 MHz
[00:00:00.507,507] <inf> wifi_nrf_bus: SPIM spi@4002f000: latency = 0
[00:00:00.642,028] <inf> wifi_nrf: Management buffer offload enabled

*** Booting nRF Connect SDK v2.9.1-60d0d6c8d42d ***
*** Using Zephyr OS v3.7.99-ca954a6216c9 ***
[00:00:00.773,223] <inf> net_config: Initializing network
[00:00:00.773,223] <inf> net_config: Waiting interface 1 (0x200018c8) to be up...
[00:00:00.773,406] <inf> net_config: IPv4 address: 192.168.1.99
[00:00:00.773,468] <inf> net_config: Running dhcpv4 client...
[00:00:00.774,505] <inf> sta: Starting nrf52840dk with CPU frequency: 64 MHz
[00:00:00.777,252] <inf> wifi_supplicant: wpa_supplicant initialized
....[00:00:01.774,780] <inf> sta: Static IP address (overridable): 192.168.1.99/255.255.255.0 -> 192.168.1.1
[00:00:03.476,074] <inf> wifi_mgmt_ext: Connection requested
[00:00:03.476,104] <inf> sta: Connection requested
[00:00:03.476,165] <inf> sta: ==================
[00:00:03.476,196] <inf> sta: State: SCANNING
[00:00:03.776,336] <inf> sta: ==================
[00:00:03.776,367] <inf> sta: State: SCANNING
[00:00:04.076,507] <inf> sta: ==================
[00:00:04.076,538] <inf> sta: State: SCANNING
[00:00:04.376,678] <inf> sta: ==================
[00:00:04.376,708] <inf> sta: State: SCANNING
[00:00:04.676,849] <inf> sta: ==================
[00:00:04.676,879] <inf> sta: State: SCANNING
[00:00:04.977,020] <inf> sta: ==================
[00:00:04.977,050] <inf> sta: State: SCANNING
[00:00:05.277,191] <inf> sta: ==================
[00:00:05.277,221] <inf> sta: State: SCANNING
[00:00:05.577,362] <inf> sta: ==================
[00:00:05.577,392] <inf> sta: State: SCANNING
[00:00:05.877,532] <inf> sta: ==================
[00:00:05.877,563] <inf> sta: State: SCANNING
[00:00:06.177,703] <inf> sta: ==================
[00:00:06.177,734] <inf> sta: State: SCANNING
[00:00:06.477,874] <inf> sta: ==================
[00:00:06.477,905] <inf> sta: State: SCANNING
[00:00:06.778,045] <inf> sta: ==================
[00:00:06.778,076] <inf> sta: State: SCANNING
[00:00:07.078,216] <inf> sta: ==================
[00:00:07.078,247] <inf> sta: State: SCANNING
[00:00:07.378,967] <inf> sta: ==================
[00:00:07.378,997] <inf> sta: State: AUTHENTICATING
[00:00:07.679,168] <inf> sta: ==================
[00:00:07.679,199] <inf> sta: State: AUTHENTICATING
[00:00:07.829,711] <inf> sta: Connected
[00:00:07.994,964] <inf> sta: ==================
[00:00:07.994,995] <inf> sta: State: COMPLETED
[00:00:07.995,025] <inf> sta: Interface Mode: STATION
[00:00:07.995,056] <inf> sta: Link Mode: WIFI 4 (802.11n/HT)
[00:00:07.995,086] <inf> sta: SSID: ************
[00:00:07.995,117] <inf> sta: BSSID: ************
[00:00:07.995,147] <inf> sta: Band: 2.4GHz
[00:00:07.995,147] <inf> sta: Channel: 1
[00:00:07.995,178] <inf> sta: Security: WPA2-PSK
[00:00:07.995,208] <inf> sta: MFP: Optional
[00:00:07.995,208] <inf> sta: RSSI: -37
[00:00:07.995,208] <inf> sta: Try to open as client
[00:00:09.321,838] <wrn> net_tcp: net_pkt alloc failure
[00:00:09.626,037] <wrn> net_tcp: net_pkt alloc failure
[00:00:09.930,236] <wrn> net_tcp: net_pkt alloc failure
[00:00:10.951,232] <err> sta: Cannot connect to IPv4 remote (-116)
[00:00:10.951,232] <err> sta: Cannot create HTTP connection.
[00:00:12.052,185] <wrn> net_tcp: net_pkt alloc failure
[00:00:15.052,337] <err> sta: Cannot connect to IPv4 remote (-116)
[00:00:15.052,337] <err> sta: Cannot create HTTP connection.
[00:00:16.278,167] <err> sta: Cannot connect to 192.168.101.98:3001 (err -113)
[00:00:16.278,198] <err> sta: No IPv4 connectivity

Again, for context:

• I call connect() multiple times because there's a timeout in trying to connect; it's confirmed on my server too that no connection is established.
• I see the attempt to connect to socket will timeout if I see "Cannot connect to IPv4 remote (-116)"
• The data arrives on the server if I see " Cannot connect to 192.168.101.98:3001 (err -113)". The message is misleading but my server does receive data.

[Håkon Alseth]

Hi,

 

Where is your socket created?

The log lines here indicate that the network stack isn't able to allocate data:

[00:00:09.321,838] <wrn> net_tcp: net_pkt alloc failure
[00:00:09.626,037] <wrn> net_tcp: net_pkt alloc failure
[00:00:09.930,236] <wrn> net_tcp: net_pkt alloc failure

You can try to adjust the buf size via "CONFIG_NET_BUF_DATA_SIZE", or you can switch do a variable data size buffer for the net stack via "CONFIG_NET_BUF_VARIABLE_DATA_SIZE=y".

 

Kind regards,

Håkon

[esmart-engineering]

Socket is created and a connection is established in connect_to_server().

I will try those KConfig flags when I get in the office next. I previously increased CONFIG_NET_PKT_TX_COUNT from 8 to 16, and this removed those "alloc failure" messages. But the problem still persists.

[Håkon Alseth]

Hi,

 

You're connecting to a server on 192.168.101.x, have you enabled DHCPv4 on the nRF side?

If not, it will default to this IP and mask:

....[00:00:01.774,780] <inf> sta: Static IP address (overridable): 192.168.1.99/255.255.255.0 -> 192.168.1.1

 

Kind regards,

Håkon

[esmart-engineering]

I already have CONFIG_NET_DHCPV4=y. In addition, I had these which probably explain the IP's/masks in the log:

• CONFIG_NET_CONFIG_MY_IPV4_ADDR="192.168.1.99"
• CONFIG_NET_CONFIG_MY_IPV4_NETMASK="255.255.255.0"
• CONFIG_NET_CONFIG_MY_IPV4_GW="192.168.1.1"

[Håkon Alseth]

Hi,

 

Can you confirm that you're receiving an IP within 192.168.101.x range? Or with a netmask of 255.255.0.0 if in the 192.168.x.x range?

Could you please share the full log, and do not take out any of the lines? Feel free to redact the SSID for instance.

 

Kind regards,

Håkon