JAndrassy / WiFiEspAT

Arduino networking library. Standard Arduino WiFi networking API over ESP8266 or ESP32 AT commands.
GNU Lesser General Public License v2.1
288 stars 44 forks source link

Timeout when parsing UDP packet in a one-shot fashion #17

Closed asteinh closed 4 years ago

asteinh commented 4 years ago

For an application that runs at a predefined sampling rate, I encountered the following problem: In most cases, when I try to parse a UDP packet, I run into timeout errors, even though the debug output shows all the right sizes. The expected package length is 64 bytes (which is confirmed by wireshark) and the library tries to read 64 bytes, but something seems to go wrong. Even more confusing is the fact that in rare cases everything seems to work, see the debug output below. This seems to depend on the rate at which the packages are coming in...

To reproduce, an Arduino sketch as a minimal working example:

#include <WiFiEspAT.h>

#define NETWORK_SSID "mynetwork"
#define NETWORK_PASS "mypassword"
#define IP IPAddress(192, 168, 0, 200)
#define PORT 10002
#define ESP8266_SERIAL Serial1
#define ESP8266_BAUD 115200

char buffer[255];
WiFiUDP udp;
unsigned long starttime;

void setup() {
  Serial.begin(115200);
  ESP8266_SERIAL.begin(ESP8266_BAUD);

  WiFi.init(&ESP8266_SERIAL);

  if (WiFi.status() == WL_NO_MODULE) {
    Serial.println("WiFi shield not present");
    while (true);
  }

  WiFi.config(IP);

  while (WiFi.status() != WL_CONNECTED)
    WiFi.begin(NETWORK_SSID, NETWORK_PASS);

  udp.begin(PORT);
}

void loop() {
  starttime = millis();

  int packetSize = udp.parsePacket();
  if (packetSize) {
    // read the packet into packetBufffer
    int len = udp.read(buffer, 255);

    Serial.print("Read ");
    Serial.print(len);
    Serial.print(" bytes in ");
    Serial.print(millis() - starttime);
    Serial.println(" milliseconds.");
  }

  delay(100);
}

Without the delay(100); line everything seems to work as expected. However, with this line, the debug output reads

...

08:56:13.953 -> esp> WIFI CONNECTED ...ignored
08:56:13.953 -> esp> WIFI GOT IP ...ignored
08:56:14.898 -> esp> OK ...matched
08:56:14.898 -> esp INFO: wifi status
08:56:14.898 -> esp> AT+CIPSTATUS ...sent
08:56:14.898 -> esp> STATUS:2 ...matched
08:56:14.898 -> esp> OK ...matched
08:56:14.898 -> esp INFO: free linkId is 4
08:56:14.898 -> esp INFO: start UDP to 0.0.0.0:10002 on link 4
08:56:14.898 -> esp> AT+CIPSTART=4,"UDP","0.0.0.0",10002,10002,2 ...sent
08:56:14.898 -> esp> 4,CONNECT ...ignored
08:56:14.898 -> esp> OK ...matched
08:56:23.223 -> esp> +IPD,4,64:<DATA> ...error
08:56:24.233 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:26.512 -> esp> +IPD,4,64:<DATA> ...error
08:56:27.526 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:28.829 -> esp> +IPD,4,64:<DATA> ...error
08:56:29.813 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:30.615 -> esp> +IPD,4,64:<DATA> ...processed
08:56:30.649 -> Read 64 bytes in 5 milliseconds.
08:56:32.426 -> esp> +IPD,4,64:<DATA> ...error
08:56:33.433 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:34.350 -> esp> +IPD,4,64:<DATA> ...error
08:56:35.329 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:36.036 -> esp> +IPD,4,64:<DATA> ...error
08:56:37.041 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:37.562 -> esp> +IPD,4,64:<DATA> ...processed
08:56:37.562 -> Read 64 bytes in 4 milliseconds.
08:56:39.156 -> esp> +IPD,4,64:<DATA> ...error
08:56:40.148 -> esp ERROR: UDP message on link 4 size 64 error 3
08:56:40.947 -> esp> +IPD,4,64:<DATA> ...error
08:56:41.952 -> esp ERROR: UDP message on link 4 size 64 error 3

I hope someone has a little hint as to what I am missing or doing wrong here 😅

JAndrassy commented 4 years ago

it is in WiFiUDP::readRxData.

  size_t l = serial->readBytes(rxBuffer, len);
  if (l != len) // timeout
    return TIMEOUT;

readRXData is called EspATDrv to read the data after +IPD.

this problem is usually a serial buffer overflow. bytes get lost and readBytes then can't retrieve the advised count of bytes and times out. it is possible, that with a delay some packets are dropped so the buffer is cleaned up quickly for the next packet.. check WiFi.getLastDriverError() for EspAtDrvError ::UDP_BUSY after

asteinh commented 4 years ago

Thanks for the fast response! 👏

I'm not sure how to resolve this though. I checked for EspAtDrvError::UDP_BUSY, which in all cases appears false. When the error occurs it's a EspAtDrvError::UDP_TIMEOUT.

Is there a remedy for this timeout? I read about changing the Arduino's serial buffer size, but if possible, I'd prefer a solution that doesn't require such changes.

JAndrassy commented 4 years ago

the solution would be UART flow control or fimware's passive mode for UDP. possible workarounds are:

asteinh commented 4 years ago
  • send less messages

I don't see how this would change anything - it fails to receive a single message already?

  • low baud rate. 9600 baud

I successfully tried 9600 baud - but it's too slow for the application, i.e. the time required is too long.

  • smaller UDP message

That's unfortunately not an option.

  • larger serial buffer

I'll look into this, but it seems (as long as using the Arduino IDE) injecting a custom #define for HardwareSerial.h is not as easy as it should be...

JAndrassy commented 4 years ago

somehow I understood the the version with delay is the working one. the serial buffer is 64 bytes. "+IPD,4,64:" and 64 bytes of data is 74 bytes. while the code waits in delay the message is revived to serial buffer and the last 10 bytes are lost.