esp_websocket_client_stop() get stuck (IDFGH-16741)

[huming2207]

Answers checklist.

• I have read the documentation for esp-protocols components and the issue is not addressed there.
• I have updated my esp-protocols branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

What component are you using? If you choose Other, provide details in More Information.

esp_websocket_client

component version

git commit c078c36 or current master

IDF version.

v6.0-dev-3218-g811e27118d

More Information.

Hi @david-cermak @gabsuren @euripedesrocha

It looks like somehow with ESP-IDF v6.0 and the recent versions of esp-websocket-client, calling esp_websocket_client_stop() may get stuck forever in some conditions when the internet is down. Here's our test environment:

• Genuine ESP32-S3-WROOM-1-N16R8 with PSRAM enabled
• ESP-IDF v6.0
• Recent esp-websocket-client (e.g. c078c36)
• Quectel EG800K modem with a SIM that has no data credit left, but still able to dial out and then retrieved IP address, but no Internet access, and a W5500 NIC but no ethernet cable plugged in
• Also have a MQTT client running, it talks to a MQTT server on the internet over WebSocket protocol
• Set esp_websocket_client_config_t->disable_auto_reconnect to true so that we can handle the reconnect logic manually
• Set esp_websocket_client_config_t->network_timeout_ms to 10000ms
• No external proxy is used

Now, if I let the device to run for a while and attempt to connect to a WS and a MQTT server over the modem, since there's no internet access, it will always fail. Then in my firmware, I call the esp_websocket_client_stop() and then esp_websocket_client_destroy(), and try to recreate a new WS client. If I run more than 3-5 attempts, it will stuck forever.

We dig into this issue a bit further and we realised it looks like in the esp_websocket_client_task(), the client->state is 1 (WEBSOCKET_STATE_INIT), and this websocket task stuck at the previous esp_transport_connect() call, even though the network_timeout_ms is 10000ms and it should've been timed out and return way earlier. Therefore I guess this might also be a tcp_transport issue, not the WS client's issue.

This sort of lockup also occasionally happens on MQTT client. It may stuck at the esp_mqtt_client_stop() forever as well. But somehow for us it's less likely to happen.

Here are some of our logs:

• I added a line of log ESP_LOGW(TAG, "Client state: %u; state_bit: 0x%x", client->state, xEventGroupGetBits(client->status_bits)); in the esp_websocket_client_stop() before xEventGroupGetBits(client->status_bits) & STOPPED_BIT
• This is what it be like when it did not stuck, WS client state is 0 (because never connect successfully)

• This is what it be like when it get stuck, WS client state is 1

Regards,
Jackson

[huming2207]

Also I forgot to mention, it seems like on ESP-IDF v5.4.x this lockup will not happen. We will have a try on v5.5 tomorrow and see what will happen.

[huming2207]

@gabsuren we've just done some more investigation.

Firstly it's the DNS. Apparently on ESP-IDF v6 the dns_clear_cache() is causing trouble again. For our mobile ISP, it seems like even with a dead data SIM that doesn't have any credit left, it can still dial out and get IP address. The ISP's DNS service will still work but it doesn't have any internet access. So the DNS server is actually legit, we've tested on Linux and no issue with dig commands.

In the first a few runs on ESP32, if we call dns_clear_cache() before each connection, it will cause getaddrinfo() to lock up.

Here's what it be like - we've added some logs into esp_tls_hostname_to_fd() in esp-tls:

Then after a few attempts, getaddrinfo() never return:

[huming2207]

Also see: espressif/esp-idf#14287

This is an old issue. I think the dns_clear_cache() in espressif/esp-lwip@b15cd2d might be not enough. My guess is you probably need to implement a LwIP IPC call to wrap this LwIP API.

[huming2207]

Meanwhile we can confirm there's no such issue with IDF v5.5.1 and v5.4.3. It's a ESP-IDF v6's thing...

[david-cermak]

Hi @huming2207

Does it happen only if the SIM card has no credit? Looks like a race condition, almost like clearing each callback and the table wasn't in sync?
Could you please try calling that dns_clear_cache() in lwip context, something like:

