possible fix for #3201

CHANGELOG_LATEST.md

@@ -16,6 +16,7 @@ This release is based on the latest Espressif/Arduino core version 3. It brings
 - cleaner MD5 and firmware uploading in WebUI [#3222](https://github.com/emsesp/EMS-ESP32/issues/3222)
 - pc0Flow in l/min [#3224](https://github.com/emsesp/EMS-ESP32/issues/3224)
 - remove HA config for excluded entities [#3229](https://github.com/emsesp/EMS-ESP32/issues/3229)
+- `show system` reports the Ethernet status on boards with a PHY, so a failed initialisation or a link that never came up is visible instead of Ethernet being omitted completely. Also shows the loop task's lowest free stack, to help diagnose reboots
 
 ## Fixed
 
@@ -28,6 +29,9 @@ This release is based on the latest Espressif/Arduino core version 3. It brings
 - HA Discovery warning on Uptime after EMS-ESP boot due to NTP not ready
 - hc/control setting for UI800 thermostats [#3181](https://github.com/emsesp/EMS-ESP32/discussions/3181)
 - solar module switches [#3223](https://github.com/emsesp/EMS-ESP32/issues/3223)
+- possible crash when the WebUI asked for version information while the hourly versions.json refresh was rewriting the cache from the main loop task
+- HTTP client could write past a fixed 64 byte buffer when a URL had a hostname of 64 characters or more, could busy-spin for the whole read budget if the socket reported bytes it wouldn't return, and buffered responses without any size limit
+- the "Ethernet clock mode (GPIO16/17) conflicts with PSRAM" error was never logged because Ethernet had already been skipped by the time the check ran
 
 ## Changed
 
@@ -42,4 +46,6 @@ This release is based on the latest Espressif/Arduino core version 3. It brings
 - set `None` for undefined values in HA `val_tpl`
 - changes in WebUI - remove multiple calls systemInfo endpoint, Vewrsion pages checks for internet connection [#3195](https://github.com/emsesp/EMS-ESP32/pull/3195)
 - multiple optimization in network, power down WiFi when Ethernet and WiFi nosleep is instant when selected [#3213](https://github.com/emsesp/EMS-ESP32/pull/3213)
+- TLS buffers (~17KB per HTTPS request) are taken from PSRAM on boards that have it, instead of fragmenting the internal heap
+- failed versions.json fetches back off from 5 up to 160 minutes instead of retrying every 5 minutes, as each attempt blocks the main loop for as long as the DNS, connect and read timeouts allow
 

platformio.ini

@@ -43,6 +43,9 @@ build_flags =
   ; ESPAsyncWebServer
   ; -D WS_MAX_QUEUED_MESSAGES=0 ; not used, default 8
   ; -D SSE_MAX_QUEUED_MESSAGES=1 ; for log messages, default 32
+  ; ESP_SSLClient
+  -D ENABLE_PSRAM ; take the ~17KB of TLS buffers from PSRAM instead of the internal heap. The library
+                  ; needs BOARD_HAS_PSRAM too, so boards without PSRAM keep using the internal heap
   -D EMSESP_MQTT_RUNNING_CORE=1 ; default 1
   ; -D EMSESP_MQTT_STACKSIZE=5120 ; default
   -D EMSESP_UART_RUNNING_CORE=1 ; default any core

src/core/httpClient.cpp

@@ -35,6 +35,31 @@ int HttpClient::request(std::string url, const std::string & method, const std::
         return 0; // unsupported scheme
     }
 
+    // split the host from the path before anything is allocated, so a bad URL costs nothing
+    url.replace(0, is_https ? 8 : 7, "");
+    std::string host  = url;
+    auto        index = url.find_first_of('/');
+    if (index != std::string::npos) {
+        host = url.substr(0, index);
+        url.replace(0, index, "");
+    } else {
+        url = "/";
+    }
+
+    if (host.empty()) {
+        return 0;
+    }
+
+    // ESP_SSLClient keeps the host in a fixed char[64] and strcpy()s into it without a length
+    // check, so a longer name would corrupt whatever follows it and crash somewhere unrelated
+    if (host.length() > MAX_HOSTNAME_LENGTH) {
+        EMSESP::logger().warning("%s hostname is too long (%u characters, max is %u)",
+                                 is_https ? "HTTPS" : "HTTP",
+                                 (unsigned)host.length(),
+                                 (unsigned)MAX_HOSTNAME_LENGTH);
+        return 0;
+    }
+
     WiFiClient *    basic_client = new WiFiClient;
     ESP_SSLClient * ssl_client   = new ESP_SSLClient;
     if (is_https) {
@@ -50,16 +75,6 @@ int HttpClient::request(std::string url, const std::string & method, const std::
     ssl_client->setTimeout(5);                     // seconds, drives BearSSL only - unused on the plain HTTP path
     ssl_client->setClient(basic_client, is_https); // enableSSL = false for plain HTTP
 
-    url.replace(0, is_https ? 8 : 7, "");
-    std::string host  = url;
-    auto        index = url.find_first_of('/');
-    if (index != std::string::npos) {
-        host = url.substr(0, index);
-        url.replace(0, index, "");
-    } else {
-        url = "/";
-    }
-
     const uint16_t port = is_https ? 443 : 80;
     if (ssl_client->connect(host.c_str(), port)) {
         bool content_set = false;
@@ -97,16 +112,25 @@ int HttpClient::request(std::string url, const std::string & method, const std::
         // the stream goes idle, or the overall budget runs out
         const uint32_t started   = millis();
         uint32_t       last_data = started;
+        bool           truncated = false;
         while (millis() - started < TOTAL_TIMEOUT_MS) {
             const int avail = ssl_client->available();
             if (avail > 0) {
+                if (result.length() >= MAX_RESPONSE_BYTES) {
+                    truncated = true;
+                    break;
+                }
                 uint8_t      buf[128];
                 const size_t want = (avail < (int)sizeof(buf)) ? (size_t)avail : sizeof(buf);
                 const int    len  = ssl_client->read(buf, want);
                 if (len > 0) {
                     result.append(reinterpret_cast<const char *>(buf), len);
                     last_data = millis();
+                    continue;
                 }
+                // available() reported bytes the client won't hand over. Yielding here keeps a
+                // stale count from busy-spinning the whole read budget on this task's core
+                delay(1);
                 continue;
             }
             if (!ssl_client->connected()) {
@@ -121,6 +145,9 @@ int HttpClient::request(std::string url, const std::string & method, const std::
         ssl_client->stop();
 
         const auto received = result.length();
+        if (truncated) {
+            EMSESP::logger().warning("%s response from %s truncated at %u bytes", is_https ? "HTTPS" : "HTTP", host.c_str(), (unsigned)received);
+        }
 
         // parse the status line "HTTP/1.x <code> <reason>". stoi() would abort rather than throw on
         // a malformed response, since the firmware is built with -fno-exceptions

src/core/httpClient.h

@@ -34,6 +34,12 @@ class HttpClient {
     static constexpr uint32_t FIRST_BYTE_TIMEOUT_MS = 8000;  // how long the server may take to start replying
     static constexpr uint32_t IDLE_TIMEOUT_MS       = 500;   // gap in the stream that marks the end of a response
     static constexpr uint32_t TOTAL_TIMEOUT_MS      = 10000; // ceiling for the whole read
+
+    // ceiling on the response we'll buffer. Without it a chatty or hijacked endpoint can grow the
+    // result string until the heap runs out, which aborts the firmware since it's built -fno-exceptions
+    static constexpr size_t MAX_RESPONSE_BYTES = 32 * 1024;
+
+    static constexpr size_t MAX_HOSTNAME_LENGTH = 63; // ESP_SSLClient stores the host in a char[64]
 };
 
 } // namespace emsesp

src/core/system.cpp

@@ -1126,6 +1126,12 @@ void System::show_system(uuid::console::Shell & shell) {
     shell.printfln(" Internal heap free/largest block: %u KB / %u KB",
                    heap_caps_get_free_size(MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT) / 1024,
                    heap_caps_get_largest_free_block(MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT) / 1024);
+    // Lowest the loop task's stack has ever been since boot. EMSESP::loop() runs the blocking HTTP
+    // client and all the JSON work on this task, and a TLS handshake alone can want several KB
+    TaskHandle_t loop_task = xTaskGetHandle("loopTask");
+    if (loop_task != nullptr) {
+        shell.printfln(" Loop task stack min free/total: %u / %u bytes", (unsigned)uxTaskGetStackHighWaterMark(loop_task), (unsigned)getArduinoLoopTaskStackSize());
+    }
 #endif
     shell.printfln(" App used/free: %lu KB / %lu KB", appUsed(), appFree());
     uint32_t FSused = LittleFS.usedBytes() / 1024;

src/emsesp_version.h

@@ -1 +1 @@
-#define EMSESP_APP_VERSION "3.9.0-dev.9"
+#define EMSESP_APP_VERSION "3.9.0-dev.10"

src/web/WebStatusService.cpp

@@ -348,7 +348,18 @@ void WebStatusService::getVersions(JsonObject root) {
         }
     }
 
-    if (!versions_cache_valid_) {
+    // take a snapshot, since the loop task can be rewriting the cache while we run on AsyncTCP
+    VersionInfo stable;
+    VersionInfo dev;
+    bool        cache_valid;
+    {
+        std::lock_guard<std::mutex> lock{versions_mutex_};
+        cache_valid = versions_cache_valid_;
+        stable      = versions_stable_;
+        dev         = versions_dev_;
+    }
+
+    if (!cache_valid) {
         // no successful fetch yet (no network, fetch pending, or parse error)
         return;
     }
@@ -364,8 +375,8 @@ void WebStatusService::getVersions(JsonObject root) {
         out["upgradeable"] = info.upgradeable;
     };
 
-    add_section("stable", versions_stable_);
+    add_section("stable", stable);
-    add_section("dev", versions_dev_);
+    add_section("dev", dev);
 #else
     // standalone/test build: provide deterministic dummy data
     JsonObject stable_out     = root["stable"].to<JsonObject>();
@@ -383,7 +394,8 @@ void WebStatusService::getVersions(JsonObject root) {
 // schedule the next versions.json fetch a few seconds out so the network stack has time to settle
 // (DHCP completion, default-netif assignment and DNS server propagation through lwip)
 void WebStatusService::schedule_versions_refresh() {
-    uint32_t next = uuid::get_uptime() + VERSIONS_INITIAL_FETCH_DELAY_MS;
+    versions_failures_ = 0; // a fresh link is a fresh chance, so start again from the short retry delay
+    uint32_t next      = uuid::get_uptime() + VERSIONS_INITIAL_FETCH_DELAY_MS;
     if (next == 0) {
         next = 1; // 0 is the "idle" sentinel — never let the wrap land there
     }
@@ -409,8 +421,18 @@ void WebStatusService::loop() {
         return;
     }
 
-    bool     ok   = refresh_versions_cache();
+    uint32_t interval;
-    uint32_t next = uuid::get_uptime() + (ok ? VERSIONS_REFRESH_INTERVAL_MS : VERSIONS_RETRY_INTERVAL_MS);
+    if (refresh_versions_cache()) {
+        versions_failures_ = 0;
+        interval           = VERSIONS_REFRESH_INTERVAL_MS;
+    } else {
+        if (versions_failures_ < VERSIONS_MAX_BACKOFF_STEPS) {
+            versions_failures_++;
+        }
+        interval = VERSIONS_RETRY_INTERVAL_MS << (versions_failures_ - 1);
+    }
+
+    uint32_t next = uuid::get_uptime() + interval;
     if (next == 0) {
         next = 1;
     }
@@ -451,16 +473,21 @@ bool WebStatusService::refresh_versions_cache() {
         out.upgradeable = !out.version.empty() && FirmwareVersion(out.version) > current_version;
     };
 
-    read_section("stable", versions_stable_);
+    // parse into locals first, then publish in one go so the AsyncTCP task never sees a half-written cache
-    read_section("dev", versions_dev_);
+    VersionInfo stable;
+    VersionInfo dev;
+    read_section("stable", stable);
+    read_section("dev", dev);
+
+    {
+        std::lock_guard<std::mutex> lock{versions_mutex_};
+        versions_stable_      = stable;
+        versions_dev_         = dev;
+        versions_cache_valid_ = true;
+    }
 
-    versions_cache_valid_ = true;
 #if defined(EMSESP_DEBUG)
-    EMSESP::logger().debug("Fetched from %s: stable=%s, dev=%s, current=%s",
+    EMSESP::logger().debug("Fetched from %s: stable=%s, dev=%s, current=%s", VERSIONS_URL, stable.version.c_str(), dev.version.c_str(), current_version_s.c_str());
-                           VERSIONS_URL,
-                           versions_stable_.version.c_str(),
-                           versions_dev_.version.c_str(),
-                           current_version_s.c_str());
 #endif
     return true;
 #endif
@@ -468,11 +495,12 @@ bool WebStatusService::refresh_versions_cache() {
 
 // returns if current dev/stable is upgradeable
 bool WebStatusService::current_upgradeable() const {
+    FirmwareVersion             current_version(current_version_s);
+    bool                        is_dev = current_version.prerelease().find("dev") != std::string::npos;
+    std::lock_guard<std::mutex> lock{versions_mutex_};
     if (!versions_cache_valid_) {
         return false;
     }
-    FirmwareVersion current_version(current_version_s);
-    bool            is_dev = current_version.prerelease().find("dev") != std::string::npos;
     return is_dev ? versions_dev_.upgradeable : versions_stable_.upgradeable;
 }
 

src/web/WebStatusService.h

@@ -7,6 +7,8 @@
 #include "../core/firmwareVersion.h"
 #include "../emsesp_version.h"
 
+#include <mutex>
+
 namespace emsesp {
 
 class WebStatusService {
@@ -67,14 +69,24 @@ class WebStatusService {
     VersionInfo versions_dev_;
     bool        versions_cache_valid_   = false; // true once we've had at least one successful fetch
     uint32_t    versions_next_fetch_ms_ = 0;     // uuid::get_uptime() of the next attempt; 0 = idle
+    uint8_t     versions_failures_      = 0;     // consecutive failed fetches, drives the retry backoff
+
+    // the cache is written by the loop task in refresh_versions_cache() and read by the AsyncTCP
+    // task in getVersions()/current_upgradeable(), so the std::strings need guarding - without it a
+    // request landing mid-update reads a buffer that has just been freed
+    mutable std::mutex versions_mutex_;
 
     bool refresh_versions_cache(); // does the actual HTTPS fetch + parse, returns true on success
 
     static constexpr const char * VERSIONS_URL = "http://emsesp.org/versions.json";
 
     static constexpr uint32_t VERSIONS_REFRESH_INTERVAL_MS    = 60UL * 60UL * 1000UL; // 1 hour on success
-    static constexpr uint32_t VERSIONS_RETRY_INTERVAL_MS      = 5UL * 60UL * 1000UL;  // 5 min after failure
+    static constexpr uint32_t VERSIONS_RETRY_INTERVAL_MS      = 5UL * 60UL * 1000UL;  // 5 min after the first failure
     static constexpr uint32_t VERSIONS_INITIAL_FETCH_DELAY_MS = 5UL * 1000UL;         // 5 s after a link comes up
+
+    // each attempt blocks the loop task for as long as the DNS lookup, connect and read timeouts
+    // allow, so double the retry delay per consecutive failure: 5, 10, 20, 40, 80, 160 minutes
+    static constexpr uint8_t VERSIONS_MAX_BACKOFF_STEPS = 6;
 };
 
 } // namespace emsesp