ESP32 webSocket.loop() doesn't return

[renegadeandy]

Hi all, I have a situation where I try to connect to a server, and call webSocket.loop() which the first time round returns, however on the second loop call, it doesn't make it through the function.

I have not dived too far into the code because I am sure support here will guide this debugging process.

The code is using version 2.7.1 and is as follows:

WebSocketsClient webSocket;
webSocket.begin("136.243.4.163", 28082);
 webSocket.onEvent(webSocketEvent);
 webSocket.setReconnectInterval(1000);

In my main loop I have:

webSocket.loop();

Sometimes the above code works nicely and I get a connected event arriving into my webSocketEvent handler:

void webSocketEvent(WStype_t type, uint8_t *payload, size_t length)
{

  switch (type)
  {
  case WStype_DISCONNECTED:
    Serial.printf("[WSc] Disconnected!\n");
    break;
  case WStype_CONNECTED:
    Serial.printf("[WSc] Connected to url: %s\n", payload);
    webSocket.sendTXT("Connected");
    break;
  case WStype_TEXT:
    Serial.printf("[WSc] get text: %s\n", payload);
    break;
  case WStype_BIN:
    Serial.printf("[WSc] Received response binary length: %u\n", length);
    decode_response(payload, length);
    break;
  case WStype_ERROR:
  case WStype_FRAGMENT_TEXT_START:
  case WStype_FRAGMENT_BIN_START:
  case WStype_FRAGMENT:
  case WStype_FRAGMENT_FIN:
    break;
  }
}

However in the case I am currently experiencing, the begin call is made, the code flows into the main loop of the ESP32, I make one call to the webSocket.loop() - which runs top to bottom, then a second called to webSocket.loop() occurs, and I can see the call arriving into the top of webSocket.loop() but it never reaches the bottom of the code (I use Serial.printf to debug).

Can anyone help me here? Why would webSocket.loop() be hanging - and is this expected behaviour given certain conditions? Perhaps there are some other best practices I am not using on my connection attempt.

Many thanks for help and support!

[Links2004]

first step is to enable debugging to see whats happening ;)

you need to set the DEBUG_ESP_PORT define global via compiler comandline
e.g.:

build_flags =
  -D DEBUG_ESP_PORT=Serial

Alternative you need to edit the file here:
https://github.com/Links2004/arduinoWebSockets/blob/master/src/WebSockets.h#L46

[renegadeandy]

Okay thanks @Links2004 Added it and now I get:

[WS-Client] connect ws...
[WS-Client] connected to 136.243.4.163:28082.
[WS-Client][sendHeader] sending header...
[WS-Client][sendHeader] handshake GET / HTTP/1.1
Host: 136.243.4.163:28082
Connection: Upgrade
Upgrade: websocket
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: U3/UGFOUHmX8k4RQmeGOWA==
Sec-WebSocket-Protocol: arduino
Origin: file://
User-Agent: arduino-WebSocket-Client

[write] n: 246 t: 5094
[WS-Client][sendHeader] sending header... Done (30456us).

Then the main program loop hangs.

[Links2004]

this looks good,
the "sending header... Done" shows us that we are at the end on the loop.

arduinoWebSockets/src/WebSocketsClient.cpp

Line 335 in 8d0744e

connectedCb();

arduinoWebSockets/src/WebSocketsClient.cpp

Line 985 in 8d0744e

sendHeader(&_client);

arduinoWebSockets/src/WebSocketsClient.cpp

Line 766 in 8d0744e

DEBUG_WEBSOCKETS("[WS-Client][sendHeader] sending header... Done (%luus).\n", (micros() - start));

not sure whats happening in your code, but you will need to add more debug output to find the place where it gets stuck.
with out seeing the full code its hard to guess whats wrong.

[renegadeandy]

I have done a bit more investigation -- see the following output:

b7
b1
[WS-Client] connect ws...
[WS-Client] connected to 176.9.112.88:28028.
[WS-Client][sendHeader] sending header...
[WS-Client][sendHeader] handshake GET / HTTP/1.1
Host: 176.9.112.88:28028
Connection: Upgrade
Upgrade: websocket
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: SStv7l9zh6gSGcBFf9ERGQ==
Sec-WebSocket-Protocol: arduino
Origin: file://
User-Agent: arduino-WebSocket-Client

[write] n: 245 t: 5102
[WS-Client][sendHeader] sending header... Done (30227us).
b2
b3
b4
b5
b6
b7
b1

