From 2dfed2fea15bdfca48dc7fe6a87ee7b3e5692032 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Wed, 10 Apr 2019 21:16:26 -0400 Subject: [PATCH 01/12] add opportunity for more than one retry to _uploadReadByte --- libraries/WebServer/src/Parsing.cpp | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index e55e6873c8f..ad49a68061d 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -304,10 +304,27 @@ void WebServer::_uploadWriteByte(uint8_t b){ int WebServer::_uploadReadByte(WiFiClient& client){ int res = client.read(); - if(res == -1){ - while(!client.available() && client.connected()) + const uint8_t max_retries = 3; + uint8_t numRetries = 0; + while(numRetries < max_retries && res == -1){ + while(!client.available() && client.connected()){ delay(2); + } + res = client.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 ellusive, and possibly indicative of a more subtle underlying + // issue + + numRetries++; } return res; } From 87aa4045cfa44b6055a0493c01207096e6aae61e Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Wed, 10 Apr 2019 21:48:36 -0400 Subject: [PATCH 02/12] an alternative timeout-based method to making _uploadReadByte more resilient --- libraries/WebServer/src/Parsing.cpp | 52 +++++++++++++++++------------ 1 file changed, 31 insertions(+), 21 deletions(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index ad49a68061d..08d439982d3 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -304,29 +304,39 @@ void WebServer::_uploadWriteByte(uint8_t b){ int WebServer::_uploadReadByte(WiFiClient& client){ int res = client.read(); - const uint8_t max_retries = 3; - uint8_t numRetries = 0; - while(numRetries < max_retries && res == -1){ - while(!client.available() && client.connected()){ - delay(2); - } + if(res < 0) { + // keep trying until you either read a valid byte or timeout + for(;;) { + // loosely modeled after blinkWithoutDelay pattern + const unsigned long startMillis = millis(); + const long timeoutIntervalMillis = HTTP_MAX_POST_WAIT; + unsigned long currentMillis = startMillis; + while(!client.available() && client.connected()){ + delay(2); + } - res = client.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 ellusive, and possibly indicative of a more subtle underlying - // issue - - numRetries++; + 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 ellusive, and possibly indicative of a more subtle underlying + // issue + + currentMillis = millis(); + if(currentMillis - startMillis >= timeoutIntervalMillis) { + return -1; // exit on a timeout + } + } } - return res; } bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){ From 1670366c2a9a87a1c6af2f99fae5cd7610f36c1f Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 08:49:51 -0400 Subject: [PATCH 03/12] move timing variables in the correct scope --- libraries/WebServer/src/Parsing.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index 08d439982d3..48b4206cc96 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -306,11 +306,11 @@ int WebServer::_uploadReadByte(WiFiClient& client){ int res = client.read(); if(res < 0) { // keep trying until you either read a valid byte or timeout + const unsigned long startMillis = millis(); + const long timeoutIntervalMillis = HTTP_MAX_POST_WAIT; + unsigned long currentMillis = startMillis; for(;;) { // loosely modeled after blinkWithoutDelay pattern - const unsigned long startMillis = millis(); - const long timeoutIntervalMillis = HTTP_MAX_POST_WAIT; - unsigned long currentMillis = startMillis; while(!client.available() && client.connected()){ delay(2); } From f8b9ab3fbd454d48ea237823b48cad73f69db9f1 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 09:46:22 -0400 Subject: [PATCH 04/12] implement and use client.getTimeout instead of hard-coded timeout in _uploadReadByte --- cores/esp32/Stream.h | 5 ++++- libraries/WebServer/src/Parsing.cpp | 2 +- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/cores/esp32/Stream.h b/cores/esp32/Stream.h index e5f4f6cc4c7..a80ad11e306 100644 --- a/cores/esp32/Stream.h +++ b/cores/esp32/Stream.h @@ -59,7 +59,10 @@ 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) + { + return _timeout; + } bool find(const char *target); // reads data from the stream until the target string is found bool find(uint8_t *target) { diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index 48b4206cc96..5d8a8c3ef06 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -307,7 +307,7 @@ int WebServer::_uploadReadByte(WiFiClient& client){ if(res < 0) { // keep trying until you either read a valid byte or timeout const unsigned long startMillis = millis(); - const long timeoutIntervalMillis = HTTP_MAX_POST_WAIT; + const long timeoutIntervalMillis = client.getTimeout(); unsigned long currentMillis = startMillis; for(;;) { // loosely modeled after blinkWithoutDelay pattern From 60009091e9acfb9a7779dcb97ae977d0c1033448 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 10:48:13 -0400 Subject: [PATCH 05/12] add missing return --- libraries/WebServer/src/Parsing.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index 5d8a8c3ef06..57ec9478510 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -337,6 +337,8 @@ int WebServer::_uploadReadByte(WiFiClient& client){ } } } + + return res; } bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){ From 50594ca84b058f4b7473ce65e859c09ac4d57f28 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 11:29:05 -0400 Subject: [PATCH 06/12] some refactoring to address respecting the timeout in a potentially deadlocked connection --- libraries/WebServer/src/Parsing.cpp | 14 ++++++++------ libraries/WiFi/src/WiFiClient.cpp | 14 +++++++------- 2 files changed, 15 insertions(+), 13 deletions(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index 57ec9478510..d4c6070bc22 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -306,13 +306,16 @@ int WebServer::_uploadReadByte(WiFiClient& client){ int res = client.read(); if(res < 0) { // keep trying until you either read a valid byte or timeout - const unsigned long startMillis = millis(); - const long timeoutIntervalMillis = client.getTimeout(); + unsigned long startMillis = millis(); + long timeoutIntervalMillis = client.getTimeout(); unsigned long currentMillis = startMillis; + boolean timedOut = false; for(;;) { // loosely modeled after blinkWithoutDelay pattern - while(!client.available() && client.connected()){ + while(!timedOut && !client.available() && client.connected()){ delay(2); + currentMillis = millis(); + timedOut = currentMillis - startMillis >= timeoutIntervalMillis; } res = client.read(); @@ -331,9 +334,8 @@ int WebServer::_uploadReadByte(WiFiClient& client){ // is ellusive, and possibly indicative of a more subtle underlying // issue - currentMillis = millis(); - if(currentMillis - startMillis >= timeoutIntervalMillis) { - return -1; // exit on a timeout + if(timedOut) { + return res; // exit on a timeout } } } diff --git a/libraries/WiFi/src/WiFiClient.cpp b/libraries/WiFi/src/WiFiClient.cpp index 77aa9ae5371..b2b5bdab0cf 100644 --- a/libraries/WiFi/src/WiFiClient.cpp +++ b/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("setOption fail on fd %d, errno: %d", fd(), 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("getOption fail on fd %d, errno: %d", fd(), 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("write fail on fd %d, errno: %d", fd(), 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("read fail on fd %d, errno: %d", fd(), errno); stop(); } return res; @@ -416,7 +416,7 @@ int WiFiClient::peek() { int res = _rxBuffer->peek(); if(_rxBuffer->failed()) { - log_e("%d", errno); + log_e("peek fail on fd %d, errno: %d", fd(), errno); stop(); } return res; @@ -430,7 +430,7 @@ int WiFiClient::available() } int res = _rxBuffer->available(); if(_rxBuffer->failed()) { - log_e("%d", errno); + log_e("available fail on fd %d, errno: %d", fd(), 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("flush fail on fd %d, errno: %d", fd(), errno); stop(); break; } From eadb93aee2e5eb7c038d3b40c1f31ddb2b72c6f4 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 11:39:05 -0400 Subject: [PATCH 07/12] fix spelling in comment --- libraries/WebServer/src/Parsing.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index d4c6070bc22..e99098a95a5 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -331,7 +331,7 @@ int WebServer::_uploadReadByte(WiFiClient& client){ // // a simple retry strategy overcomes this which is to say the // assertion is not permanent, but the reason that this works - // is ellusive, and possibly indicative of a more subtle underlying + // is elusive, and possibly indicative of a more subtle underlying // issue if(timedOut) { From d5c501f7687be64e5995189eb0be44c1fb53c7d8 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 14:36:24 -0400 Subject: [PATCH 08/12] address review comments; move impl to cpp file for getTimeout, and remove local variable for currentMillis --- cores/esp32/Stream.cpp | 3 +++ cores/esp32/Stream.h | 5 +---- libraries/WebServer/src/Parsing.cpp | 4 +--- 3 files changed, 5 insertions(+), 7 deletions(-) diff --git a/cores/esp32/Stream.cpp b/cores/esp32/Stream.cpp index 59b0bafeb55..5c090791968 100644 --- a/cores/esp32/Stream.cpp +++ b/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) diff --git a/cores/esp32/Stream.h b/cores/esp32/Stream.h index a80ad11e306..45e6e477363 100644 --- a/cores/esp32/Stream.h +++ b/cores/esp32/Stream.h @@ -59,10 +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) - { - return _timeout; - } + 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) { diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index e99098a95a5..b80e1fbe2ec 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -308,14 +308,12 @@ int WebServer::_uploadReadByte(WiFiClient& client){ // keep trying until you either read a valid byte or timeout unsigned long startMillis = millis(); long timeoutIntervalMillis = client.getTimeout(); - unsigned long currentMillis = startMillis; boolean timedOut = false; for(;;) { // loosely modeled after blinkWithoutDelay pattern while(!timedOut && !client.available() && client.connected()){ delay(2); - currentMillis = millis(); - timedOut = currentMillis - startMillis >= timeoutIntervalMillis; + timedOut = ((unsigned long) millis()) - startMillis >= timeoutIntervalMillis; } res = client.read(); From 207674564aea23d3522870e23f12b356648839e0 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 14:49:12 -0400 Subject: [PATCH 09/12] remove redundant cast --- libraries/WebServer/src/Parsing.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index b80e1fbe2ec..09d6f850771 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -313,7 +313,7 @@ int WebServer::_uploadReadByte(WiFiClient& client){ // loosely modeled after blinkWithoutDelay pattern while(!timedOut && !client.available() && client.connected()){ delay(2); - timedOut = ((unsigned long) millis()) - startMillis >= timeoutIntervalMillis; + timedOut = millis() - startMillis >= timeoutIntervalMillis; } res = client.read(); From e43f16135f30e1d457269944f022770dbc7743d1 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 17:32:48 -0400 Subject: [PATCH 10/12] need to check for timeout outside the inner while as well --- libraries/WebServer/src/Parsing.cpp | 1 + 1 file changed, 1 insertion(+) diff --git a/libraries/WebServer/src/Parsing.cpp b/libraries/WebServer/src/Parsing.cpp index 09d6f850771..303c99ad908 100644 --- a/libraries/WebServer/src/Parsing.cpp +++ b/libraries/WebServer/src/Parsing.cpp @@ -332,6 +332,7 @@ int WebServer::_uploadReadByte(WiFiClient& client){ // is elusive, and possibly indicative of a more subtle underlying // issue + timedOut = millis() - startMillis >= timeoutIntervalMillis; if(timedOut) { return res; // exit on a timeout } From 390f19b6cc184f72fb55cde097aacc18aec5120d Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 21:06:22 -0400 Subject: [PATCH 11/12] update WebUpdate example to print something in unexpected callback condition --- libraries/WebServer/examples/WebUpdate/WebUpdate.ino | 2 ++ 1 file changed, 2 insertions(+) diff --git a/libraries/WebServer/examples/WebUpdate/WebUpdate.ino b/libraries/WebServer/examples/WebUpdate/WebUpdate.ino index fc4554ab34d..843867d5f3b 100644 --- a/libraries/WebServer/examples/WebUpdate/WebUpdate.ino +++ b/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(); From 3e7dd27e0e937203b963c1af3c8eba3f6b267650 Mon Sep 17 00:00:00 2001 From: Victor Aprea Date: Thu, 11 Apr 2019 21:25:23 -0400 Subject: [PATCH 12/12] update log_e messages per review comments --- libraries/WiFi/src/WiFiClient.cpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/libraries/WiFi/src/WiFiClient.cpp b/libraries/WiFi/src/WiFiClient.cpp index b2b5bdab0cf..19b44570682 100644 --- a/libraries/WiFi/src/WiFiClient.cpp +++ b/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("setOption fail on fd %d, errno: %d", fd(), 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("getOption fail on fd %d, errno: %d", fd(), 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("write fail on fd %d, errno: %d", fd(), 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("read fail on fd %d, errno: %d", fd(), 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("peek fail on fd %d, errno: %d", fd(), 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("available fail on fd %d, errno: %d", fd(), 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("flush fail on fd %d, errno: %d", fd(), errno); + log_e("fail on fd %d, errno: %d, \"%s\"", fd(), errno, esp_err_to_name(errno)); stop(); break; }