websocket-client message receive rate seemingly limited to 1 message per second.

[mangodan]

I came across the problem with my own application and server but can reproduce the same situation by making minor changes to the example provided in the esp-idf SDK found at examples/protocols/websocket using the default ws://echo.websocket.org service.

change

Code: Select all

    while (i < 10) {
        if (esp_websocket_client_is_connected(client)) {
            int len = sprintf(data, "hello %04d", i++);
            ESP_LOGI(TAG, "Sending %s", data);
            esp_websocket_client_send(client, data, len, portMAX_DELAY);
        }
        vTaskDelay(1000 / portTICK_RATE_MS);
    }

to

Code: Select all

    while (i < 10) {
        if (esp_websocket_client_is_connected(client)) {
            int len = sprintf(data, "hello %04d", i++);
            ESP_LOGI(TAG, "Sending %s", data);
            esp_websocket_client_send(client, data, len, portMAX_DELAY);
        }
        vTaskDelay(100 / portTICK_RATE_MS);
    }
    vTaskDelay(10000 / portTICK_RATE_MS);

And you should see quite clearly what i mean, the result looks like:

Code: Select all

I (8445) WEBSOCKET: Connectiong to ws://echo.websocket.org...
I (8795) WEBSOCKET: WEBSOCKET_EVENT_CONNECTED
I (8855) WEBSOCKET: Sending hello 0000
I (8955) WEBSOCKET: Sending hello 0001
I (9055) WEBSOCKET: Sending hello 0002
I (9155) WEBSOCKET: Sending hello 0003
I (9255) WEBSOCKET: Sending hello 0004
I (9355) WEBSOCKET: Sending hello 0005
I (9455) WEBSOCKET: Sending hello 0006
I (9555) WEBSOCKET: Sending hello 0007
I (9655) WEBSOCKET: Sending hello 0008
I (9755) WEBSOCKET: Sending hello 0009
I (9815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (9815) WEBSOCKET: Received=hello 0000

I (10815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (10815) WEBSOCKET: Received=hello 0001

I (11815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (11815) WEBSOCKET: Received=hello 0002

I (12815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (12815) WEBSOCKET: Received=hello 0003

I (13815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (13815) WEBSOCKET: Received=hello 0004

I (14815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (14815) WEBSOCKET: Received=hello 0005

I (15815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (15815) WEBSOCKET: Received=hello 0006

I (16815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (16815) WEBSOCKET: Received=hello 0007

I (17815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (17815) WEBSOCKET: Received=hello 0008

I (18815) WEBSOCKET: WEBSOCKET_EVENT_DATA
W (18815) WEBSOCKET: Received=hello 0009

I (20815) WEBSOCKET: Websocket Stopped

I am not yet familiar enough with the SDK to know whether this is some configuration option I have not found or a bug within somethingin the SDK. Does anybody have any suggestions?

[jcsbanks]

It looks like the vTaskDelays are explaining it? I did not know there were now idf examples but was able to send about 700 websockets per second from Thomas Barth's code without Nagle enabled and silly numbers with it.

[mangodan]

The vTaskDelay should only be suspending the current thread and spacing out the sending, the reply events come from other threads handling the TCP stack etc.

The vanilla example sends a message once a second so the problem I am seeing is hidden. It's when one tries to send messages more frequently that the problem arises. Hence my small change noted above. The final vTaskDelay of 10 seconds was done to allow the replies to all come in before stopping the example. The sending works fine. I can see the messages arrive at the server at the desired rate. The server replies in a timely manor (or at least I know my own local one does) but the messages are being held up somewhere in the esp32. You can see this from the log output above. The numbers near the start of each line are the time stamps in mS.

[mangodan]

I found the cause of this and posted a bug report :

https://github.com/espressif/esp-idf/issues/3957