My loop function is this:

void loop()
{
    Serial.println("b1");
  webSocket.loop();
    Serial.println("b2");
  int i=0;
    Serial.println("b3");
  gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
    Serial.println("b4");
  gslc_Update(&m_gui);

    Serial.println("b5");
  //debug_heaps();
 
  Serial.println("b6");
  i=5;
  gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
  gslc_Update(&m_gui);
  i=10;
  //  delay(3000);
  unsigned long new_delta = millis();
  unsigned long delta_socket_loop = new_delta - run_time_socket_loop;
  unsigned long delta_online_players_loop = new_delta - online_players_loop;
  gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
  gslc_Update(&m_gui);
  //run the websocket updates every 3 seconds
  if (webSocket.isConnected() && delta_socket_loop >= 3000)
  {
    Serial.println("Connected sending request for getTime");
    send_get_time_request();
    i=20;
    gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
   gslc_Update(&m_gui);
    Serial.println("Connected sending request for getInfo");
    
    send_get_info_request();
   gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
    gslc_Update(&m_gui);
    i=30;
    Serial.println("Connected sending request for getTeam");
    send_get_team_request();
    gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
    gslc_Update(&m_gui);
    i=40;
    run_time_socket_loop = millis();
  }
   if(delta_online_players_loop >= 300000){
          online_players_loop = millis();
  }
  display_up_time();
  updateTime();
  i=100;
  gslc_ElemXRingGaugeSetVal(&m_gui,progress_indicator_ui,i);
  gslc_Update(&m_gui);
  Serial.println("b7");
}

By looking at this - you will see we stop after b1 and before b2 - which is in the webSocket.loop() call. The stop after b1 is infinite - it never ever returns to the main loop function.

This failure is 100% repeatable and happens consistently. I would also like to check something, should you check isConnected() before calling loop?

@Links2004 hope you can offer some advice?

[renegadeandy]

Done more debugging and it is hanging forever at this line in handleClientData:

String headerLine = _client.tcp->readStringUntil('\n');

I can tell from the len integer, that there are 4 bytes to be read but clearly it doesn't end with a newline character and therefore never returns from this call.

[Links2004]

good that you did find the line,
readStringUntil normaly has a timeout which is configured here:

arduinoWebSockets/src/WebSocketsClient.cpp

Line 959 in a7a7904

_client.tcp->setTimeout(WEBSOCKETS_TCP_TIMEOUT);

which exact ESP32 and arduino core are you using?

the ESP32 core implements it here:

https://github.com/espressif/arduino-esp32/blob/11bc7ac1a458f1f4e7afc8fd4de1dfa710f31562/cores/esp32/Stream.cpp#L239-L247

https://github.com/espressif/arduino-esp32/blob/11bc7ac1a458f1f4e7afc8fd4de1dfa710f31562/cores/esp32/Stream.cpp#L31-L41

the other questsion is why does your websocket server not answer with a HTTP answer to the requests?
may http (ws) vs https (wss) ?

[renegadeandy]

Are you asking which piece of hardware am I using or libraries?

When I look at that line in my WebSocketsClient.cpp, the WEBSOCKETS_TCP_TIMEOUT is 5000, and the setTimeout function suggests its value is in seconds, so 5000 seconds suggests this timeout will take 83 minutes to actually trigger!?

In terms of why is it not answering, well I would say it is sending something? 4 bytes, not sure what they are but I need to look into the bytes to figure out what is going on here.

[Links2004]

setTimeout takes milliseconds so the expected timeout on no data is 5sec.

https://github.com/espressif/arduino-esp32/blob/11bc7ac1a458f1f4e7afc8fd4de1dfa710f31562/cores/esp32/Stream.cpp#L86-L89