static esp_err_t my_dns_clear(void *ctx)
{
  dns_clear_cache();
  return ESP_OK;
}

---
// in your code
esp_netif_tcpip_exec(my_dns_clear, NULL);

Also, could you pls share some of your configs:

• LWIP_TCPIP_CORE_LOCKING
• LWIP_USE_ESP_GETADDRINFO

[huming2207]

Hi @david-cermak

Thanks for following this up.

Does it happen only if the SIM card has no credit?

So far I think yes, it happens only in this combo.

Also, could you pls share some of your configs

The LWIP related configs we have are:

CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y
CONFIG_LWIP_LOCAL_HOSTNAME="smartguide"
CONFIG_LWIP_TCP_MSS=1400
CONFIG_LWIP_TCP_TMR_INTERVAL=200
CONFIG_LWIP_TCP_SND_BUF_DEFAULT=5744
CONFIG_LWIP_TCP_WND_DEFAULT=5744
CONFIG_LWIP_TCP_OOSEQ_MAX_PBUFS=4
CONFIG_LWIP_PPP_SUPPORT=y
CONFIG_LWIP_PPP_NOTIFY_PHASE_SUPPORT=y
CONFIG_LWIP_PPP_PAP_SUPPORT=y
CONFIG_LWIP_PPP_CHAP_SUPPORT=y
CONFIG_LWIP_ENABLE_LCP_ECHO=y
CONFIG_LWIP_LCP_ECHOINTERVAL=15
CONFIG_LWIP_LCP_MAXECHOFAILS=4
CONFIG_LWIP_HOOK_IP6_INPUT_NONE=y

Both of the LWIP_TCPIP_CORE_LOCKING and LWIP_USE_ESP_GETADDRINFO are disabled.

Could you please try calling that dns_clear_cache() in lwip context, something like:

I will arrange this test shortly.

Jackson

[huming2207]

Meanwhile I forgot to mention some of our implementation details @david-cermak @gabsuren

Because dns_clear_cache() messed up quite badly last year, we have implemented this logic in our network client manager code:

1. If a network disconnection event is detected, and all the client is down, then stop and destroy all the clients;
2. After all clients are stopped and freed, then wait for 10 seconds, in case there is any other tasks calling getaddrinfo() or in case LwIP DNS stack is still busy waiting for the results coming back
3. Then switch or reset default netif, clear DNS and bring up the clients

I actually not sure for the delay would actually useful or not, but this works on ESP-IDF v5.5 but doesn't work on v6.

I can also confirm our device running IDF v5.5.1 runs for more than 76000 seconds and still running.

[huming2207]

@david-cermak looks like if I use esp_netif_tcpip_exec(); to call dns_clear_cache() in LwIP task, in ESP-IDF v6, it will never return:

In the first a few runs, it returns with "DNS cleared", see below:

Then afterwards - no more "DNS cleared"!

Here's our clear routine:

        ESP_LOGI(TAG, "monitor: wait for clearing DNS cache");
        vTaskDelay(pdMS_TO_TICKS(10000));
        ESP_LOGI(TAG, "monitor: clearing DNS now");
        esp_netif_tcpip_exec(dns_clear, nullptr);
        ESP_LOGI(TAG, "monitor: DNS cleared");

[huming2207]

@david-cermak I've also done some more tests:

1. On ESP-IDF v5.5, no matter with or without esp_netif_tcpip_exec() to call dns_clear_cache() it will not lock up the device; no matter with or without LWIP_TCPIP_CORE_LOCKING and/or LWIP_USE_ESP_GETADDRINFO it will not lock up the device either.
2. On ESP-IDF v6.0, no matter with or without esp_netif_tcpip_exec() to call dns_clear_cache() it will lock up the device; no matter with or without LWIP_TCPIP_CORE_LOCKING and/or LWIP_USE_ESP_GETADDRINFO it will lock up the device but it takes a bit longer to lock up the device. With esp_netif_tcpip_exec() it locks up at the clearing DNS, calling dns_clear_cache() locks up the device at getaddrinfo()