Alternative Improve _uploadReadByte (#2656)

* add opportunity for more than one retry to _uploadReadByte

* an alternative timeout-based method to making _uploadReadByte more resilient

* move timing variables in the correct scope

* implement and use client.getTimeout instead of hard-coded timeout in _uploadReadByte

* add missing return

* some refactoring to address respecting the timeout in a potentially deadlocked connection

* fix spelling in comment

* address review comments; move impl to cpp file for getTimeout, and remove local variable for currentMillis

* remove redundant cast

* need to check for timeout outside the inner while as well

* update WebUpdate example to print something in unexpected callback condition

* update log_e messages per review comments

Author: vicatcu

cores/esp32/Stream.cpp

@@ -82,6 +82,9 @@ void Stream::setTimeout(unsigned long timeout)  // sets the maximum number of mi
 {
     _timeout = timeout;
 }
+unsigned long Stream::getTimeout(void) {
+  return _timeout;
+}
 
 // find returns true if the target string is found
 bool Stream::find(const char *target)

cores/esp32/Stream.h

@@ -59,7 +59,7 @@ class Stream: public Print
 // parsing methods
 
     void setTimeout(unsigned long timeout);  // sets maximum milliseconds to wait for stream data, default is 1 second
-
+    unsigned long getTimeout(void);
     bool find(const char *target);   // reads data from the stream until the target string is found
     bool find(uint8_t *target)
     {

libraries/WebServer/examples/WebUpdate/WebUpdate.ino

@@ -50,6 +50,8 @@ void setup(void) {
           Update.printError(Serial);
         }
         Serial.setDebugOutput(false);
+      } else {
+        Serial.printf("Update Failed Unexpectedly (likely broken connection): status=%d\n", upload.status);
       }
     });
     server.begin();

libraries/WebServer/src/Parsing.cpp

@@ -304,11 +304,41 @@ void WebServer::_uploadWriteByte(uint8_t b){
 
 int WebServer::_uploadReadByte(WiFiClient& client){
   int res = client.read();
-  if(res == -1){
-    while(!client.available() && client.connected())
-      delay(2);
-    res = client.read();
+  if(res < 0) {
+    // keep trying until you either read a valid byte or timeout
+    unsigned long startMillis = millis();
+    long timeoutIntervalMillis = client.getTimeout();
+    boolean timedOut = false;
+    for(;;) {
+      // loosely modeled after blinkWithoutDelay pattern
+      while(!timedOut && !client.available() && client.connected()){
+        delay(2);
+        timedOut = millis() - startMillis >= timeoutIntervalMillis;
+      }
+
+      res = client.read();
+      if(res >= 0) {
+        return res; // exit on a valid read
+      }
+      // NOTE: it is possible to get here and have all of the following
+      //       assertions hold true
+      //
+      //       -- client.available() > 0
+      //       -- client.connected == true
+      //       -- res == -1
+      //
+      //       a simple retry strategy overcomes this which is to say the
+      //       assertion is not permanent, but the reason that this works
+      //       is elusive, and possibly indicative of a more subtle underlying
+      //       issue
+
+      timedOut = millis() - startMillis >= timeoutIntervalMillis;
+      if(timedOut) {
+        return res; // exit on a timeout
+      }
+    }
   }
+
   return res;
 }
 

libraries/WiFi/src/WiFiClient.cpp

@@ -279,7 +279,7 @@ int WiFiClient::setOption(int option, int *value)
 {
     int res = setsockopt(fd(), IPPROTO_TCP, option, (char *) value, sizeof(int));
     if(res < 0) {
-        log_e("%d", errno);
+        log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
     }
     return res;
 }
@@ -289,7 +289,7 @@ int WiFiClient::getOption(int option, int *value)
     size_t size = sizeof(int);
     int res = getsockopt(fd(), IPPROTO_TCP, option, (char *)value, &size);
     if(res < 0) {
-        log_e("%d", errno);
+        log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
     }
     return res;
 }
@@ -362,7 +362,7 @@ size_t WiFiClient::write(const uint8_t *buf, size_t size)
                 }
             }
             else if(res < 0) {
-                log_e("%d", errno);
+                log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
                 if(errno != EAGAIN) {
                     //if resource was busy, can try again, otherwise give up
                     stop();
@@ -406,7 +406,7 @@ int WiFiClient::read(uint8_t *buf, size_t size)
     int res = -1;
     res = _rxBuffer->read(buf, size);
     if(_rxBuffer->failed()) {
-        log_e("%d", errno);
+        log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
         stop();
     }
     return res;
@@ -416,7 +416,7 @@ int WiFiClient::peek()
 {
     int res = _rxBuffer->peek();
     if(_rxBuffer->failed()) {
-        log_e("%d", errno);
+        log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
         stop();
     }
     return res;
@@ -430,7 +430,7 @@ int WiFiClient::available()
     }
     int res = _rxBuffer->available();
     if(_rxBuffer->failed()) {
-        log_e("%d", errno);
+        log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
         stop();
     }
     return res;
@@ -452,7 +452,7 @@ void WiFiClient::flush() {
         toRead = (a>WIFI_CLIENT_FLUSH_BUFFER_SIZE)?WIFI_CLIENT_FLUSH_BUFFER_SIZE:a;
         res = recv(fd(), buf, toRead, MSG_DONTWAIT);
         if(res < 0) {
-            log_e("%d", errno);
+            log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno));
             stop();
             break;
         }