Poor performance when sending infrequent messages

[mikejoshea]

Hello

I have noticed poor results when measuring round trip performance from a server running on my PC, to a client running on an ESP32 using the arduinoWebSockets library, over my local network. If I send a message at a rate of 1 per second, I measure round trip times between 10 and 400ms, typically around 250ms. If I increase the frequency of my messages to 40 or 50 per second, the round trip performance of each message improves significantly to an approximately consistent 10ms. Here is the sample ESP32 client I am using to echo back messages to the server.

#include <Arduino.h>
#include <WiFi.h>
#include <WiFiMulti.h>
#include <WiFiClientSecure.h>
#include <WebSocketsClient.h>

WiFiMulti WiFiMulti;
WebSocketsClient webSocket;

const char *ssid     = "xxxxx";
const char *password = "xxxxxxxxxx";
const char *ipAddress = "192.168.86.35";
 
unsigned long messageInterval = 5000;
bool WIFIconnected = false;
bool serverReady = false;

#define DEBUG_SERIAL Serial

void processTextPayload(char * payload){

   if (strcmp(payload,"SERVER_READY")==0){
    serverReady = true;
   } 

   if (strcmp(payload,"DATA")==0){
    webSocket.sendTXT("RECEIVED_DATA");
   } 
}


void webSocketEvent(WStype_t type, uint8_t * payload, size_t length) {
    char payloadString[100];
 
    switch(type) {
        case WStype_DISCONNECTED:
            DEBUG_SERIAL.printf("[WSc] Disconnected!\n");
            serverReady = false;
            break;
        case WStype_CONNECTED:
            DEBUG_SERIAL.printf("[WSc] Connected to url: %s\n", payload);
            break;
        case WStype_TEXT:
            sprintf(payloadString, "%s", payload);
            processTextPayload(payloadString);
            break;
        case WStype_BIN:
            DEBUG_SERIAL.printf("Binary data");
            break;
        case WStype_PING:
            // pong will be send automatically
            DEBUG_SERIAL.printf("[WSc] get ping\n");
            break;
        case WStype_PONG:
            // answer to a ping we send
            DEBUG_SERIAL.printf("[WSc] get pong\n");
            break;
    case WStype_ERROR:
          DEBUG_SERIAL.printf("[WSc] Error\n");
          break;
    case WStype_FRAGMENT_TEXT_START:
    case WStype_FRAGMENT_BIN_START:
    case WStype_FRAGMENT:   
    case WStype_FRAGMENT_FIN:
        DEBUG_SERIAL.printf("[WSc] got something else\n");
        break;
    }
}

void setup() {
    DEBUG_SERIAL.begin(115200);

    DEBUG_SERIAL.println();
    DEBUG_SERIAL.println();
    DEBUG_SERIAL.println();
 
    for(uint8_t t = 4; t > 0; t--) {
        DEBUG_SERIAL.printf("[SETUP] BOOT WAIT %d...\n", t);
        DEBUG_SERIAL.flush();
        delay(1000);
    }

   WiFiMulti.addAP(ssid, password);

   while(WiFiMulti.run() != WL_CONNECTED) {
    delay(100);
    DEBUG_SERIAL.print ( "." );
    }

   WIFIconnected = true;

   DEBUG_SERIAL.print("Local IP: "); DEBUG_SERIAL.println(WiFi.localIP());
   
   webSocket.begin(ipAddress, 8080);
   webSocket.onEvent(webSocketEvent);

   //webSocket.enableHeartbeat(10, 1000, 5);
}

unsigned long lastUpdate = millis();
 
void loop() {
  webSocket.loop();
  
  if (WIFIconnected && lastUpdate+messageInterval<millis() && !serverReady){
        DEBUG_SERIAL.println("[WSc] SENT: Device Ready Message");
        webSocket.sendTXT("DEVICE_READY");
        lastUpdate = millis();
    }
 
}

I also noticed that if I uncomment the enableHeartBeat line above, the performance improves to a consistent approximately 10ms no matter what rate I send messages from the server. It seems that if I keep throwing things at the ESP32 I get nice consistent performance, but if I slow my messages down and only send them every second or so, performance is poor for those individual messages. I expect I'm doing something dumb, but I'm not seeing it yet. Here is a python server I wrote to test this:

import asyncio
import websockets
import logging
import time
from time import sleep

logger = logging.getLogger('websockets')
logger.setLevel(logging.INFO)
logger.addHandler(logging.StreamHandler())

deviceReady = False

async def ws_handler(websocket, path):
    #while True:
        #message = await websocket.recv()
    async for message in websocket:

        if(message=="DEVICE_READY"):
            print('The device is ready!')
            await websocket.send("SERVER_READY")
            deviceReady = True

        if(message =="RECEIVED_DATA"):
            print("Elapsed time = ", int(time.perf_counter() * 1000) - startTime)
            await asyncio.sleep(1)

        if deviceReady:
            startTime = int(time.perf_counter() * 1000)
            await websocket.send("DATA")

start_server = websockets.serve(ws_handler=ws_handler, host="192.168.86.35", port=8080,close_timeout=1000)

asyncio.get_event_loop().run_until_complete(start_server)
asyncio.get_event_loop().run_forever()

To compare, I also wrote a python client. If I run the client on a separate PC from my server on the same network I get good performance regardless of messaging rate, however it too is slower for less frequent messages (about 20ms for 1Hz messages down from about 10ms for higher rates). Here is the python client:

import asyncio
import websockets

async def handler():
    uri = "ws://192.168.86.35:8080"

    async with websockets.connect(uri) as websocket:
        await websocket.send("DEVICE_READY")

        while True:
            message = await websocket.recv()
            if(message=="DATA"):
                await websocket.send("RECEIVED_DATA")

asyncio.get_event_loop().run_until_complete(handler())

I appreciate any insights, comments or criticism.

[ahmetcumhurarslan]

i am facing the same problem. it does not feel good to fill the network with ping pong messages to get lower delays. Hope to find a solution or the root of the problem.

[mikejoshea]

After posting the question above I looked closer at the WebSocket library logs and noticed interesting behavior. I would see the client read the message from the server and then send a message in response. Then I would see a “handleWebsocketWaitFor” call, which would take a considerable amount of time (~100ms). My theory is that the Websocket library is waiting for some kind of ACK from the interface or the server. This behaviour is reminiscent of the topics raised here:

https://github.com/Links2004/arduinoWebSockets/issues/119 https://github.com/Links2004/arduinoWebSockets/issues/52

The solution seems to be to use Async mode, however this seems to work for the ESP8266 and not for the ESP32. This Async mode uses the ESPAsyncTCP library and it looks like the authors of this made the AsyncTCP library for the ESP32. However this is not integrated with the AndroidWebSockets library as far as I know.

[lucasalberto01]

+1