I am asking for the ESP32 variant e.g. ESP32-S3 , ESP32-C3 etc.
and the arduino esp32 core version (https://github.com/espressif/arduino-esp32/releases).

2 ideas for debugging:

• hardcoding a 4 byte read in the code
• tcpdump / wireshark on the servers side (if the server is under your control)

[renegadeandy]

I may be wrong @Links2004 but:

int WiFiClient::setTimeout(uint32_t seconds)
{
    Client::setTimeout(seconds * 1000); // This should be here?
    _timeout = seconds * 1000;
    if(fd() >= 0) {
        struct timeval tv;
        tv.tv_sec = seconds;
        tv.tv_usec = 0;
        if(setSocketOption(SO_RCVTIMEO, (char *)&tv, sizeof(struct timeval)) < 0) {
            return -1;
        }
        return setSocketOption(SO_SNDTIMEO, (char *)&tv, sizeof(struct timeval));
    }
    else {
        return 0;
    }
}

Says to me this function expects to be passed a value in seconds, which it transforms to milliseconds.

However my function call is:
_client.tcp->setTimeout(WEBSOCKETS_TCP_TIMEOUT);
where WEBSOCKETS_TCP_TIMEOUT is 5000, so it is then doing 5000*1000 to get 5000000000 seconds..hence the wait feels infinite.

changing the line to be:

_client.tcp->setTimeout(5);

makes the timeout behave as an appropriate 5 second timeout.

I think the WEBSOCKETS_TCP_TIMEOUT is set incorrectly to 5000, not sure where that lies. That the setTimeout function should be:

Client::setTimeout(seconds); // This should be here?
_timeout = seconds;

I
l'll leave your response to figure the best path. Having changed the timeout to 5, it gives control back to the main esp32 loop code, which is great.

Each time I am receiving the 4 bytes back from the server(which I have no control over). I read the 4 bytes receied back this way:

   u_int8_t byte1 = 0;
                  u_int8_t byte2 = 0;
                   u_int8_t byte3 = 0;
                    u_int8_t byte4 = 0;
                 _client.tcp->read(&byte1,1);
                  _client.tcp->read(&byte2,1);
                   _client.tcp->read(&byte3,1);
                    _client.tcp->read(&byte4,1);
               // _client.tcp->readBytes(&buf[0], std::min((size_t)len, sizeof(buf)));
                Serial.println("bytes are:");
                Serial.println(byte1);
                Serial.println(byte2);
                Serial.println(byte3);
                Serial.println(byte4);

and the output is consistently the following:

136
2
3
232

... not sure what to make of that!

I am using espressif 32 6.10.0 on a ESP32-WROOM-32.

I

[Links2004]

arduino is spezifinging the API of setTimeout as millis saconds:

https://docs.arduino.cc/language-reference/en/functions/communication/stream/streamSetTimeout/

and WiFiClient has been super seeded by NetworkClient for ESP32:
https://github.com/espressif/arduino-esp32/blob/master/libraries/WiFi/src/WiFiClient.h

from where does the setTimeout code you posted come, a git link may help me to understand it better.

does the 6.10.0 refere to the platformio version
https://github.com/platformio/platform-espressif32/releases/tag/v6.10.0
?

[Links2004]

did some digging and found:
espressif/arduino-esp32#6835
and
espressif/arduino-esp32#6676

all ESP32 arduino core < 3.0.0 will have this problem.

I pushed a change to master, feel free to test if the timeout works now.

the first to bytes (0x88, 0x02) look like the close of a websocket connection, but this makes no sense since we not have a connection yet, the first step is to establish a HTTP connection an then upgrade to websockets.
I recommand to look at the server logs if possible, or test with a diffrent websocket server.

[renegadeandy]

Was about to post the same links.

Perhaps I should upgrade to the newer version and use NetworkClient - would you suggest I do that? I will need to look into how to do it, suppose its just upping the version within platformio.

Maybe the close is happening because the server doesn't want to talk to my network (I may be hitting it too often and am being rate limited...not sure) but that is a response to the connection attempt so...

[Links2004]

hint for using newer core versions:

https://github.com/pioarduino/platform-espressif32

[renegadeandy]

arduino is spezifinging the API of setTimeout as millis saconds:

https://docs.arduino.cc/language-reference/en/functions/communication/stream/streamSetTimeout/

and WiFiClient has been super seeded by NetworkClient for ESP32: https://github.com/espressif/arduino-esp32/blob/master/libraries/WiFi/src/WiFiClient.h

from where does the setTimeout code you posted come, a git link may help me to understand it better.

does the 6.10.0 refere to the platformio version https://github.com/platformio/platform-espressif32/releases/tag/v6.10.0 ?

Regarding the WifiClient being replaced with NetworkStack -- I am using WiFi.h from espressif, and all tutorials I see continue to use:

 WiFi.mode(WIFI_STA);
  WiFi.begin(ssid, password);
  Serial.print("Connecting to WiFi ..");
  while (WiFi.status() != WL_CONNECTED)
  {
    Serial.print('.');
    delay(1000);
  }
  Serial.println("Connected");
  Serial.println(WiFi.localIP());

So I think although you are right - the change at the user programming level isn't required? Do you agree?