From 6c4ec6869ce52e5a8fa224a53a709250b51764c6 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 14:42:39 -0700 Subject: [PATCH 01/19] fix(dispatcher): pick radio-watchdog activity by age, not largest timestamp MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The watchdog took max(last_recv, last_irq, last_tx) of three raw millis() timestamps. Around the 32-bit wrap a transmit stamped in the upper half of the range is numerically larger than every fresh post-wrap receive, so it kept winning for up to ~24 days: the watchdog measured silence from that stale transmit, concluded the radio had gone deaf, and reset a radio that was receiving normally — once per watchdog interval, until the old value stopped winning. Extract the decision into RadioWatchdog (pure, host-testable). It compares each timestamp only against its own previous value, so any change is fresh activity, and stamps it against a monotonic 64-bit clock extended from millis(). Evidence older than one 32-bit cycle now stays old instead of aliasing back to "recent", which the previous unsigned-subtraction age could not do either. Covered in test/test_radio_watchdog: pre-wrap TX with continuous post-wrap RX, genuine silence across the wrap, silence past a full millis() cycle, no activity since boot, disabled watchdog, TX-only traffic, and a stalled mesh loop. --- src/Dispatcher.cpp | 34 +-- src/Dispatcher.h | 8 +- src/helpers/RadioWatchdog.h | 116 ++++++++++ .../test_radio_watchdog.cpp | 204 ++++++++++++++++++ 4 files changed, 343 insertions(+), 19 deletions(-) create mode 100644 src/helpers/RadioWatchdog.h create mode 100644 test/test_radio_watchdog/test_radio_watchdog.cpp diff --git a/src/Dispatcher.cpp b/src/Dispatcher.cpp index 2a491a610..0c9c47506 100644 --- a/src/Dispatcher.cpp +++ b/src/Dispatcher.cpp @@ -29,6 +29,9 @@ void Dispatcher::begin() { _radio->begin(); prev_isrecv_mode = _radio->isInRecvMode(); +#ifdef WITH_MQTT_BRIDGE + radio_watchdog.reset((uint32_t)_ms->getMillis()); +#endif } float Dispatcher::getAirtimeBudgetFactor() const { @@ -94,23 +97,20 @@ void Dispatcher::loop() { // MQTTPrefs radio_watchdog_minutes setting. #ifdef WITH_MQTT_BRIDGE { - const uint32_t watchdog_ms = getRadioWatchdogMillis(); - if (watchdog_ms > 0) { - unsigned long last_recv = _radio->getLastRecvMillis(); - unsigned long last_irq = _radio->getLastRadioInterruptMillis(); - unsigned long last_active = (last_recv > last_irq ? last_recv : last_irq); - if (last_radio_active_ms > last_active) last_active = last_radio_active_ms; - if (is_recv && last_active > 0) { - unsigned long silent_ms = _ms->getMillis() - last_active; - unsigned long since_recovery = _ms->getMillis() - last_watchdog_recovery; - if (silent_ms > watchdog_ms && since_recovery > watchdog_ms) { - _err_flags |= ERR_EVENT_RADIO_WATCHDOG; - MESH_DEBUG_PRINTLN("Radio watchdog: silent %lu ms, state=%d, recovering", silent_ms, _radio->getRadioState()); - _radio->idle(); - _radio->startRecv(); - last_watchdog_recovery = _ms->getMillis(); - } - } + // Selecting the most recent event by age rather than by largest timestamp is + // what keeps this correct across the millis() wrap — see RadioWatchdog. + RadioWatchdogDecision wd = radio_watchdog.update( + (uint32_t)_ms->getMillis(), is_recv, getRadioWatchdogMillis(), + (uint32_t)_radio->getLastRecvMillis(), + (uint32_t)_radio->getLastRadioInterruptMillis(), + (uint32_t)last_radio_active_ms); + if (wd.recover) { + _err_flags |= ERR_EVENT_RADIO_WATCHDOG; + MESH_DEBUG_PRINTLN("Radio watchdog: silent %lu ms, state=%d, recovering", + (unsigned long)wd.silent_ms, _radio->getRadioState()); + _radio->idle(); + _radio->startRecv(); + radio_watchdog.noteRecovery(); } } #endif // WITH_MQTT_BRIDGE (radio watchdog) diff --git a/src/Dispatcher.h b/src/Dispatcher.h index 7edb7c7fe..25f1c3077 100644 --- a/src/Dispatcher.h +++ b/src/Dispatcher.h @@ -5,6 +5,9 @@ #include #include #include +#ifdef WITH_MQTT_BRIDGE + #include "helpers/RadioWatchdog.h" +#endif namespace mesh { @@ -135,8 +138,10 @@ typedef uint32_t DispatcherAction; class Dispatcher { Packet* outbound; // current outbound packet unsigned long outbound_expiry, outbound_start, total_air_time, rx_air_time; - unsigned long last_watchdog_recovery; unsigned long last_radio_active_ms; // updated on any TX or RX event; used by watchdog +#ifdef WITH_MQTT_BRIDGE + RadioWatchdog radio_watchdog; +#endif unsigned long next_tx_time; unsigned long cad_busy_start; unsigned long radio_nonrx_start; @@ -171,7 +176,6 @@ protected: tx_budget_ms = 0; last_budget_update = 0; duty_cycle_window_ms = 3600000; - last_watchdog_recovery = 0; last_radio_active_ms = 0; } diff --git a/src/helpers/RadioWatchdog.h b/src/helpers/RadioWatchdog.h new file mode 100644 index 000000000..1642c60be --- /dev/null +++ b/src/helpers/RadioWatchdog.h @@ -0,0 +1,116 @@ +#pragma once + +#include + +// Decides when the observer radio watchdog should kick a radio that is parked in +// RX but hearing nothing (see Dispatcher::loop()). +// +// Pure logic: no Arduino, radio or mesh headers. The caller feeds the raw 32-bit +// activity timestamps it can see (last receive, last radio interrupt, last +// successful transmit) plus its millis() counter. +// +// Why this is not a max() of those three timestamps: millis() wraps every ~49.7 +// days, and a pre-wrap timestamp is numerically larger than every fresh +// post-wrap one. Picking the largest therefore latches onto an old transmit and +// reports the radio silent while it is receiving continuously, resetting a +// healthy radio once per watchdog interval until that timestamp stops winning. +// +// Instead the caller's timestamps are only ever compared with their own previous +// values: any change is fresh activity, stamped against a monotonic 64-bit clock +// extended from millis(). Nothing downstream has a rollover case, and evidence +// older than one 32-bit cycle stays old instead of aliasing back to "recent". +// +// How far a timestamp may run behind the previous one and still count as an +// out-of-order reading rather than a very long forward gap (same rule as +// RadioActivityWindow). +#define RADIO_WATCHDOG_BACKSTEP_TOLERANCE_MS 5000UL + +struct RadioWatchdogDecision { + bool recover; // trip now: idle + restart receive + bool measurable; // false until some activity has been observed + uint64_t silent_ms; // age of the most recent activity (0 when !measurable) +}; + +class RadioWatchdog { +public: + RadioWatchdog() { reset(0); } + + void reset(uint32_t now_ms) { + _now_ms = now_ms; + _last_input_ms = now_ms; + _seeded = false; + _has_activity = false; + _last_recv = _last_irq = _last_tx = 0; + _last_activity_ms = now_ms; + _recovered = false; + _last_recovery_ms = 0; + } + + // Call once per loop with the current activity timestamps. `in_recv_mode` and + // `watchdog_ms` (0 disables) gate the decision; the silence measurement is + // updated either way so a disabled or transmitting radio does not accumulate + // phantom silence. + RadioWatchdogDecision update(uint32_t now_ms, bool in_recv_mode, uint32_t watchdog_ms, + uint32_t last_recv, uint32_t last_irq, uint32_t last_tx) { + tick(now_ms); + + if (!_seeded) { + // First observation: the timestamps carry activity from before this + // tracker existed, so date it to now rather than trusting a raw value we + // cannot place on our own clock. Worst case that delays the first + // possible trip by one watchdog interval. + _seeded = true; + _has_activity = (last_recv != 0 || last_irq != 0 || last_tx != 0); + _last_activity_ms = _now_ms; + } else if (last_recv != _last_recv || last_irq != _last_irq || last_tx != _last_tx) { + _has_activity = true; + _last_activity_ms = _now_ms; + } + _last_recv = last_recv; + _last_irq = last_irq; + _last_tx = last_tx; + + RadioWatchdogDecision d; + d.recover = false; + d.measurable = _has_activity; + d.silent_ms = _has_activity ? (_now_ms - _last_activity_ms) : 0; + + if (!_has_activity || !in_recv_mode || watchdog_ms == 0) return d; + if (d.silent_ms <= watchdog_ms) return d; + // One recovery per watchdog interval: a radio that stays silent through a + // reset must not be reset every loop. + if (_recovered && (_now_ms - _last_recovery_ms) <= watchdog_ms) return d; + + d.recover = true; + return d; + } + + // Call after acting on a decision with recover set. + void noteRecovery() { + _recovered = true; + _last_recovery_ms = _now_ms; + } + + uint64_t nowMs() const { return _now_ms; } + +private: + // Extends the caller's 32-bit millis() to a monotonic 64-bit clock. + void tick(uint32_t now_ms) { + uint32_t delta = now_ms - _last_input_ms; + if (delta > 0x80000000u && + (uint32_t)(_last_input_ms - now_ms) <= RADIO_WATCHDOG_BACKSTEP_TOLERANCE_MS) { + return; // out-of-order reading: no time has passed + } + _now_ms += delta; + _last_input_ms = now_ms; + } + + uint64_t _now_ms; + uint32_t _last_input_ms; + bool _seeded; + bool _has_activity; + uint32_t _last_recv, _last_irq, _last_tx; + uint64_t _last_activity_ms; + bool _recovered; + uint64_t _last_recovery_ms; +}; diff --git a/test/test_radio_watchdog/test_radio_watchdog.cpp b/test/test_radio_watchdog/test_radio_watchdog.cpp new file mode 100644 index 000000000..fea7e7203 --- /dev/null +++ b/test/test_radio_watchdog/test_radio_watchdog.cpp @@ -0,0 +1,204 @@ +#include "helpers/RadioWatchdog.h" + +#include + +namespace { + +const uint32_t WATCHDOG_MS = 300000UL; // RADIO_WATCHDOG_MS default: 5 minutes + +// Mirrors Dispatcher::loop(): the radio's three timestamps are sampled every +// pass, and a recovery is acknowledged as soon as it is decided. +struct Radio { + uint32_t last_recv = 0; + uint32_t last_irq = 0; + uint32_t last_tx = 0; +}; + +RadioWatchdogDecision run(RadioWatchdog& w, const Radio& r, uint32_t now, + bool in_recv_mode = true, uint32_t watchdog_ms = WATCHDOG_MS) { + RadioWatchdogDecision d = w.update(now, in_recv_mode, watchdog_ms, + r.last_recv, r.last_irq, r.last_tx); + if (d.recover) w.noteRecovery(); + return d; +} + +} // namespace + +TEST(RadioWatchdog, NoActivitySinceBootNeverTrips) { + RadioWatchdog w; + w.reset(0); + Radio r; // radio has never received, interrupted or transmitted + + for (uint32_t t = 0; t <= 4 * WATCHDOG_MS; t += 10000) { + RadioWatchdogDecision d = run(w, r, t); + EXPECT_FALSE(d.recover) << "tripped at t=" << t; + EXPECT_FALSE(d.measurable); + } +} + +TEST(RadioWatchdog, ContinuousReceiveNeverTrips) { + RadioWatchdog w; + w.reset(0); + Radio r; + + for (uint32_t t = 1000; t <= 3 * WATCHDOG_MS; t += 1000) { + r.last_recv = t; + r.last_irq = t; + RadioWatchdogDecision d = run(w, r, t); + EXPECT_FALSE(d.recover) << "tripped at t=" << t; + EXPECT_LE(d.silent_ms, 1000u); + } +} + +TEST(RadioWatchdog, SilentRadioTripsOncePerInterval) { + RadioWatchdog w; + w.reset(0); + Radio r; + r.last_recv = 1000; + run(w, r, 1000); + + int trips = 0; + uint32_t first_trip = 0; + for (uint32_t t = 2000; t <= 1000000; t += 1000) { + if (run(w, r, t).recover) { + if (trips == 0) first_trip = t; + trips++; + } + } + + EXPECT_EQ(302000u, first_trip); // strictly past the interval, from the last receive + EXPECT_EQ(3, trips); // ~1 M ms / 300 s, never per-loop +} + +// F13: a transmit timestamp from just before the millis() wrap is numerically +// larger than every fresh post-wrap receive. Selecting the largest timestamp +// reported ~24 days of silence and reset a radio that was receiving normally. +TEST(RadioWatchdog, PreWrapTransmitDoesNotSilenceFreshPostWrapReceives) { + const uint32_t WRAP = 0xFFFFFFFFu; + const uint32_t TX_AT = 0x80000000u; // upper half: beats any post-wrap value + + RadioWatchdog w; + w.reset(TX_AT - 60000); + Radio r; + r.last_recv = TX_AT - 60000; + r.last_irq = TX_AT - 60000; + run(w, r, TX_AT - 60000); + + r.last_tx = TX_AT; + run(w, r, TX_AT); + + // Receive steadily right up to the wrap... + for (uint32_t t = TX_AT + 1000; t < WRAP - 1000; t += 1000) { + r.last_recv = t; + r.last_irq = t; + ASSERT_FALSE(run(w, r, t).recover) << "tripped before wrap at t=" << t; + } + + // ...and straight through it. The stale transmit is still the numerically + // largest of the three timestamps for the next ~24 days. + for (uint32_t t = 1000; t < 2 * WATCHDOG_MS; t += 1000) { + r.last_recv = t; + r.last_irq = t; + RadioWatchdogDecision d = run(w, r, t); + ASSERT_FALSE(d.recover) << "tripped after wrap at t=" << t; + ASSERT_LE(d.silent_ms, 1000u); + } +} + +// The wrap must not hide a genuinely silent radio either. +TEST(RadioWatchdog, SilenceAcrossTheWrapIsStillDetected) { + const uint32_t LAST_RX = 0xFFFF0000u; // ~65 s before the wrap + + RadioWatchdog w; + w.reset(LAST_RX - 1000); + Radio r; + r.last_recv = LAST_RX; + r.last_irq = LAST_RX; + run(w, r, LAST_RX); + + bool tripped = false; + uint64_t silent_at_trip = 0; + for (uint32_t step = 1000; step <= WATCHDOG_MS + 5000; step += 1000) { + uint32_t t = LAST_RX + step; // wraps on its own + RadioWatchdogDecision d = run(w, r, t); + if (d.recover) { + tripped = true; + silent_at_trip = d.silent_ms; + break; + } + } + + EXPECT_TRUE(tripped); + EXPECT_GT(silent_at_trip, (uint64_t)WATCHDOG_MS); +} + +// Uptime past 2^32 ms must not alias a long silence back to "recent". +TEST(RadioWatchdog, SilenceBeyondOneMillisCycleKeepsGrowing) { + RadioWatchdog w; + w.reset(0); + Radio r; + r.last_recv = 1000; + run(w, r, 1000); + + // Walk a full cycle in 1-minute steps; the raw timestamp aliases back to its + // starting value, the tracked age does not. + uint64_t last_silent = 0; + for (uint64_t step = 60000; step <= 0x100000000ull + 600000ull; step += 60000) { + uint32_t t = (uint32_t)((1000ull + step) & 0xFFFFFFFFull); + RadioWatchdogDecision d = w.update(t, true, WATCHDOG_MS, r.last_recv, r.last_irq, r.last_tx); + if (d.recover) w.noteRecovery(); + ASSERT_GT(d.silent_ms, last_silent); + last_silent = d.silent_ms; + } + + EXPECT_GT(last_silent, 0x100000000ull); +} + +TEST(RadioWatchdog, DisabledWatchdogAndNonRecvModeNeverTrip) { + RadioWatchdog w; + w.reset(0); + Radio r; + r.last_recv = 1000; + run(w, r, 1000); + + for (uint32_t t = 2000; t <= 1000000; t += 10000) { + EXPECT_FALSE(run(w, r, t, /*in_recv_mode=*/true, /*watchdog_ms=*/0).recover); + EXPECT_FALSE(run(w, r, t, /*in_recv_mode=*/false).recover); + } +} + +// Transmit-only traffic still counts as a live radio. +TEST(RadioWatchdog, TransmitActivityRefreshesSilence) { + RadioWatchdog w; + w.reset(0); + Radio r; + r.last_recv = 1000; + run(w, r, 1000); + + for (uint32_t t = 100000; t <= 900000; t += 100000) { + r.last_tx = t; + EXPECT_FALSE(run(w, r, t).recover) << "tripped at t=" << t; + } +} + +// A blocked mesh loop (e.g. a 30 s NTP probe) collapses several events into one +// observation. That may only shorten measured silence, never lengthen it. +TEST(RadioWatchdog, LoopStallDoesNotManufactureSilence) { + RadioWatchdog w; + w.reset(0); + Radio r; + r.last_recv = 1000; + run(w, r, 1000); + + r.last_recv = 20000; // arrived during the stall + r.last_irq = 20000; + RadioWatchdogDecision d = run(w, r, 31000); + + EXPECT_FALSE(d.recover); + EXPECT_EQ(0u, d.silent_ms); +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From a868c8eeb3bdb128ae0d99761d7315230b430dd1 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 14:44:14 -0700 Subject: [PATCH 02/19] fix(wifi): one power-save mapping for CLI, startup and reconnect MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `set wifi.powersave min` stored 0 and applied WIFI_PS_MIN_MODEM, but the bridge's post-reconnect mapping read the same 0 as WIFI_PS_NONE. A node explicitly configured for minimum modem sleep therefore ran with power save off after its first reconnect, while `get wifi.powersave` still reported min. The stored default is already 1 (`none`), so nothing here changes the product default — it stops an operator's explicit choice from being reinterpreted. Move the value/name/mode table into WifiPowerSavePolicy (pure, host-tested) and use it from the CLI setter and getter, the web config snapshot and the bridge. The bridge now also applies the mode when it finds the STA already associated at start — that path has no connect transition to carry the setting, so a bridge restart used to leave whatever mode was set before. --- src/helpers/CommonCLI_Observer.cpp | 30 ++------ src/helpers/WifiPowerSavePolicy.h | 73 +++++++++++++++++++ src/helpers/bridges/MQTTBridge.cpp | 31 +++++--- src/helpers/bridges/MQTTBridge.h | 1 + src/helpers/esp32/WebConfigServer.cpp | 4 +- .../test_wifi_power_save_policy.cpp | 58 +++++++++++++++ 6 files changed, 163 insertions(+), 34 deletions(-) create mode 100644 src/helpers/WifiPowerSavePolicy.h create mode 100644 test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp diff --git a/src/helpers/CommonCLI_Observer.cpp b/src/helpers/CommonCLI_Observer.cpp index 9b2b2d302..dbb6e0214 100644 --- a/src/helpers/CommonCLI_Observer.cpp +++ b/src/helpers/CommonCLI_Observer.cpp @@ -15,6 +15,7 @@ #include "TxtDataHelpers.h" #include "AlertReporter.h" // for alertReporterBannedChannelMatch[Hex]() #include "MQTTObserverValidation.h" // pure input validators (host-testable) +#include "WifiPowerSavePolicy.h" // one powersave value->mode/name mapping #include #include #ifdef ESP_PLATFORM @@ -438,41 +439,28 @@ bool CommonCLI::handleObserverSetCmd(uint32_t sender_timestamp, const char* conf if (!persistObserverPrefs(reply)) return true; strcpy(reply, "OK"); } else if (memcmp(config, "wifi.powersave ", 15) == 0) { - const char* value = &config[15]; uint8_t ps_value; - bool valid = false; - if (memcmp(value, "min", 3) == 0 && (value[3] == 0 || value[3] == ' ')) { - ps_value = 0; - valid = true; - } else if (memcmp(value, "none", 4) == 0 && (value[4] == 0 || value[4] == ' ')) { - ps_value = 1; - valid = true; - } else if (memcmp(value, "max", 3) == 0 && (value[3] == 0 || value[3] == ' ')) { - ps_value = 2; - valid = true; - } - if (!valid) { + if (!WifiPowerSavePolicy::parseName(&config[15], &ps_value)) { strcpy(reply, "Error: must be none, min, or max"); } else { _mqtt_prefs.wifi_power_save = ps_value; if (!persistObserverPrefs(reply)) return true; + const char* ps_name = WifiPowerSavePolicy::nameFor(ps_value); #ifdef ESP_PLATFORM if (WiFi.status() == WL_CONNECTED) { - wifi_ps_type_t ps_mode = (ps_value == 1) ? WIFI_PS_NONE : - (ps_value == 2) ? WIFI_PS_MAX_MODEM : WIFI_PS_MIN_MODEM; - esp_err_t ps_result = esp_wifi_set_ps(ps_mode); + // Same mapping the bridge applies on every association, so this cannot + // drift back apart (see WifiPowerSavePolicy). + esp_err_t ps_result = + esp_wifi_set_ps((wifi_ps_type_t)WifiPowerSavePolicy::modeFor(ps_value)); if (ps_result == ESP_OK) { - const char* ps_name = (ps_value == 1) ? "none" : (ps_value == 2) ? "max" : "min"; sprintf(reply, "OK - power save set to %s", ps_name); } else { sprintf(reply, "OK - saved, but failed to apply: %d", ps_result); } } else { - const char* ps_name = (ps_value == 1) ? "none" : (ps_value == 2) ? "max" : "min"; sprintf(reply, "OK - saved as %s (will apply on next WiFi connection)", ps_name); } #else - const char* ps_name = (ps_value == 1) ? "none" : (ps_value == 2) ? "max" : "min"; sprintf(reply, "OK - saved as %s", ps_name); #endif } @@ -1090,9 +1078,7 @@ bool CommonCLI::handleObserverGetCmd(uint32_t sender_timestamp, const char* conf #endif } } else if (memcmp(config, "wifi.powersave", 14) == 0) { - uint8_t ps = _mqtt_prefs.wifi_power_save; - const char* ps_name = (ps == 1) ? "none" : (ps == 2) ? "max" : "min"; - sprintf(reply, "> %s", ps_name); + sprintf(reply, "> %s", WifiPowerSavePolicy::nameFor(_mqtt_prefs.wifi_power_save)); } else if (memcmp(config, "timezone.offset", 15) == 0) { // Must precede the "timezone" (8-byte) check below — that prefix-matches // "timezone.offset" too, so the more-specific key has to come first or diff --git a/src/helpers/WifiPowerSavePolicy.h b/src/helpers/WifiPowerSavePolicy.h new file mode 100644 index 000000000..bdebd57e1 --- /dev/null +++ b/src/helpers/WifiPowerSavePolicy.h @@ -0,0 +1,73 @@ +#pragma once + +#include +#include + +// The single mapping between the stored `wifi.powersave` preference, its CLI +// name, and the IDF power-save mode. +// +// Pure lookup so host tests can hold startup, reconnect, CLI and web config to +// one table: they used to map the same stored value differently, so a node set +// to `min` silently ran with power save off after its first reconnect while +// `get wifi.powersave` still said min. +// +// Stored values are fleet state — never renumber them. The product default is +// `none`, which is a *default* (MQTTDefaults.h), not a reinterpretation of an +// operator's explicit `min`. +namespace WifiPowerSavePolicy { + +enum StoredValue : uint8_t { + kMin = 0, // WIFI_PS_MIN_MODEM + kNone = 1, // WIFI_PS_NONE (default) + kMax = 2, // WIFI_PS_MAX_MODEM +}; + +// Mirrors wifi_ps_type_t. MQTTBridge.cpp static_asserts these against the SDK. +enum Mode : uint8_t { + kModeNone = 0, + kModeMinModem = 1, + kModeMaxModem = 2, +}; + +// Anything outside the known range reads as the default rather than as the +// lowest-numbered mode, so a corrupt byte cannot silently enable modem sleep. +static inline Mode modeFor(uint8_t stored) { + switch (stored) { + case kMin: return kModeMinModem; + case kMax: return kModeMaxModem; + case kNone: return kModeNone; + default: return kModeNone; + } +} + +static inline const char* nameFor(uint8_t stored) { + switch (stored) { + case kMin: return "min"; + case kMax: return "max"; + case kNone: return "none"; + default: return "none"; + } +} + +// Parses a CLI argument, which may be followed by trailing text (the observer +// setters take the rest of the command line). Returns false and leaves *out +// untouched for anything else. +static inline bool parseName(const char* value, uint8_t* out) { + if (value == nullptr || out == nullptr) return false; + static const struct { const char* name; uint8_t stored; } kNames[] = { + { "min", kMin }, + { "none", kNone }, + { "max", kMax }, + }; + for (unsigned i = 0; i < sizeof(kNames) / sizeof(kNames[0]); i++) { + const size_t len = strlen(kNames[i].name); + if (strncmp(value, kNames[i].name, len) == 0 && + (value[len] == '\0' || value[len] == ' ')) { + *out = kNames[i].stored; + return true; + } + } + return false; +} + +} // namespace WifiPowerSavePolicy diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 39c8f05b7..a45dd6124 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -1,4 +1,5 @@ #include "MQTTBridge.h" +#include "../WifiPowerSavePolicy.h" #include "../MQTTConnectionPolicy.h" #include "../MQTTMessageBuilder.h" #include "../MQTTPacketQueuePolicy.h" @@ -427,6 +428,19 @@ int MQTTBridge::getMaxActiveSlots() { #endif } +// One mapping for startup, reconnect and CLI (see WifiPowerSavePolicy). The +// stored default is `none`; `min` means MIN_MODEM here exactly as the CLI says +// it does. +void MQTTBridge::applyWifiPowerSave() { + #ifdef ESP_PLATFORM + static_assert((int)WifiPowerSavePolicy::kModeNone == (int)WIFI_PS_NONE, "wifi_ps_type_t drift"); + static_assert((int)WifiPowerSavePolicy::kModeMinModem == (int)WIFI_PS_MIN_MODEM, "wifi_ps_type_t drift"); + static_assert((int)WifiPowerSavePolicy::kModeMaxModem == (int)WIFI_PS_MAX_MODEM, "wifi_ps_type_t drift"); + if (!_obs) return; + esp_wifi_set_ps((wifi_ps_type_t)WifiPowerSavePolicy::modeFor(_obs->wifi_power_save)); + #endif +} + uint8_t MQTTBridge::getLastWifiDisconnectReason() { return s_wifi_disconnect_reason; } unsigned long MQTTBridge::getLastWifiDisconnectTime() { return s_wifi_disconnect_time; } @@ -2804,6 +2818,12 @@ bool MQTTBridge::handleWiFiConnection(unsigned long now) { _wifi_status_initialized = true; setWifiOutage(AlertFaultPolicy::applyWifiStatus( (uint32_t)now, current_wifi_status == WL_CONNECTED, wifiOutage(), false)); + #ifdef ESP_PLATFORM + // Already associated at bridge start (end()/begin() leaves STA up): there is + // no connect transition below to carry the setting, so apply it here or the + // node runs on whatever the previous mode was. + if (current_wifi_status == WL_CONNECTED) applyWifiPowerSave(); + #endif } if (now - _last_wifi_check <= 10000) { // Events own the snapshot between 10 s polls. If STA is associated again @@ -2827,16 +2847,7 @@ bool MQTTBridge::handleWiFiConnection(unsigned long now) { s_wifi_connected_at = now; _wifi_reconnect_backoff_attempt = 0; #ifdef ESP_PLATFORM - wifi_ps_type_t ps_mode; - uint8_t ps_pref = _obs->wifi_power_save; - if (ps_pref == 1) { - ps_mode = WIFI_PS_NONE; - } else if (ps_pref == 2) { - ps_mode = WIFI_PS_MAX_MODEM; - } else { - ps_mode = WIFI_PS_NONE; // default: no power save; eliminates DTIM wake latency on mains-powered bridges - } - esp_wifi_set_ps(ps_mode); + applyWifiPowerSave(); #ifdef MQTT_WIFI_TX_POWER WiFi.setTxPower(MQTT_WIFI_TX_POWER); #else diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index e2d272538..b4ee7b992 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -517,6 +517,7 @@ private: void getClientVersion(char* buffer, size_t buffer_size) const; void logMemoryStatus(); void refreshOriginFromPrefs(); + void applyWifiPowerSave(); // one mapping, applied on every association // begin()/end()-scoped PSRAM buffers. Each allocation is independent so a // transient heap shortage degrades to the existing stack fallback instead // of making the bridge unusable. diff --git a/src/helpers/esp32/WebConfigServer.cpp b/src/helpers/esp32/WebConfigServer.cpp index 34bdca4b7..d62a07f18 100644 --- a/src/helpers/esp32/WebConfigServer.cpp +++ b/src/helpers/esp32/WebConfigServer.cpp @@ -14,6 +14,7 @@ #include #include #include +#include #include #include "WebConfigHtml.h" @@ -722,8 +723,7 @@ void WebConfigServer::handleConfigGet(AsyncWebServerRequest* req) { JsonObject wifi = doc.createNestedObject("wifi"); wifi["ssid"] = (const char*)_obs->wifi_ssid; wifi["pwd"] = _obs->wifi_password[0] ? SECRET_SENTINEL : ""; - wifi["powersave"] = _obs->wifi_power_save == 0 ? "min" - : _obs->wifi_power_save == 2 ? "max" : "none"; + wifi["powersave"] = WifiPowerSavePolicy::nameFor(_obs->wifi_power_save); JsonObject mqtt = doc.createNestedObject("mqtt"); mqtt["origin"] = (const char*)_obs->mqtt_origin; diff --git a/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp b/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp new file mode 100644 index 000000000..66803aa5e --- /dev/null +++ b/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp @@ -0,0 +1,58 @@ +#include "helpers/WifiPowerSavePolicy.h" + +#include + +using namespace WifiPowerSavePolicy; + +// F11: the CLI applied stored 0 as MIN_MODEM while the reconnect path applied it +// as NONE, so a node configured for `min` changed behaviour after every +// reconnect and `get wifi.powersave` still reported min. One table, one answer. +TEST(WifiPowerSavePolicy, StoredValuesMapToOneModeEach) { + EXPECT_EQ(kModeMinModem, modeFor(kMin)); + EXPECT_EQ(kModeNone, modeFor(kNone)); + EXPECT_EQ(kModeMaxModem, modeFor(kMax)); +} + +TEST(WifiPowerSavePolicy, NamesRoundTripWithStoredValues) { + for (uint8_t stored = 0; stored <= 2; stored++) { + uint8_t parsed = 0xFF; + ASSERT_TRUE(parseName(nameFor(stored), &parsed)) << "stored " << (int)stored; + EXPECT_EQ(stored, parsed); + EXPECT_EQ(modeFor(stored), modeFor(parsed)); + } +} + +// A byte outside the stored range must read as the product default, not as +// whatever mode happens to sit at that index. +TEST(WifiPowerSavePolicy, OutOfRangeStoredValueReadsAsDefault) { + for (int stored = 3; stored <= 255; stored++) { + EXPECT_EQ(kModeNone, modeFor((uint8_t)stored)) << "stored " << stored; + EXPECT_STREQ("none", nameFor((uint8_t)stored)); + } +} + +// The setters take the remainder of the command line, so a trailing argument +// must still parse — and a longer word starting with a valid name must not. +TEST(WifiPowerSavePolicy, ParsesCliArgumentsExactly) { + uint8_t stored = 0xFF; + + EXPECT_TRUE(parseName("min", &stored)); + EXPECT_EQ(kMin, stored); + EXPECT_TRUE(parseName("none extra", &stored)); + EXPECT_EQ(kNone, stored); + EXPECT_TRUE(parseName("max ", &stored)); + EXPECT_EQ(kMax, stored); + + stored = 0xFF; + EXPECT_FALSE(parseName("minimum", &stored)); + EXPECT_FALSE(parseName("", &stored)); + EXPECT_FALSE(parseName("off", &stored)); + EXPECT_FALSE(parseName("MIN", &stored)); + EXPECT_FALSE(parseName(nullptr, &stored)); + EXPECT_EQ(0xFF, stored); // rejected input leaves the caller's value alone +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From ffa50679477413e10a412910ea69209bc398fc14 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 14:44:37 -0700 Subject: [PATCH 03/19] fix(mqtt): label SDK errors from named constants; report broker refusals MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four of the hand-written error labels named the wrong failure against the installed SDK: Wi-Fi reason 201 is NO_AP_FOUND (reported as "security mismatch"), 202 is AUTH_FAIL (reported as "auth mode rejected"), 39 is TIMEOUT (reported as "SSID not found") and 34 is MISSING_ACKS (reported as an "AP state mismatch"). esp-tls 0x8008 is TCP_CLOSED_FIN, not a timeout, and 0x8010 is CERT_PARTLY_OK, not a generic mbedTLS error. 0x800B, labelled "cert verify failed", is not an esp-tls error at all. So the one line an operator reads to find out why a node is offline could name the wrong cause. Move the tables into MQTTErrorLabels.h (pure, host-tested) with every value static_asserted against the SDK enum/#define actually being compiled, so a framework bump fails the build instead of relabelling errors in the field. Codes the SDK does not define — including 61/88/168, which had labels no header supports — now return no label and the caller prints the raw number. Also keep the CONNACK return code from a broker refusal and show it in `get mqttN.diag` ("refused: bad user/password (4)"). A refusal is not a transport failure, so the TLS/socket fields are empty and a slot with wrong credentials previously showed no useful detail at all. --- src/helpers/bridges/MQTTBridge.cpp | 91 ++++++++----- src/helpers/bridges/MQTTBridge.h | 4 + src/helpers/bridges/MQTTErrorLabels.h | 125 ++++++++++++++++++ .../test_mqtt_error_labels.cpp | 78 +++++++++++ 4 files changed, 267 insertions(+), 31 deletions(-) create mode 100644 src/helpers/bridges/MQTTErrorLabels.h create mode 100644 test/test_mqtt_error_labels/test_mqtt_error_labels.cpp diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index a45dd6124..056af62a6 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -1,4 +1,5 @@ #include "MQTTBridge.h" +#include "MQTTErrorLabels.h" #include "../WifiPowerSavePolicy.h" #include "../MQTTConnectionPolicy.h" #include "../MQTTMessageBuilder.h" @@ -22,6 +23,7 @@ #ifdef ESP_PLATFORM #include +#include #include #include #include @@ -463,41 +465,52 @@ const char* MQTTBridge::getSlotPresetName(int slot_index) const { return MQTT_PRESET_CUSTOM; } +// The label tables live in MQTTErrorLabels.h so host tests can exercise them. +// These asserts are the contract between that pure table and the SDK actually +// being compiled against: a framework bump that renumbers a reason or an +// esp-tls error fails here instead of silently mislabelling it in the field. +#ifdef ESP_PLATFORM +static_assert(MQTTErrorLabels::kWifiNoApFound == WIFI_REASON_NO_AP_FOUND, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiAuthFail == WIFI_REASON_AUTH_FAIL, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiAssocFail == WIFI_REASON_ASSOC_FAIL, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiHandshakeTimeout == WIFI_REASON_HANDSHAKE_TIMEOUT, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiConnectionFail == WIFI_REASON_CONNECTION_FAIL, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiBeaconTimeout == WIFI_REASON_BEACON_TIMEOUT, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiApTsfReset == WIFI_REASON_AP_TSF_RESET, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiRoaming == WIFI_REASON_ROAMING, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiSaQueryTimeout == WIFI_REASON_SA_QUERY_TIMEOUT, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiAuthExpire == WIFI_REASON_AUTH_EXPIRE, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiAssocExpire == WIFI_REASON_ASSOC_EXPIRE, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiAssocLeave == WIFI_REASON_ASSOC_LEAVE, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiBssTransitionDisassoc == WIFI_REASON_BSS_TRANSITION_DISASSOC, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifi4WayHandshakeTimeout == WIFI_REASON_4WAY_HANDSHAKE_TIMEOUT, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiGroupCipherInvalid == WIFI_REASON_GROUP_CIPHER_INVALID, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiCipherSuiteRejected == WIFI_REASON_CIPHER_SUITE_REJECTED, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiMissingAcks == WIFI_REASON_MISSING_ACKS, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiTimeout == WIFI_REASON_TIMEOUT, "wifi reason drift"); +static_assert(MQTTErrorLabels::kWifiInvalidPmkid == WIFI_REASON_INVALID_PMKID, "wifi reason drift"); + +static_assert(MQTTErrorLabels::kTlsCannotResolveHostname == ESP_ERR_ESP_TLS_CANNOT_RESOLVE_HOSTNAME, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsCannotCreateSocket == ESP_ERR_ESP_TLS_CANNOT_CREATE_SOCKET, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsUnsupportedProtoFamily == ESP_ERR_ESP_TLS_UNSUPPORTED_PROTOCOL_FAMILY, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsFailedConnectToHost == ESP_ERR_ESP_TLS_FAILED_CONNECT_TO_HOST, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsSocketSetoptFailed == ESP_ERR_ESP_TLS_SOCKET_SETOPT_FAILED, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsConnectionTimeout == ESP_ERR_ESP_TLS_CONNECTION_TIMEOUT, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsTcpClosedFin == ESP_ERR_ESP_TLS_TCP_CLOSED_FIN, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsCertPartlyOk == ESP_ERR_MBEDTLS_CERT_PARTLY_OK, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsSetHostname == ESP_ERR_MBEDTLS_SSL_SET_HOSTNAME_FAILED, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsX509ParseFailed == ESP_ERR_MBEDTLS_X509_CRT_PARSE_FAILED, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsSslSetupFailed == ESP_ERR_MBEDTLS_SSL_SETUP_FAILED, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsSslWriteFailed == ESP_ERR_MBEDTLS_SSL_WRITE_FAILED, "esp-tls error drift"); +static_assert(MQTTErrorLabels::kTlsMbedtlsHandshakeFailed == ESP_ERR_MBEDTLS_SSL_HANDSHAKE_FAILED, "esp-tls error drift"); +#endif + const char* MQTTBridge::wifiReasonStr(uint8_t reason) { - switch (reason) { - case 2: return "auth expired"; - case 4: return "assoc timeout"; - case 8: return "AP disconnected"; - case 15: return "4-way handshake timeout"; - case 18: return "group cipher mismatch"; - case 40: return "cipher suite rejected"; - case 49: return "invalid PMKID"; - case 61: return "AP BSS management"; - case 88: return "AP BSS management"; - case 168: return "AP band-steering kick"; - case 34: return "AP state mismatch (class 3 frame)"; - case 39: return "SSID not found"; - case 63: return "SA query timeout (PMF)"; - case 200: return "signal lost"; - case 201: return "security mismatch"; - case 202: return "auth mode rejected"; - case 204: return "handshake timeout"; - default: return nullptr; - } + return MQTTErrorLabels::wifiReason(reason); } const char* MQTTBridge::tlsErrorStr(int32_t err) { - switch (err) { - case 0x8001: return "DNS failed"; - case 0x8002: return "socket error"; - case 0x8004: return "connect refused"; - case 0x8006: return "TLS timeout"; - case 0x8008: return "connection timeout"; - case 0x800B: return "cert verify failed"; - case 0x8010: return "mbedTLS error"; - case 0x801A: return "TLS handshake failed"; - default: return nullptr; - } + return MQTTErrorLabels::tlsError(err); } void MQTTBridge::formatSlotDiagReply(char* buf, size_t bufsize, int slot_index) { @@ -564,6 +577,16 @@ void MQTTBridge::formatSlotDiagReply(char* buf, size_t bufsize, int slot_index) if (slot.connected && slot.last_error_time == 0) { replyAppendf(buf, bufsize, &pos, ", no errors"); } else if (slot.last_error_time > 0) { + // Broker refusal: the CONNECT reached a broker that answered "no". Reported + // first because the transport fields below are empty or irrelevant then. + if (slot.last_connack_code != 0) { + const char* why = MQTTErrorLabels::connackReason(slot.last_connack_code); + if (why) { + replyAppendf(buf, bufsize, &pos, ", refused: %s (%u)", why, (unsigned)slot.last_connack_code); + } else { + replyAppendf(buf, bufsize, &pos, ", refused: code %u", (unsigned)slot.last_connack_code); + } + } // TLS error with human-friendly description if (slot.last_tls_err != 0) { const char* desc = tlsErrorStr(slot.last_tls_err); @@ -1660,6 +1683,7 @@ bool MQTTBridge::ensureSlotClient(int index) { _slots[index].last_tls_err = 0; _slots[index].last_tls_stack_err = 0; _slots[index].last_sock_errno = 0; + _slots[index].last_connack_code = 0; _slots[index].last_error_time = 0; _slots[index].current_outage_started_ms = 0; // clear current-outage timer for AlertReporter updateCachedConnectionStatus(); // bool store — safe from this (esp-mqtt) task @@ -1689,6 +1713,11 @@ bool MQTTBridge::ensureSlotClient(int index) { _slots[index].last_tls_stack_err = error.esp_tls_stack_err; _slots[index].last_sock_errno = error.esp_transport_sock_errno; _slots[index].last_error_time = millis(); + // Cleared on any other error type so the diag describes the latest failure + // rather than pairing a fresh transport error with an old refusal. + _slots[index].last_connack_code = + (error.error_type == MQTT_ERROR_TYPE_CONNECTION_REFUSED) + ? (uint8_t)error.connect_return_code : 0; if (error.error_type == MQTT_ERROR_TYPE_CONNECTION_REFUSED) { _slot_force_jwt_mint[index] = true; // Broker rejected the MQTT CONNECT itself — not a transport failure. diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index b4ee7b992..9dd3f29c4 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -135,6 +135,10 @@ private: int32_t last_tls_err; // esp_tls_last_esp_err (0 = no error) int32_t last_tls_stack_err; // mbedTLS stack error int last_sock_errno; // socket errno + // CONNACK return code from the last broker refusal (0 = none). A refusal is + // not a transport failure, and without this the diag shows a slot with wrong + // credentials as an unexplained disconnect. + uint8_t last_connack_code; unsigned long last_error_time; // millis() of last error uint32_t disconnect_count; // Number of disconnect callbacks since boot unsigned long first_disconnect_time; // millis() of first disconnect after boot diff --git a/src/helpers/bridges/MQTTErrorLabels.h b/src/helpers/bridges/MQTTErrorLabels.h new file mode 100644 index 000000000..cee1b6880 --- /dev/null +++ b/src/helpers/bridges/MQTTErrorLabels.h @@ -0,0 +1,125 @@ +#pragma once + +#include + +// Operator-facing labels for the SDK error codes the observer reports through +// `get wifi.status`, `get mqttN.diag` and the web config panel. +// +// Pure lookup: no Arduino or ESP headers, so the table is host-testable. The +// numeric values below are the installed SDK's; MQTTBridge.cpp static_asserts +// every one of them against the real enum/#define, so a framework bump either +// keeps these labels honest or fails the build. Codes with no entry return +// nullptr and the caller prints the raw number — an unknown code must never be +// given a neighbouring code's name. +namespace MQTTErrorLabels { + +// esp_wifi_types.h wifi_err_reason_t. Values below 200 are 802.11 reason codes +// forwarded from the AP; 200+ are Espressif's own local failures. +enum WifiReason : uint16_t { + kWifiAuthExpire = 2, + kWifiAssocExpire = 4, + kWifiAssocLeave = 8, + kWifi4WayHandshakeTimeout = 15, + kWifiGroupCipherInvalid = 18, + kWifiCipherSuiteRejected = 24, + kWifiMissingAcks = 34, + kWifiTimeout = 39, + kWifiInvalidPmkid = 49, + kWifiBssTransitionDisassoc = 12, + kWifiBeaconTimeout = 200, + kWifiNoApFound = 201, + kWifiAuthFail = 202, + kWifiAssocFail = 203, + kWifiHandshakeTimeout = 204, + kWifiConnectionFail = 205, + kWifiApTsfReset = 206, + kWifiRoaming = 207, + kWifiSaQueryTimeout = 209, +}; + +// esp_tls_errors.h, ESP_ERR_ESP_TLS_BASE (0x8000) + offset. +enum TlsError : int32_t { + kTlsCannotResolveHostname = 0x8001, + kTlsCannotCreateSocket = 0x8002, + kTlsUnsupportedProtoFamily= 0x8003, + kTlsFailedConnectToHost = 0x8004, + kTlsSocketSetoptFailed = 0x8005, + kTlsConnectionTimeout = 0x8006, + kTlsTcpClosedFin = 0x8008, + kTlsMbedtlsCertPartlyOk = 0x8010, + kTlsMbedtlsSetHostname = 0x8012, + kTlsMbedtlsX509ParseFailed= 0x8015, + kTlsMbedtlsSslSetupFailed = 0x8017, + kTlsMbedtlsSslWriteFailed = 0x8018, + kTlsMbedtlsHandshakeFailed= 0x801A, +}; + +// MQTT 3.1.1 CONNACK return codes (esp_mqtt_error_codes.connect_return_code). +enum ConnackCode : uint8_t { + kConnackAccepted = 0, + kConnackBadProtocol = 1, + kConnackIdRejected = 2, + kConnackServerUnavail = 3, + kConnackBadCredentials = 4, + kConnackNotAuthorized = 5, +}; + +// Short enough to sit inside a LoRa-bounded diagnostic reply next to the raw code. +static inline const char* wifiReason(uint8_t reason) { + switch (reason) { + case kWifiAuthExpire: return "auth expired"; + case kWifiAssocExpire: return "assoc expired"; + case kWifiAssocLeave: return "AP disconnected"; + case kWifiBssTransitionDisassoc: return "AP steered us away"; + case kWifi4WayHandshakeTimeout: return "4-way handshake timeout"; + case kWifiGroupCipherInvalid: return "group cipher mismatch"; + case kWifiCipherSuiteRejected: return "cipher suite rejected"; + case kWifiMissingAcks: return "AP saw no acks"; + case kWifiTimeout: return "802.11 timeout"; + case kWifiInvalidPmkid: return "invalid PMKID"; + case kWifiBeaconTimeout: return "beacon lost"; + case kWifiNoApFound: return "SSID not found"; + case kWifiAuthFail: return "auth failed (check password)"; + case kWifiAssocFail: return "association failed"; + case kWifiHandshakeTimeout: return "handshake timeout"; + case kWifiConnectionFail: return "connect failed"; + case kWifiApTsfReset: return "AP restarted"; + case kWifiRoaming: return "roaming"; + case kWifiSaQueryTimeout: return "SA query timeout (PMF)"; + default: return nullptr; + } +} + +static inline const char* tlsError(int32_t err) { + switch (err) { + case kTlsCannotResolveHostname: return "DNS failed"; + case kTlsCannotCreateSocket: return "socket error"; + case kTlsUnsupportedProtoFamily: return "unsupported protocol family"; + case kTlsFailedConnectToHost: return "connect failed"; + case kTlsSocketSetoptFailed: return "socket setopt failed"; + case kTlsConnectionTimeout: return "connection timeout"; + case kTlsTcpClosedFin: return "server closed connection"; + case kTlsMbedtlsCertPartlyOk: return "cert chain partly parsed"; + case kTlsMbedtlsSetHostname: return "SNI hostname rejected"; + case kTlsMbedtlsX509ParseFailed: return "cert parse failed"; + case kTlsMbedtlsSslSetupFailed: return "TLS setup failed"; + case kTlsMbedtlsSslWriteFailed: return "TLS write failed"; + case kTlsMbedtlsHandshakeFailed: return "TLS handshake failed"; + default: return nullptr; + } +} + +// The broker answered and refused: this is what an operator needs instead of a +// transport error, which is why the bridge keeps the CONNACK code separately. +static inline const char* connackReason(uint8_t code) { + switch (code) { + case kConnackBadProtocol: return "protocol rejected"; + case kConnackIdRejected: return "client id rejected"; + case kConnackServerUnavail: return "server unavailable"; + case kConnackBadCredentials: return "bad user/password"; + case kConnackNotAuthorized: return "not authorized"; + default: return nullptr; + } +} + +} // namespace MQTTErrorLabels diff --git a/test/test_mqtt_error_labels/test_mqtt_error_labels.cpp b/test/test_mqtt_error_labels/test_mqtt_error_labels.cpp new file mode 100644 index 000000000..604789bcd --- /dev/null +++ b/test/test_mqtt_error_labels/test_mqtt_error_labels.cpp @@ -0,0 +1,78 @@ +#include "helpers/bridges/MQTTErrorLabels.h" + +#include + +#include + +using namespace MQTTErrorLabels; + +namespace { + +bool labelIs(const char* actual, const char* expected) { + return actual != nullptr && strcmp(actual, expected) == 0; +} + +} // namespace + +// F14: these four were the mislabels found in review. 201 is "no AP found" +// (usually a wrong/hidden SSID), not a security mismatch; 202 is an auth +// failure (usually a wrong password), not a rejected auth mode. +TEST(MQTTErrorLabels, WifiReasonsMatchTheSdkMeaning) { + EXPECT_TRUE(labelIs(wifiReason(201), "SSID not found")); + EXPECT_TRUE(labelIs(wifiReason(202), "auth failed (check password)")); + EXPECT_TRUE(labelIs(wifiReason(39), "802.11 timeout")); // was "SSID not found" + EXPECT_TRUE(labelIs(wifiReason(34), "AP saw no acks")); // was "AP state mismatch" +} + +TEST(MQTTErrorLabels, TlsErrorsMatchTheSdkMeaning) { + EXPECT_TRUE(labelIs(tlsError(0x8008), "server closed connection")); // was "connection timeout" + EXPECT_TRUE(labelIs(tlsError(0x8010), "cert chain partly parsed")); // was "mbedTLS error" + EXPECT_TRUE(labelIs(tlsError(0x8006), "connection timeout")); + EXPECT_TRUE(labelIs(tlsError(0x8001), "DNS failed")); + EXPECT_TRUE(labelIs(tlsError(0x801A), "TLS handshake failed")); +} + +// An unknown code must fall through to the caller's raw-number formatting +// rather than borrow a neighbouring code's label. 0x800B is the one the review +// caught: no such esp-tls error exists, but it was labelled "cert verify failed". +TEST(MQTTErrorLabels, UnknownCodesHaveNoLabel) { + EXPECT_EQ(nullptr, tlsError(0x800B)); + EXPECT_EQ(nullptr, tlsError(0)); + EXPECT_EQ(nullptr, tlsError(-1)); + EXPECT_EQ(nullptr, tlsError(0x8099)); + + EXPECT_EQ(nullptr, wifiReason(0)); + EXPECT_EQ(nullptr, wifiReason(61)); // not defined by the installed SDK + EXPECT_EQ(nullptr, wifiReason(88)); + EXPECT_EQ(nullptr, wifiReason(168)); + EXPECT_EQ(nullptr, wifiReason(255)); +} + +TEST(MQTTErrorLabels, ConnackReasonsCoverTheRefusalCodes) { + EXPECT_TRUE(labelIs(connackReason(1), "protocol rejected")); + EXPECT_TRUE(labelIs(connackReason(2), "client id rejected")); + EXPECT_TRUE(labelIs(connackReason(3), "server unavailable")); + EXPECT_TRUE(labelIs(connackReason(4), "bad user/password")); + EXPECT_TRUE(labelIs(connackReason(5), "not authorized")); + EXPECT_EQ(nullptr, connackReason(0)); // accepted: not an error to report + EXPECT_EQ(nullptr, connackReason(6)); +} + +// Labels share a bounded LoRa reply with the rest of the diagnostic line. +TEST(MQTTErrorLabels, LabelsStayShortEnoughForABoundedReply) { + for (int i = 0; i <= 255; i++) { + const char* w = wifiReason((uint8_t)i); + if (w) EXPECT_LE(strlen(w), 30u) << "wifi reason " << i; + const char* c = connackReason((uint8_t)i); + if (c) EXPECT_LE(strlen(c), 30u) << "connack code " << i; + } + for (int32_t e = 0x8000; e <= 0x8040; e++) { + const char* t = tlsError(e); + if (t) EXPECT_LE(strlen(t), 30u) << "tls error " << e; + } +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From 5b8ccc837d2afdfd826051b003e62d5aab607b6c Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 14:45:06 -0700 Subject: [PATCH 04/19] fix(mqtt): honour `mqtt.status off` for the on-connect status message MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Only the periodic status path consulted the setting. The connect callback armed a status publish unconditionally and publishStatusToSlot() never checked it, so every boot and every reconnect published a status message — including the metadata an operator turned the setting off to suppress. The documented contract is "Enable/disable status messages". Read the toggle live from prefs at publish time, matching the periodic path, and also skip a slot the operator has disabled: teardown only stops a client that reports connected, so a slot switched off mid-connect can still complete its handshake and arm this publish. --- MQTT_IMPLEMENTATION.md | 2 +- src/helpers/bridges/MQTTBridge.cpp | 10 ++++++++++ 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/MQTT_IMPLEMENTATION.md b/MQTT_IMPLEMENTATION.md index baf39ed64..9d4d16bc8 100644 --- a/MQTT_IMPLEMENTATION.md +++ b/MQTT_IMPLEMENTATION.md @@ -531,7 +531,7 @@ These settings apply across all MQTT slots: #### Set Commands - `set mqtt.origin ` - Set device origin name - `set mqtt.iata ` - Set IATA code (auto-uppercased) -- `set mqtt.status on|off` - Enable/disable status messages +- `set mqtt.status on|off` - Enable/disable status messages (periodic *and* the one sent on each broker connect) - `set mqtt.packets on|off` - Enable/disable packet messages - `set mqtt.raw on|off` - Enable/disable raw messages - `set mqtt.rx on|off` - Enable/disable RX (received) packet uplinking diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 056af62a6..7fa5d69e0 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -2604,6 +2604,16 @@ void MQTTBridge::publishStatusToSlot(int index) { if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return; MQTTSlot& slot = _slots[index]; if (!slot.client || !slot.connected) return; + // `set mqtt.status off` disables status messages, on-connect ones included + // (MQTT_IMPLEMENTATION.md: "Enable/disable status messages"). Read live from + // prefs like the periodic path, and checked here rather than at the pending + // flag so the setting that counts is the one in force when we publish. + if (!_obs->mqtt_status_enabled) return; + // A disabled slot can still hold a connection that was established before it + // was switched off (teardown only stops a client reporting connected), and + // its callback arms this publish. Do not speak for a slot the operator + // turned off. + if (!slot.enabled) return; refreshOriginFromPrefs(); From d1b5ed3fafb1d14898003030380cb65dd400f95d Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 14:45:22 -0700 Subject: [PATCH 05/19] fix(mqtt): validate NTP replies before trusting them MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit NTPClient::forceUpdate() treated any non-empty datagram arriving on its fixed local port 1337 as a time response: it ignored the read length, the version, the mode, the stratum, the leap indicator and any request/response correlation, then handed the bytes at offset 40 to the bridge. The bridge only checked that the derived epoch was at least 2026-01-01 before calling settimeofday() and writing the RTC. A host probe against the installed library source accepted a one-byte non-NTP datagram and produced epoch 2085978496. Anyone able to land a UDP datagram during a query window could set a bogus clock, which then feeds JWT issuance, certificate validity and packet timestamps. Replace that path with probeNtpServer(): one exchange per server on a fresh ephemeral socket, closed again on every exit. A reply is accepted only if it is a full 48 bytes, from the address and port queried, NTPv3/v4 mode 4, from a synchronised server (no leap alarm, stratum 1-15), echoing the random transmit timestamp of the request, with an epoch inside a plausible range. Rejected datagrams leave the clock alone and do not end the wait, so an early bogus packet cannot pre-empt the real answer. Era-1 (post-2036) timestamps convert forward instead of wrapping into 1900. The diagnostic now runs the same validated probe, so `get mqtt.ntp.diag` answers the question it is asked — would this server be trusted? — instead of reporting a datagram nothing checked. It also no longer leaves its UDP socket open after the probe, and each server's per-probe result carries the reason it failed ("DNS failed", "unsolicited reply", "server unsynced", ...). The diagnostic still blocks its caller; making it asynchronous is a separate change. The acceptance rules live in NtpValidation.h (pure, host-tested), including the review's one-byte-datagram reproduction. --- MQTT_IMPLEMENTATION.md | 3 +- src/helpers/NtpValidation.h | 141 ++++++++++++++ src/helpers/bridges/MQTTBridge.cpp | 168 ++++++++++++---- src/helpers/bridges/MQTTBridge.h | 20 +- .../test_ntp_validation.cpp | 184 ++++++++++++++++++ 5 files changed, 474 insertions(+), 42 deletions(-) create mode 100644 src/helpers/NtpValidation.h create mode 100644 test/test_ntp_validation/test_ntp_validation.cpp diff --git a/MQTT_IMPLEMENTATION.md b/MQTT_IMPLEMENTATION.md index 9d4d16bc8..56f43569a 100644 --- a/MQTT_IMPLEMENTATION.md +++ b/MQTT_IMPLEMENTATION.md @@ -524,7 +524,7 @@ These settings apply across all MQTT slots: - `get mqtt.neighbors` - Get periodic neighbors publishing setting (on/off; neighbors-enabled builds) - `get mqtt.neighbors.interval` - Get neighbors publish interval in hours (neighbors-enabled builds) - `get mqtt.ntp` - Get effective NTP server hostname -- `get mqtt.ntp.diag` - Probe every configured NTP server for connectivity (does not change the clock; serial console shows each server's reported time, LoRa shows a compact ` ok|fail` list) +- `get mqtt.ntp.diag` - Probe every configured NTP server for connectivity (does not change the clock; serial console shows each server's reported time, or why a probe was rejected — `DNS failed`, `unsolicited reply`, `server unsynced`, ... — and LoRa shows a compact ` ok|fail` list) - `get mqtt.owner` - Get owner public key (serial console only) - `get mqtt.email` - Get owner email address (serial console only) @@ -884,6 +884,7 @@ the radio actually performs in that case. - Automatic time synchronization with NTP servers (required for JWT authentication) - Default primary: `pool.ntp.org`; built-in fallbacks (tried sequentially on failure): `time.google.com`, `time.cloudflare.com`, `time.aws.com`, `time.nist.gov` - Periodic time updates (every hour) on the effective primary only; system time is kept in UTC +- Replies are validated before they are trusted: the datagram must be a full-length NTPv3/v4 server reply from the queried address and port, from a synchronised server (stratum 1-15, no leap alarm), echoing the random transmit timestamp of the request, with a plausible epoch. Anything else is discarded and the clock, the RTC and JWT issuance are left alone - Configure and diagnose with `set mqtt.ntp` / `get mqtt.ntp` / `get mqtt.ntp.diag` — see [MQTT Shared Commands](#mqtt-shared-commands) ### Authentication diff --git a/src/helpers/NtpValidation.h b/src/helpers/NtpValidation.h new file mode 100644 index 000000000..e81510b7f --- /dev/null +++ b/src/helpers/NtpValidation.h @@ -0,0 +1,141 @@ +#pragma once + +#include +#include + +// Client-side NTPv4 request building and response validation. +// +// Pure logic: no Arduino, WiFi or UDP headers, so every rejection case is +// host-testable. The caller owns the socket and supplies the datagram plus +// whether it arrived from the server it asked (see MQTTBridge::probeNtpServer). +// +// This exists because the NTPClient library accepted *any* non-empty datagram +// on its fixed local port as time: it ignored the read length, the mode, the +// stratum, the leap indicator and the request/response correlation, so a +// one-byte packet from anywhere set the clock — which then feeds JWT issuance, +// certificate validity and the RTC. Everything below is the validation that +// path never had. +namespace NtpValidation { + +static const size_t kPacketSize = 48; + +// Seconds between the NTP epoch (1900-01-01) and the Unix epoch (1970-01-01). +static const uint32_t kUnixEpochOffset = 2208988800UL; +// Wrap distance for NTP era 1, which starts 2036-02-07: era-1 seconds count +// from there, so a small NTP seconds field is a *future* time, not a past one. +static const uint32_t kEra1UnixOffset = 2085978496UL; + +enum Reject : uint8_t { + kAccepted = 0, + kShortPacket, // fewer than 48 bytes: not an NTP response at all + kWrongSource, // not from the address/port we queried + kBadVersion, // NTP version outside 3..4 + kBadMode, // not mode 4 (server) + kLeapAlarm, // LI=3: the server itself is unsynchronised + kBadStratum, // 0 (kiss-of-death) or >= 16 (unsynchronised) + kOriginMismatch, // did not echo the transmit timestamp we sent + kZeroTransmit, // no transmit timestamp + kEpochTooEarly, // before the caller's floor + kEpochTooLate, // implausibly far in the future +}; + +// The transmit timestamp we send and the server must echo back in its originate +// field. Random, so an off-path sender cannot answer a query it never saw. +struct Nonce { + uint32_t seconds; + uint32_t fraction; +}; + +struct Result { + Reject reject; + uint32_t epoch; // Unix seconds; only meaningful when reject == kAccepted +}; + +static inline uint32_t readU32(const uint8_t* p) { + return ((uint32_t)p[0] << 24) | ((uint32_t)p[1] << 16) | + ((uint32_t)p[2] << 8) | (uint32_t)p[3]; +} + +static inline void writeU32(uint8_t* p, uint32_t v) { + p[0] = (uint8_t)(v >> 24); + p[1] = (uint8_t)(v >> 16); + p[2] = (uint8_t)(v >> 8); + p[3] = (uint8_t)v; +} + +// LI=0 (no warning), VN=4, Mode=3 (client). The NTPClient request claimed LI=3, +// advertising an alarm condition it had no business asserting. +static inline void buildRequest(uint8_t out[kPacketSize], Nonce nonce) { + memset(out, 0, kPacketSize); + out[0] = 0x23; + out[1] = 0; // stratum: unspecified + out[2] = 6; // poll interval + out[3] = 0xEC; // precision + writeU32(out + 40, nonce.seconds); // transmit timestamp = our nonce + writeU32(out + 44, nonce.fraction); +} + +// Unix time for an NTP seconds field, handling the 2036 era rollover instead of +// wrapping into 1900 the way an unchecked subtraction does. +static inline uint32_t unixFromNtpSeconds(uint32_t ntp_seconds) { + return ntp_seconds >= kUnixEpochOffset ? (ntp_seconds - kUnixEpochOffset) + : (ntp_seconds + kEra1UnixOffset); +} + +// `source_matches` is the caller's check that the datagram came from the +// address and port it queried; it is a parameter rather than a lookup so this +// stays free of socket types. +static inline Result validate(const uint8_t* data, size_t len, bool source_matches, + Nonce nonce, uint32_t min_epoch, uint32_t max_epoch) { + Result r; + r.epoch = 0; + + if (data == nullptr || len < kPacketSize) { r.reject = kShortPacket; return r; } + if (!source_matches) { r.reject = kWrongSource; return r; } + + const uint8_t li = (uint8_t)((data[0] >> 6) & 0x03); + const uint8_t version = (uint8_t)((data[0] >> 3) & 0x07); + const uint8_t mode = (uint8_t)(data[0] & 0x07); + const uint8_t stratum = data[1]; + + if (version < 3 || version > 4) { r.reject = kBadVersion; return r; } + if (mode != 4) { r.reject = kBadMode; return r; } + if (li == 3) { r.reject = kLeapAlarm; return r; } + // Stratum 0 carries a kiss-of-death code (RATE/DENY/RSTR) rather than time; + // 16 and above means the server has no time to give. + if (stratum == 0 || stratum >= 16) { r.reject = kBadStratum; return r; } + + if (readU32(data + 24) != nonce.seconds || + readU32(data + 28) != nonce.fraction) { r.reject = kOriginMismatch; return r; } + + const uint32_t transmit_seconds = readU32(data + 40); + if (transmit_seconds == 0) { r.reject = kZeroTransmit; return r; } + + const uint32_t epoch = unixFromNtpSeconds(transmit_seconds); + if (epoch < min_epoch) { r.reject = kEpochTooEarly; return r; } + if (epoch > max_epoch) { r.reject = kEpochTooLate; return r; } + + r.reject = kAccepted; + r.epoch = epoch; + return r; +} + +// Short enough for a LoRa-bounded diagnostic reply. +static inline const char* rejectReason(Reject reject) { + switch (reject) { + case kAccepted: return "ok"; + case kShortPacket: return "short packet"; + case kWrongSource: return "wrong source"; + case kBadVersion: return "bad version"; + case kBadMode: return "not a server reply"; + case kLeapAlarm: return "server unsynced"; + case kBadStratum: return "bad stratum"; + case kOriginMismatch: return "unsolicited reply"; + case kZeroTransmit: return "no timestamp"; + case kEpochTooEarly: return "time too old"; + case kEpochTooLate: return "time too far ahead"; + default: return "invalid"; + } +} + +} // namespace NtpValidation diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 7fa5d69e0..c2deeaed9 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -2,13 +2,13 @@ #include "MQTTErrorLabels.h" #include "../WifiPowerSavePolicy.h" #include "../MQTTConnectionPolicy.h" +#include "../NtpValidation.h" #include "../MQTTMessageBuilder.h" #include "../MQTTPacketQueuePolicy.h" #include "../MQTTReplyFormat.h" #include "../MQTTRuntimeBufferLifecycle.h" #include "../MQTTTopicRouter.h" #include "../TxtDataHelpers.h" -#include #include #include #include @@ -24,6 +24,7 @@ #ifdef ESP_PLATFORM #include #include +#include #include #include #include @@ -57,6 +58,10 @@ static constexpr size_t kNtpBuiltinFallbackCount = static_assert(MQTTBridge::kMaxNtpServers >= 1 + (int)kNtpBuiltinFallbackCount, "kMaxNtpServers must hold the custom primary plus all built-in fallbacks"); +// Shared so the retry loop can recognise "this name did not resolve" by pointer +// and stop retrying: nothing was sent, so a second attempt changes nothing. +static const char* const kNtpDnsFailedReason = "DNS failed"; + static bool ntpHostnameEquals(const char* a, const char* b) { if (!a || !b) return false; return strcasecmp(a, b) == 0; @@ -674,7 +679,7 @@ MQTTBridge::MQTTBridge(NodePrefs *prefs, MQTTPrefs *obs, mesh::PacketManager *mg _obs(obs), _queue_count(0), _last_status_publish(0), _last_status_retry(0), _status_interval(300000), - _ntp_client(_ntp_udp, effectiveNtpPrimary(obs), 0, 60000), _last_ntp_sync(0), _ntp_synced(false), _ntp_sync_pending(false), _slots_setup_done(false), _max_active_slots(RUNTIME_MQTT_SLOTS), + _last_ntp_sync(0), _ntp_synced(false), _ntp_sync_pending(false), _slots_setup_done(false), _max_active_slots(RUNTIME_MQTT_SLOTS), _ntp_force_requested(false), _ntp_force_done(false), _ntp_force_result(false), _ntp_diag_requested(false), _ntp_diag_done(false), _ntp_diag_count(0), // Default to UTC; setRules() will be called from syncTimeWithNTP when a @@ -4026,6 +4031,106 @@ void MQTTBridge::refreshNTP() { MQTT_DEBUG_PRINTLN("NTP refresh triggered (async SNTP)"); } +// One validated NTP exchange with one named server, on a fresh ephemeral socket. +// +// Replaces NTPClient, which accepted any datagram that arrived on its fixed +// local port 1337 as time — no length, mode, stratum, leap or request/response +// check — and fed it straight into the system clock, the RTC and JWT issuance +// (F07). Everything that makes a reply trustworthy is checked here or in +// NtpValidation; a rejected reply leaves the clock alone and the loop keeps +// listening until the deadline, so an early bogus datagram cannot cancel the +// real answer. +// +// Returns false with *why set to a short reason for the diagnostic. The socket +// is opened and closed inside this call: no listener outlives the probe, and +// each server gets its own local port, so no reply can be credited to the wrong +// name (F08). +bool MQTTBridge::probeNtpServer(const char* server, uint32_t min_epoch, + uint32_t* epoch_out, const char** why) { + if (why) *why = "no reply"; + if (!server || server[0] == '\0') { if (why) *why = "no server"; return false; } + + bool have_expected_ip = false; + IPAddress expected_ip; + #ifdef ESP_PLATFORM + // Authoritative, not advisory. WiFiUDP leaves remote_ip/remote_port at the + // previous destination when a name fails to resolve, so sending anyway asks + // whichever server resolved last and credits its genuine reply to this name. + // Observed on d4: `set mqtt.ntp bogus.invalid` reported success with a correct + // epoch, answered by the pool address left over from boot. + if (!WiFi.hostByName(server, expected_ip)) { + if (why) *why = kNtpDnsFailedReason; + return false; + } + have_expected_ip = true; + #endif + + // Ephemeral local port: nothing to aim unsolicited traffic at between probes. + if (!_ntp_udp.begin(0)) { + if (why) *why = "no socket"; + return false; + } + + NtpValidation::Nonce nonce; + #ifdef ESP_PLATFORM + nonce.seconds = esp_random(); + nonce.fraction = esp_random(); + #else + nonce.seconds = (uint32_t)millis() * 2654435761UL; + nonce.fraction = (uint32_t)random(0, 0x7FFFFFFF); + #endif + + uint8_t packet[NtpValidation::kPacketSize]; + NtpValidation::buildRequest(packet, nonce); + + bool sent; + if (have_expected_ip) { + sent = _ntp_udp.beginPacket(expected_ip, kNtpPort) != 0; + } else { + sent = _ntp_udp.beginPacket(server, kNtpPort) != 0; + } + if (sent) { + _ntp_udp.write(packet, sizeof(packet)); + sent = _ntp_udp.endPacket() != 0; + } + if (!sent) { + _ntp_udp.stop(); + if (why) *why = "send failed"; + return false; + } + + bool accepted = false; + const unsigned long started = millis(); + while (millis() - started < kNtpProbeTimeoutMs) { + delay(10); + int len = _ntp_udp.parsePacket(); + if (len <= 0) continue; + + uint8_t reply[NtpValidation::kPacketSize]; + const int read_len = _ntp_udp.read(reply, sizeof(reply)); + // Discard any tail: WiFiUDP::parsePacket() refuses to read the next datagram + // while an unread one is still buffered, so an oversized reply would + // otherwise block the rest of this wait. + _ntp_udp.flush(); + const bool source_ok = (!have_expected_ip || _ntp_udp.remoteIP() == expected_ip) && + _ntp_udp.remotePort() == kNtpPort; + NtpValidation::Result r = NtpValidation::validate( + reply, read_len > 0 ? (size_t)read_len : 0, source_ok, nonce, + min_epoch, kNtpMaxValidEpoch); + if (r.reject == NtpValidation::kAccepted) { + if (epoch_out) *epoch_out = r.epoch; + if (why) *why = "ok"; + accepted = true; + break; + } + // Keep waiting: a rejected datagram must not consume this server's chance. + if (why) *why = NtpValidation::rejectReason(r.reject); + } + + _ntp_udp.stop(); + return accepted; +} + bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { if (!WiFi.isConnected()) { MQTT_DEBUG_PRINTLN("Cannot sync time - WiFi not connected"); @@ -4058,49 +4163,32 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { bool ntp_ok = false; unsigned long epochTime = 0; - const unsigned long kMinValidEpoch = 1767225600; // 2026-01-01 00:00:00 UTC + const uint32_t kMinValidEpoch = kNtpMinValidEpoch; const char* ntp_server_used = nullptr; - _ntp_client.begin(); const int kMaxNtpRetriesPerServer = 2; for (int s = 0; s < server_count && !ntp_ok; s++) { const char* server = servers[s]; - #ifdef ESP_PLATFORM - // Authoritative, not advisory. NTPClient::sendNTPPacket() ignores what - // beginPacket() returns, and WiFiUDP leaves remote_ip/remote_port at the previous - // destination when a name fails to resolve — so asking an unresolvable host sends - // the request to whichever server resolved last, and that server's genuine reply - // gets credited to this name. Observed on d4: `set mqtt.ntp bogus.invalid` reported - // success with a correct epoch, answered by the pool address left over from boot. - // Skipping is what keeps the credit honest; the name that answered is the name - // recorded. - IPAddress resolved_ip; - if (!WiFi.hostByName(server, resolved_ip)) { - MQTT_DEBUG_PRINTLN("NTP: %s does not resolve — skipping, not attempting a send", server); - continue; - } - #endif - - _ntp_client.setPoolServerName(server); - for (int attempt = 1; attempt <= kMaxNtpRetriesPerServer && !ntp_ok; attempt++) { if (attempt > 1) { MQTT_DEBUG_PRINTLN("NTP retry %d/%d on %s...", attempt, kMaxNtpRetriesPerServer, server); delay(1000); } - if (_ntp_client.forceUpdate()) { - epochTime = _ntp_client.getEpochTime(); - if (epochTime >= kMinValidEpoch) { - ntp_ok = true; - ntp_server_used = server; - } + uint32_t probed_epoch = 0; + const char* why = nullptr; + if (probeNtpServer(server, kMinValidEpoch, &probed_epoch, &why)) { + epochTime = probed_epoch; + ntp_ok = true; + ntp_server_used = server; + } else { + MQTT_DEBUG_PRINTLN("NTP: %s rejected (%s)", server, why ? why : "no reply"); + if (why == kNtpDnsFailedReason) break; // no send happened; try the next server } } } - _ntp_client.end(); - // Fallback: use ESP32 built-in SNTP (configTime) when NTPClient fails + // Fallback: use ESP32 built-in SNTP (configTime) when no server passed validation #ifdef ESP_PLATFORM if (!ntp_ok) { MQTT_DEBUG_PRINTLN("NTP client failed, trying SNTP fallback..."); @@ -4304,15 +4392,18 @@ void MQTTBridge::runNtpDiagProbe() { int count = 0; fillNtpServerList(_obs, servers, count); - _ntp_client.begin(); for (int i = 0; i < count; i++) { - _ntp_client.setPoolServerName(servers[i]); - bool ok = _ntp_client.forceUpdate(); + // Same validated probe the real sync uses, so the diagnostic answers the + // question an operator is actually asking: would this server be trusted? + uint32_t epoch = 0; + const char* why = nullptr; + bool ok = probeNtpServer(servers[i], kNtpMinValidEpoch, &epoch, &why); NtpDiagResult& r = _ntp_diag_results[i]; strncpy(r.server, servers[i], sizeof(r.server) - 1); r.server[sizeof(r.server) - 1] = '\0'; r.ok = ok; - r.epoch = ok ? (uint32_t)_ntp_client.getEpochTime() : 0; + r.epoch = ok ? epoch : 0; + r.why = why; // static literal from NtpValidation/probeNtpServer } _ntp_diag_count = count; } @@ -4346,12 +4437,13 @@ bool MQTTBridge::ntpDiag(char* reply, size_t reply_size, bool verbose) { const NtpDiagResult& r = _ntp_diag_results[i]; if (r.ok) { time_t t = (time_t)r.epoch; - struct tm* tmv = gmtime(&t); + struct tm tmv; + gmtime_r(&t, &tmv); // caller-owned storage: gmtime()'s buffer is shared Serial.printf(" %-20s OK %04d-%02d-%02d %02d:%02d:%02d UTC\r\n", - r.server, tmv->tm_year + 1900, tmv->tm_mon + 1, tmv->tm_mday, - tmv->tm_hour, tmv->tm_min, tmv->tm_sec); + r.server, tmv.tm_year + 1900, tmv.tm_mon + 1, tmv.tm_mday, + tmv.tm_hour, tmv.tm_min, tmv.tm_sec); } else { - Serial.printf(" %-20s FAIL\r\n", r.server); + Serial.printf(" %-20s FAIL %s\r\n", r.server, r.why ? r.why : "no reply"); } } snprintf(reply, reply_size, "> NTP diag: %d/%d OK (see console)", ok_count, _ntp_diag_count); diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 9dd3f29c4..39d169e20 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -4,7 +4,6 @@ #include "helpers/bridges/BridgeBase.h" #include #include -#include #include #include #include "helpers/JWTHelper.h" @@ -92,6 +91,13 @@ public: private: static const size_t AUTH_TOKEN_SIZE = 768; + // NTP acceptance bounds. A reply outside them is rejected outright rather + // than allowed to set the clock, the RTC and every JWT minted afterwards. + static const uint16_t kNtpPort = 123; + static const uint32_t kNtpProbeTimeoutMs = 1000; + static const uint32_t kNtpMinValidEpoch = 1767225600UL; // 2026-01-01 UTC + static const uint32_t kNtpMaxValidEpoch = 4102444800UL; // 2100-01-01 UTC + // Connection slot - each slot holds one MQTT connection struct MQTTSlot { PsychicMqttClient* client; @@ -216,9 +222,9 @@ private: #endif int _queue_count; // Protected by queue operations or mutex - // NTP time sync + // NTP time sync. The socket is opened per probe and closed again (see + // probeNtpServer); nothing listens between syncs. WiFiUDP _ntp_udp; - NTPClient _ntp_client; unsigned long _last_ntp_sync; bool _ntp_synced; bool _ntp_sync_pending; // Flag to trigger NTP sync from loop() instead of event handler @@ -266,6 +272,10 @@ private: char server[64]; bool ok; uint32_t epoch; // server-reported UTC epoch when ok + // Why a probe failed, as a static literal ("DNS failed", "unsolicited + // reply", ...). Previously every failure looked alike, and a name that never + // resolved could be credited with another server's reply. + const char* why; }; NtpDiagResult _ntp_diag_results[kMaxNtpServers]; int _ntp_diag_count; @@ -509,6 +519,10 @@ private: bool isAnySlotConnected(); void refreshNTP(); // Lightweight periodic NTP refresh (non-blocking) void runNtpDiagProbe(); // Probe every server for connectivity; never sets the clock. Core 0 only. + // One validated NTP exchange with one server on a fresh ephemeral socket. + // Core 0 only; never touches the clock. *why receives a static reason literal. + bool probeNtpServer(const char* server, uint32_t min_epoch, + uint32_t* epoch_out, const char** why); // Populates dst_out/std_out with TimeChangeRules for the given IANA or // abbreviation string. Returns false if the string is not recognized // (callers should fall back to UTC). Zero-allocation. diff --git a/test/test_ntp_validation/test_ntp_validation.cpp b/test/test_ntp_validation/test_ntp_validation.cpp new file mode 100644 index 000000000..d2222dd83 --- /dev/null +++ b/test/test_ntp_validation/test_ntp_validation.cpp @@ -0,0 +1,184 @@ +#include "helpers/NtpValidation.h" + +#include + +#include + +using namespace NtpValidation; + +namespace { + +const uint32_t MIN_EPOCH = 1767225600UL; // 2026-01-01, the bridge's floor +const uint32_t MAX_EPOCH = 4102444800UL; // 2100-01-01 +const Nonce NONCE = { 0xA1B2C3D4UL, 0x0F1E2D3CUL }; + +// A well-formed reply to buildRequest(): stratum 2, mode 4, our nonce echoed. +void makeReply(uint8_t out[48], uint32_t unix_epoch = 1789000000UL) { + memset(out, 0, 48); + out[0] = (0 << 6) | (4 << 3) | 4; // LI=0, VN=4, mode=4 (server) + out[1] = 2; // stratum + writeU32(out + 24, NONCE.seconds); // originate = our transmit timestamp + writeU32(out + 28, NONCE.fraction); + writeU32(out + 32, unix_epoch + kUnixEpochOffset); // receive + writeU32(out + 40, unix_epoch + kUnixEpochOffset); // transmit +} + +Result check(const uint8_t* data, size_t len, bool source_matches = true) { + return validate(data, len, source_matches, NONCE, MIN_EPOCH, MAX_EPOCH); +} + +} // namespace + +TEST(NtpValidation, RequestIsAClientPacketCarryingTheNonce) { + uint8_t req[48]; + memset(req, 0xFF, sizeof(req)); + buildRequest(req, NONCE); + + EXPECT_EQ(0u, (req[0] >> 6) & 0x03); // LI = 0, not the library's bogus alarm + EXPECT_EQ(4u, (req[0] >> 3) & 0x07); // version 4 + EXPECT_EQ(3u, req[0] & 0x07); // mode 3 = client + EXPECT_EQ(NONCE.seconds, readU32(req + 40)); + EXPECT_EQ(NONCE.fraction, readU32(req + 44)); +} + +TEST(NtpValidation, ValidReplyIsAccepted) { + uint8_t pkt[48]; + makeReply(pkt, 1789000000UL); + + Result r = check(pkt, sizeof(pkt)); + + EXPECT_EQ(kAccepted, r.reject); + EXPECT_EQ(1789000000UL, r.epoch); +} + +// F07's reproduction: the installed NTPClient accepted a one-byte non-NTP +// datagram and derived epoch 2085978496 from the uninitialised buffer. +TEST(NtpValidation, OneByteNonNtpDatagramIsRejected) { + const uint8_t junk[1] = { 0x00 }; + + Result r = check(junk, sizeof(junk)); + + EXPECT_EQ(kShortPacket, r.reject); + EXPECT_EQ(0u, r.epoch); +} + +TEST(NtpValidation, ShortAndEmptyDatagramsAreRejected) { + uint8_t pkt[48]; + makeReply(pkt); + + for (size_t len = 0; len < 48; len++) { + EXPECT_EQ(kShortPacket, check(pkt, len).reject) << "len " << len; + } + EXPECT_EQ(kShortPacket, check(nullptr, 48).reject); +} + +TEST(NtpValidation, ReplyFromAnotherSourceIsRejected) { + uint8_t pkt[48]; + makeReply(pkt); + + EXPECT_EQ(kWrongSource, check(pkt, sizeof(pkt), /*source_matches=*/false).reject); +} + +// An off-path sender that never saw the query cannot echo the nonce. +TEST(NtpValidation, UnsolicitedReplyIsRejected) { + uint8_t pkt[48]; + makeReply(pkt); + writeU32(pkt + 24, 0); + writeU32(pkt + 28, 0); + + EXPECT_EQ(kOriginMismatch, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + writeU32(pkt + 28, NONCE.fraction ^ 1u); // one bit off is still not ours + EXPECT_EQ(kOriginMismatch, check(pkt, sizeof(pkt)).reject); +} + +TEST(NtpValidation, ClientModeAndWrongVersionAreRejected) { + uint8_t pkt[48]; + + makeReply(pkt); + pkt[0] = (0 << 6) | (4 << 3) | 3; // our own request echoed back + EXPECT_EQ(kBadMode, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + pkt[0] = (0 << 6) | (5 << 3) | 4; // version 5 does not exist + EXPECT_EQ(kBadVersion, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + pkt[0] = (0 << 6) | (3 << 3) | 4; // NTPv3 servers are fine + EXPECT_EQ(kAccepted, check(pkt, sizeof(pkt)).reject); +} + +TEST(NtpValidation, UnsynchronisedServersAreRejected) { + uint8_t pkt[48]; + + makeReply(pkt); + pkt[0] |= (3 << 6); // LI = 3: alarm, clock not set + EXPECT_EQ(kLeapAlarm, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + pkt[1] = 0; // stratum 0: kiss-of-death + EXPECT_EQ(kBadStratum, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + pkt[1] = 16; // unsynchronised + EXPECT_EQ(kBadStratum, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt); + pkt[1] = 15; // last usable stratum + EXPECT_EQ(kAccepted, check(pkt, sizeof(pkt)).reject); +} + +TEST(NtpValidation, MissingTransmitTimestampIsRejected) { + uint8_t pkt[48]; + makeReply(pkt); + writeU32(pkt + 40, 0); + + EXPECT_EQ(kZeroTransmit, check(pkt, sizeof(pkt)).reject); +} + +// The bridge's floor is the only defence against a stale or rolled-back clock, +// and nothing previously stopped an absurd forward jump. +TEST(NtpValidation, ImplausibleTimesAreRejected) { + uint8_t pkt[48]; + + makeReply(pkt, MIN_EPOCH - 1); + EXPECT_EQ(kEpochTooEarly, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt, MIN_EPOCH); + EXPECT_EQ(kAccepted, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt, MAX_EPOCH + 1); + EXPECT_EQ(kEpochTooLate, check(pkt, sizeof(pkt)).reject); + + makeReply(pkt, MAX_EPOCH); + EXPECT_EQ(kAccepted, check(pkt, sizeof(pkt)).reject); +} + +// Era 1 begins 2036-02-07; a naive subtraction turns those seconds into 1900. +TEST(NtpValidation, Era1TimestampsConvertForward) { + EXPECT_EQ(0u, unixFromNtpSeconds(kUnixEpochOffset)); + EXPECT_EQ(2085978496UL, unixFromNtpSeconds(0)); // 2036-02-07 + EXPECT_GT(unixFromNtpSeconds(1000), unixFromNtpSeconds(0xFFFFFFFFu)); + + uint8_t pkt[48]; + makeReply(pkt); + writeU32(pkt + 40, 1000); // 1000 s into era 1 + Result r = check(pkt, sizeof(pkt)); + EXPECT_EQ(kAccepted, r.reject); + EXPECT_EQ(2085979496UL, r.epoch); +} + +TEST(NtpValidation, EveryRejectionHasAShortReason) { + for (int i = 0; i <= (int)kEpochTooLate; i++) { + const char* reason = rejectReason((Reject)i); + ASSERT_NE(nullptr, reason); + EXPECT_GT(strlen(reason), 0u); + EXPECT_LE(strlen(reason), 20u) << "reject " << i; + } +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From 31d9925b05d92e3c802942df3720d4383d0edbe9 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 16:26:54 -0700 Subject: [PATCH 06/19] feat(mqtt): log the Wi-Fi power-save mode read back from the SDK The applied mode had no observable trace on a running node, which is how the CLI and the reconnect path could disagree about what `min` means for as long as they did. Log it at the one place that applies it, reading the value back with esp_wifi_get_ps() rather than printing what was requested. Used to confirm F11 on hardware: with `min` stored, a Heltec V4 now reports "WiFi power save: min (mode=1)" on association, where the old mapping applied WIFI_PS_NONE (mode=0). --- src/helpers/bridges/MQTTBridge.cpp | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index c2deeaed9..0f8e1e33d 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -444,7 +444,15 @@ void MQTTBridge::applyWifiPowerSave() { static_assert((int)WifiPowerSavePolicy::kModeMinModem == (int)WIFI_PS_MIN_MODEM, "wifi_ps_type_t drift"); static_assert((int)WifiPowerSavePolicy::kModeMaxModem == (int)WIFI_PS_MAX_MODEM, "wifi_ps_type_t drift"); if (!_obs) return; - esp_wifi_set_ps((wifi_ps_type_t)WifiPowerSavePolicy::modeFor(_obs->wifi_power_save)); + const uint8_t stored = _obs->wifi_power_save; + esp_wifi_set_ps((wifi_ps_type_t)WifiPowerSavePolicy::modeFor(stored)); + // Read back rather than logging what we asked for: this is the only place the + // mode is observable on a running node, and the setting used to change + // meaning between the CLI and this path. + wifi_ps_type_t applied = WIFI_PS_NONE; + esp_wifi_get_ps(&applied); + MQTT_DEBUG_PRINTLN("WiFi power save: %s (mode=%d)", + WifiPowerSavePolicy::nameFor(stored), (int)applied); #endif } From 415c5d6580b61ac080fb819c8d64a21304fa0d83 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 17:33:46 -0700 Subject: [PATCH 07/19] fix(mqtt): release nothing after a stop the MQTT task never acknowledged (F01) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The timeout fallback did the two things that cannot be done safely to a task that may still be inside mbedTLS or holding esp-mqtt's API mutex: it deleted that task from the loop task, then force-stopped and deleted the clients it owned, then freed the queue and buffers it can reach. `esp_mqtt_client_stop()` waits on the API mutex and the task's stopped event with no bound, so killing its caller strands the next one; a second stop sees the run flag already clear and returns failure without joining. Nothing in that path established quiescence, and `canFlashAfterStop()` could only withhold OTA afterwards. Changes, all of them about who owns what: - `MQTTLifecycle` gains a `StopUnproven` state (appended, so existing values keep their numbering). `StopTimedOut` now leads there and releases NOTHING; it still fires `ota_release` so the OTA barrier aborts. `acceptsNewWork`, `mayRestart` and `isStopInProgress` are false there, `mayTouchOwnedState` is true, and `end()`'s wait loop still terminates. - `begin()` refuses to start while a stop is unproven. A new start was never proof that the previous clients stopped, and it used to clear the dirty latch that withheld OTA. Because a start is now impossible from `StopUnproven`, clearing that latch on an accepted start is sound. - A late acknowledgement is honoured. The task publishes it only after tearing its clients down, so it proves the same thing whenever it arrives; the deadline is an availability policy, not a statement about what the ack means. `pollLateStopAck()` releases the withheld resources and makes the bridge restartable — a slow stop (a blackholed WSS broker can hold the SDK well past the budget) no longer costs a reboot. - The handshake flags become `std::atomic` with release/acquire, and the ack moves into the task trampoline immediately before `vTaskDelete(nullptr)`, gated on a `_teardown_complete` flag the loop sets. Published from inside the loop it proved teardown returned, not that the task had stopped executing — and `volatile` ordered none of it. This is the soak campaign's blocker #20, the one item on its list that can corrupt memory. - The force-stop paths are gone with their only caller: `destroySlotClients()` and `teardownSlot()` no longer take a `force` flag. - `get mqtt.status` reports "previous stop unproven, reboot to recover" instead of a bare "not running", latched so it survives end() clearing the singleton. Two lifecycle tests asserted the old contract and are re-encoded, not deleted: a timed-out stop is no longer `Stopped`-and-released, and "repeated failed stops leave the bridge restartable" becomes "repeated *slow* stops recover on their late ack" plus a new case pinning that a never-acknowledged stop stays unusable for the boot. That availability trade is the point of the change. --- src/helpers/MQTTLifecycle.h | 51 +++++- src/helpers/bridges/MQTTBridge.cpp | 151 +++++++++++------- src/helpers/bridges/MQTTBridge.h | 42 +++-- .../test_mqtt_lifecycle.cpp | 131 +++++++++++++-- 4 files changed, 285 insertions(+), 90 deletions(-) diff --git a/src/helpers/MQTTLifecycle.h b/src/helpers/MQTTLifecycle.h index d85aafa9d..099d2ee76 100644 --- a/src/helpers/MQTTLifecycle.h +++ b/src/helpers/MQTTLifecycle.h @@ -40,6 +40,13 @@ enum class State : uint8_t { Running, StopRequested, Stopping, + // A requested stop passed its deadline without an acknowledgement. The MQTT + // task may still be alive inside mbedTLS or holding the SDK's API mutex, so + // NOTHING it can reach may be released and the bridge may not restart. This + // is deliberately not Stopped: releasing on a stop we cannot prove is the + // reviewed teardown-heap-panic path (F01). Appended so the values above keep + // their numbering. + StopUnproven, }; // Events driven either by the owner (loop task) or by the MQTT task reporting @@ -135,12 +142,17 @@ inline Result apply(State s, Event e) { r.accepted = true; break; case Event::StopAcknowledged: - case Event::StopTimedOut: r.next = State::Stopped; r.effects.release_resources = true; r.effects.ota_release = true; r.accepted = true; break; + case Event::StopTimedOut: + // Unblock the OTA barrier (so it aborts) but release nothing. + r.next = State::StopUnproven; + r.effects.ota_release = true; + r.accepted = true; + break; default: // Duplicate StopRequested is a no-op (idempotent stop). break; @@ -150,16 +162,33 @@ inline Result apply(State s, Event e) { case State::Stopping: switch (e) { case Event::StopAcknowledged: - case Event::StopTimedOut: r.next = State::Stopped; r.effects.release_resources = true; r.effects.ota_release = true; r.accepted = true; break; + case Event::StopTimedOut: + r.next = State::StopUnproven; + r.effects.ota_release = true; + r.accepted = true; + break; default: break; } break; + + case State::StopUnproven: + // A late acknowledgement proves exactly what a timely one proves: the + // task published it only after tearing its clients down. The deadline was + // an availability policy, not a statement about what the ack means — so + // honour it, release, and let the bridge be restartable again. A start + // before that proof is refused (see mayRestart). + if (e == Event::StopAcknowledged) { + r.next = State::Stopped; + r.effects.release_resources = true; + r.accepted = true; + } + break; } return r; } @@ -182,6 +211,11 @@ inline bool mayTouchOwnedState(State s) { return s != State::Stopped; } // A restart (begin()) is safe only from a completed stop. inline bool mayRestart(State s) { return s == State::Stopped; } +// True while a stop has passed its deadline unproven: the owner must keep every +// resource the MQTT task can reach (queue, buffers, clients, its own task) and +// must not restart. Cleared only by a late StopAcknowledged. +inline bool isStopUnproven(State s) { return s == State::StopUnproven; } + inline bool isStopInProgress(State s) { return s == State::StopRequested || s == State::Stopping; } @@ -193,6 +227,7 @@ inline const char* stateName(State s) { case State::Running: return "Running"; case State::StopRequested: return "StopRequested"; case State::Stopping: return "Stopping"; + case State::StopUnproven: return "StopUnproven"; } return "?"; } @@ -264,10 +299,16 @@ class Coordinator { bool isStopInProgress() const { return MQTTLifecycle::isStopInProgress(_state); } - // A restart is safe from a completed stop. A stop that reached Stopped via - // the timeout fallback still allows restart (the bridge is down); only OTA - // flashing is withheld after a dirty stop. + // A restart is safe only from a PROVEN stop. An unproven stop keeps the + // bridge down until the task acknowledges late (or the node reboots): a new + // start is not proof that the previous clients stopped, and starting on top + // of them is what the review refused to approve. Because a start is + // impossible while unproven, clearing the dirty latch on start (below) can no + // longer erase an unproven stop's OTA block. bool mayRestart() const { return MQTTLifecycle::mayRestart(_state); } + // The owner polls this to decide whether it may release/restart, and calls + // onTaskStopped() again if the task acknowledges late. + bool isStopUnproven() const { return MQTTLifecycle::isStopUnproven(_state); } // OTA erase/write is permitted only after a CLEAN stop. A timed-out stop // leaves ownership uncertain, so flashing stays blocked until a clean // start/stop cycle clears the latch. diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 0f8e1e33d..1c5ce4ef9 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -223,6 +223,11 @@ static unsigned long s_wifi_connected_at = 0; // Last WiFi disconnect reason (from ESP-IDF event). Used for get wifi.status diagnostics. static uint8_t s_wifi_disconnect_reason = 0; +// Latched by end() when a stop passes its deadline unacknowledged. end() clears +// the diagnostic singleton, so without this `get mqtt.status` could only say +// "not running" and an operator would have no way to learn that the bridge is +// down for the rest of the boot and why. +static bool s_stop_unproven = false; static unsigned long s_wifi_disconnect_time = 0; #ifdef MQTT_MEMORY_DEBUG @@ -267,7 +272,9 @@ void MQTTBridge::formatMqttStatusReply(char* buf, size_t bufsize, const MQTTPref if (buf == nullptr || bufsize == 0) return; const char* msgs = (obs && obs->mqtt_status_enabled) ? "on" : "off"; if (s_mqtt_bridge_instance == nullptr || !s_mqtt_bridge_instance->_initialized) { - snprintf(buf, bufsize, "> msgs: %s (bridge not running)", msgs); + snprintf(buf, bufsize, "> msgs: %s (bridge %s)", msgs, + s_stop_unproven ? "stopped: previous stop unproven, reboot to recover" + : "not running"); return; } MQTTBridge* b = s_mqtt_bridge_instance; @@ -456,6 +463,8 @@ void MQTTBridge::applyWifiPowerSave() { #endif } +bool MQTTBridge::stopUnprovenLatched() { return s_stop_unproven; } + uint8_t MQTTBridge::getLastWifiDisconnectReason() { return s_wifi_disconnect_reason; } unsigned long MQTTBridge::getLastWifiDisconnectTime() { return s_wifi_disconnect_time; } @@ -871,6 +880,18 @@ void MQTTBridge::begin() { return; } + // A stop that never acknowledged leaves its task possibly still running and + // everything it can reach still owned. Starting on top of that is the failure + // F01 describes: a new start is not proof the previous clients stopped. Check + // once for a late acknowledgement (which releases and clears this), then + // refuse. Recovery is the task finishing, or a reboot. + pollLateStopAck(); + if (!_lifecycle.mayRestart()) { + MQTT_DEBUG_PRINTLN("MQTT Bridge start refused: previous stop unproven (%s) - reboot to recover", + MQTTLifecycle::stateName(_lifecycle.state())); + return; + } + // PSRAM diagnostic - helps debug memory fragmentation on boards with external RAM #ifdef BOARD_HAS_PSRAM { @@ -1067,8 +1088,9 @@ void MQTTBridge::begin() { // Clear the cooperative-stop handshake before the new task starts reading it. // deliverStop() leaves _stop_requested latched true after a stop cycle, so a // restart must reset it or the fresh task would self-terminate immediately. - _stop_requested = false; - _stop_acked = false; + _stop_requested.store(false, std::memory_order_relaxed); + _stop_acked.store(false, std::memory_order_relaxed); + _teardown_complete.store(false, std::memory_order_relaxed); BaseType_t create_result = xTaskCreatePinnedToCore( mqttTask, "MQTTBridge", @@ -1161,14 +1183,14 @@ void MQTTBridge::end() { #ifdef ESP_PLATFORM // Wait (bounded) for the task to acknowledge. tick() synthesizes the timeout - // fallback if the task never acks. Checking the ack first each iteration means - // a stop that completes right as the timeout expires is still treated as clean. + // if the task never acks. Checking the ack first each iteration means a stop + // that completes right as the timeout expires is still treated as clean. while (_lifecycle.isStopInProgress()) { - if (_stop_acked) { - _lifecycle.onTaskStopped(); // StopRequested -> Stopped (clean): releaseResources() + if (_stop_acked.load(std::memory_order_acquire)) { + _lifecycle.onTaskStopped(); // -> Stopped (proven): releaseResources() break; } - _lifecycle.tick(); // may fire StopTimedOut -> Stopped (dirty): releaseResources() + _lifecycle.tick(); // may fire StopTimedOut -> StopUnproven: releases NOTHING if (!_lifecycle.isStopInProgress()) break; vTaskDelay(pdMS_TO_TICKS(20)); } @@ -1182,10 +1204,38 @@ void MQTTBridge::end() { // Timezone is inline class storage (_timezone_storage) — nothing to delete. // The shared JSON document's pools were freed by releaseRuntimeBuffers() above. + // Not running either way, so diagnostics and publishing stop. What differs is + // ownership: after an unproven stop the task may still be alive and every + // resource it can reach is deliberately still allocated (nothing was freed + // above). begin() refuses until the task acknowledges, so _initialized == false + // cannot be turned into a second task over the same state. _initialized = false; _slots_setup_done = false; // Reset so deferred setup runs again on next begin() - MQTT_DEBUG_PRINTLN("MQTT Bridge stopped (%s)", - _lifecycle.stopTimedOut() ? "forced/timeout - OTA blocked" : "clean"); + s_stop_unproven = _lifecycle.isStopUnproven(); + if (_lifecycle.isStopUnproven()) { + MQTT_DEBUG_PRINTLN("MQTT Bridge stop UNPROVEN after %lu ms: task did not acknowledge. " + "Nothing released, restart refused, OTA blocked - reboot to recover.", + (unsigned long)_lifecycle.stopTimeoutMs()); + } else { + MQTT_DEBUG_PRINTLN("MQTT Bridge stopped (clean)"); + } +} + +// A stop whose deadline passed unproven is not necessarily wedged forever: the +// MQTT task may simply have been slow (a blackholed WSS broker can hold +// esp_mqtt_client_stop() well past the budget). Its acknowledgement means the +// same thing whenever it arrives — teardown finished and the task is about to +// stop executing — so honour it late: release the resources that were withheld +// and let the bridge be restartable again. Called from begin() (the moment it +// matters) and from the diagnostics path, both on the loop task. +void MQTTBridge::pollLateStopAck() { + if (!_lifecycle.isStopUnproven()) return; +#ifdef ESP_PLATFORM + if (!_stop_acked.load(std::memory_order_acquire)) return; + MQTT_DEBUG_PRINTLN("MQTT task acknowledged its stop late - releasing withheld resources"); + _lifecycle.onTaskStopped(); // StopUnproven -> Stopped: releaseResources() + s_stop_unproven = false; +#endif } // --------------------------------------------------------------------------- @@ -1203,38 +1253,27 @@ void MQTTBridge::LifecycleOps::startTask() { } void MQTTBridge::LifecycleOps::deliverStop() { - // Clear any stale ack before raising the request (same ordering as the NTP - // handshake: clear the done-flag, then set the request). The MQTT task polls - // _stop_requested at the top of mqttTaskLoop(). - _b->_stop_acked = false; - _b->_stop_requested = true; + // Clear the completion flags before raising the request, so the task cannot + // observe a stale ack from a previous cycle. Release on the request store + // publishes those clears to the MQTT task. + _b->_stop_acked.store(false, std::memory_order_relaxed); + _b->_teardown_complete.store(false, std::memory_order_relaxed); + _b->_stop_requested.store(true, std::memory_order_release); } void MQTTBridge::LifecycleOps::releaseResources() { MQTTBridge* b = _b; #ifdef ESP_PLATFORM - // stopTimedOut() is set before this effect fires (Coordinator::dispatch), so - // it reliably distinguishes a clean ack from the timeout fallback. - const bool dirty = b->_lifecycle.stopTimedOut(); - if (dirty && !b->_stop_acked) { - // Reviewed fallback: the task never acknowledged (likely wedged in mbedTLS). - // Force-kill it and tear down clients here on Core 1 — the pre-cooperative - // behavior — accepting the heap risk. The dirty latch keeps OTA flashing - // blocked (canFlashAfterStop() == false) so firmware is never written after - // this path. - if (b->_mqtt_task_handle != nullptr) { - vTaskDelete(b->_mqtt_task_handle); - } - // force: the task is already gone and the client is presumed wedged, so waiting on a - // DISCONNECTED event that may never arrive would hang this task (the app loop) forever. - for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) b->teardownSlot(i, /*force=*/true); - b->destroySlotClients(/*force=*/true); - } - // Clean path (or a task that acked right at the deadline): the MQTT task - // already disconnected/deleted its clients on Core 0 and self-terminated, so - // we must NOT touch slots here (that would be a cross-core double-delete). - // Just drop our handle reference; FreeRTOS reclaims the self-deleted task's - // dynamically-allocated stack/TCB in the idle task. + // This effect now fires ONLY after an acknowledged stop — timely or late (see + // MQTTLifecycle: StopTimedOut leads to StopUnproven, which releases nothing). + // So there is no force-kill branch here any more, and there must not be one: + // the task published the ack from its trampoline immediately before + // vTaskDelete(nullptr), after destroying its own clients on Core 0. Deleting + // that task from here, or tearing its clients down a second time, was the + // reviewed use-after-free (F01, soak blocker #20). + // + // The MQTT task self-terminates; FreeRTOS reclaims its stack/TCB in the idle + // task. We only drop our handle reference. b->_mqtt_task_handle = nullptr; // Drain and delete the FreeRTOS packet queue (value-copied packets, no @@ -1282,8 +1321,14 @@ void MQTTBridge::mqttTask(void* parameter) { MQTTBridge* bridge = static_cast(parameter); if (bridge) { bridge->mqttTaskLoop(); + // Last act before ceasing to execute: publish the stop acknowledgement, but + // only if the loop actually completed its ordered teardown. An unexpected + // return (mqttTaskLoop() has no other exit) must not tell the owner it is + // safe to free the queue, the buffers and the clients. + if (bridge->_teardown_complete.load(std::memory_order_acquire)) { + bridge->_stop_acked.store(true, std::memory_order_release); + } } - // Task should never return, but if it does, delete itself vTaskDelete(nullptr); } @@ -1371,13 +1416,17 @@ void MQTTBridge::mqttTaskLoop() { // vTaskDelete. Acknowledge LAST so end() only frees the queue/buffers once // this teardown has completed, then self-terminate via the mqttTask() // trampoline (vTaskDelete(nullptr)). - if (_stop_requested) { + if (_stop_requested.load(std::memory_order_acquire)) { MQTT_DEBUG_PRINTLN("MQTT task: cooperative stop - tearing down clients on Core 0"); for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { teardownSlot(i); } destroySlotClients(); - _stop_acked = true; // release semantics: set only after teardown is done + // Record that the ordered teardown finished, but do NOT publish the ack + // here: the owner treats the ack as permission to free everything this + // task can reach, and between this point and vTaskDelete(nullptr) the task + // is still executing. mqttTask() publishes it as its last act. + _teardown_complete.store(true, std::memory_order_release); return; } @@ -1789,17 +1838,11 @@ void MQTTBridge::releaseSlotAuthToken(int index) { slot.last_token_renewal = 0; } -void MQTTBridge::destroySlotClients(bool force) { +void MQTTBridge::destroySlotClients() { for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { MQTTSlot& slot = _slots[i]; if (slot.client != nullptr) { - // force is deliberately NOT gated on connected(). The state it exists for — a client - // that already took its DISCONNECTED callback and is now stuck inside - // esp_mqtt_client_stop() — reports not-connected, so gating skipped the stop exactly - // when it mattered and left the object to be deleted from under a live IDF task. - if (force) { - slot.client->forceStop(); - } else if (slot.client->connected()) { + if (slot.client->connected()) { slot.client->disconnect(); } #ifdef ESP_PLATFORM @@ -2057,18 +2100,12 @@ bool MQTTBridge::setupSlot(int index) { // the client object alive so a subsequent setupSlot() can reuse its mbedTLS // context. This is called both on reconfigure (preset change) and at shutdown; // destruction of the underlying client happens once in destroySlotClients(). -void MQTTBridge::teardownSlot(int index, bool force) { +void MQTTBridge::teardownSlot(int index) { if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return; MQTTSlot& slot = _slots[index]; - // As in destroySlotClients(): force is not gated on connected(), because the wedged - // mid-stop state it exists for already reports not-connected. - if (slot.client && (force || slot.client->connected())) { - if (force) { - slot.client->forceStop(); - } else { - slot.client->disconnect(); - } + if (slot.client && slot.client->connected()) { + slot.client->disconnect(); #ifdef ESP_PLATFORM vTaskDelay(pdMS_TO_TICKS(50)); #else diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 39d169e20..0ec28cccd 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -280,15 +280,22 @@ private: NtpDiagResult _ntp_diag_results[kMaxNtpServers]; int _ntp_diag_count; - // Cooperative-shutdown handshake (Phase 5). The loop task (Core 1) raises + // Cooperative-shutdown handshake. The loop task (Core 1) raises // _stop_requested through the lifecycle Coordinator; the MQTT task (Core 0) // sees it, tears down its own clients on Core 0 (where the mbedTLS contexts - // live), sets _stop_acked LAST, and self-terminates. end() waits for the ack - // before freeing the queue/buffers. Plain volatile matches the existing - // NTP/reconfigure handshake idiom above; replacing all of these with a command - // channel / task notifications is explicitly deferred (see MQTT_OWNERSHIP.md). - volatile bool _stop_requested = false; - volatile bool _stop_acked = false; + // live), records _teardown_complete, and publishes _stop_acked from the task + // trampoline immediately before vTaskDelete(nullptr). end() waits for that ack + // before anything is freed. + // + // std::atomic, not volatile: this is a two-flag release/acquire handshake + // across cores, and the owner acts on it by freeing memory the other task can + // reach. `volatile` orders nothing and was the soak campaign's blocker #20. + // Publishing the ack from the trampoline is what makes it mean "this task is + // about to cease executing" rather than "teardown returned"; _teardown_complete + // gates it so an unexpected return from mqttTaskLoop() cannot claim a clean stop. + std::atomic _stop_requested{false}; + std::atomic _stop_acked{false}; + std::atomic _teardown_complete{false}; // Timezone handling. // _timezone_storage is inline class storage (zero heap) that is reconfigured @@ -467,10 +474,11 @@ private: bool ensureSlotClient(int index); // Allocate this slot's persistent client + callbacks on first use bool ensureSlotAuthToken(int index); // Allocate this slot's JWT token buffer on first token creation void releaseSlotAuthToken(int index);// Free the token buffer (only with the client — see MQTTSlot) - // force=true stops each client without waiting for its DISCONNECTED event. Only the - // dirty-stop fallback passes it: disconnect()'s wait is unbounded, so a client already - // wedged in mbedTLS would block the caller — MyMesh::loop() — indefinitely. - void destroySlotClients(bool force = false); // Delete all persistent clients (shutdown only) + // No force variant: the only caller that ever passed one was the dirty-stop + // fallback, and that fallback is gone (F01). A client whose stop cannot be + // proven is now left alone rather than force-stopped and deleted under a + // possibly-live SDK task. + void destroySlotClients(); // Delete all persistent clients (shutdown only) bool setupSlot(int index); // Configure and connect the slot; false = not activated // Single definition of "this slot holds one of the _max_active_slots positions": // it is enabled and has been through a successful setupSlot(). Startup, the @@ -479,7 +487,7 @@ private: int activatedSlotCount() const; bool canActivateSlot(int index) const; // force as in destroySlotClients(): skip the unbounded wait, dirty-stop path only. - void teardownSlot(int index, bool force = false); // Disconnect the slot's client (keeps the object alive) + void teardownSlot(int index); // Disconnect the slot's client (keeps the object alive) // Reconnect a slot, starting it instead when the client is stopped (reconnect() is a // no-op on a stopped client). See the definition. void reconnectSlotClient(int index); @@ -536,6 +544,9 @@ private: void logMemoryStatus(); void refreshOriginFromPrefs(); void applyWifiPowerSave(); // one mapping, applied on every association + // Honours a stop acknowledgement that arrived after the deadline: releases the + // withheld resources and makes the bridge restartable. Loop task only. + void pollLateStopAck(); // begin()/end()-scoped PSRAM buffers. Each allocation is independent so a // transient heap shortage degrades to the existing stack fallback instead // of making the bridge unusable. @@ -670,6 +681,13 @@ public: * OTA flashing is withheld until a clean start/stop cycle. Mirrors * MQTTLifecycle::mayBeginFlash(); read on the loop task (Core 1). */ bool canFlashAfterStop() const { return _lifecycle.mayBeginFlash(); } + // True when a stop passed its deadline without the MQTT task acknowledging: + // the bridge is down, nothing was released, and it will not restart until the + // task acknowledges late (pollLateStopAck) or the node reboots. + bool isStopUnproven() const { return _lifecycle.isStopUnproven(); } + // Survives end() clearing the diagnostic singleton, so `get mqtt.status` can + // still explain why a stopped bridge will not come back without a reboot. + static bool stopUnprovenLatched(); static unsigned long getWifiConnectedAtMillis(); diff --git a/test/test_mqtt_lifecycle/test_mqtt_lifecycle.cpp b/test/test_mqtt_lifecycle/test_mqtt_lifecycle.cpp index b5dec2f3c..7b3f05e9a 100644 --- a/test/test_mqtt_lifecycle/test_mqtt_lifecycle.cpp +++ b/test/test_mqtt_lifecycle/test_mqtt_lifecycle.cpp @@ -174,9 +174,12 @@ TEST(MQTTLifecycle, RestartAfterStop) { // --- Timeout / fallback ---------------------------------------------------- -// Handoff: "Timeout/fallback behavior when the MQTT task or client does not -// acknowledge." Models the reviewed fallback replacing the abrupt vTaskDelete. -TEST(MQTTLifecycle, StopTimeoutFiresReviewedFallback) { +// F01: a stop that passes its deadline unacknowledged releases NOTHING. The +// MQTT task may still be inside mbedTLS or holding the SDK's API mutex, so the +// queue, buffers, clients and the task itself all stay owned. The OTA barrier +// is still unblocked — so it can abort — but nothing is freed and the bridge +// may not restart. +TEST(MQTTLifecycle, StopTimeoutReleasesNothingAndBlocksRestart) { FakeOps ops; L::Coordinator c(ops, kStopTimeoutMs); bringUpToRunning(c); @@ -191,18 +194,70 @@ TEST(MQTTLifecycle, StopTimeoutFiresReviewedFallback) { EXPECT_EQ(L::State::StopRequested, c.state()); EXPECT_EQ(0, ops.release_calls); - // At the deadline the fallback fires: forced release, dirty OTA signal. ops.now = 1000 + kStopTimeoutMs; c.tick(); - EXPECT_EQ(L::State::Stopped, c.state()); + + EXPECT_EQ(L::State::StopUnproven, c.state()); + EXPECT_TRUE(c.isStopUnproven()); EXPECT_TRUE(c.stopTimedOut()); - EXPECT_EQ(1, ops.release_calls); + EXPECT_EQ(0, ops.release_calls) << "an unproven stop must not release"; EXPECT_EQ(1, ops.stop_complete_calls); EXPECT_FALSE(ops.last_stop_clean); - // A late ack after the fallback does not double-release. + // Everything the task can reach is still owned, and neither a restart nor a + // flash is permitted. A repeated tick does not change that. + EXPECT_TRUE(c.mayTouchOwnedState()); + EXPECT_FALSE(c.mayRestart()); + EXPECT_FALSE(c.mayBeginFlash()); + EXPECT_FALSE(c.acceptsNewWork()); + EXPECT_FALSE(c.isStopInProgress()) << "end()'s wait loop must terminate"; + + ops.now += kStopTimeoutMs * 10; + c.tick(); + EXPECT_EQ(L::State::StopUnproven, c.state()); + EXPECT_EQ(0, ops.release_calls); + + // A start attempt is refused outright: a new start is not proof that the + // previous clients stopped. + EXPECT_FALSE(c.requestStart()); + EXPECT_EQ(L::State::StopUnproven, c.state()); + EXPECT_EQ(1, ops.start_task_calls) << "no second task while unproven"; + EXPECT_TRUE(c.stopTimedOut()) << "a refused start cannot clear the dirty latch"; +} + +// The deadline is an availability policy, not a statement about what an ack +// means: the task publishes it only after tearing its clients down, so a late +// ack is exactly as trustworthy as a timely one. Honouring it releases the +// resources and makes the bridge restartable without a reboot. +TEST(MQTTLifecycle, LateAckRecoversFromAnUnprovenStop) { + FakeOps ops; + L::Coordinator c(ops, kStopTimeoutMs); + bringUpToRunning(c); + + ops.now = 1000; + ASSERT_TRUE(c.requestStop()); + ops.now = 1000 + kStopTimeoutMs; + c.tick(); + ASSERT_EQ(L::State::StopUnproven, c.state()); + ASSERT_EQ(0, ops.release_calls); + + ops.now = 1000 + kStopTimeoutMs * 4; + ASSERT_TRUE(c.onTaskStopped()); + + EXPECT_EQ(L::State::Stopped, c.state()); + EXPECT_EQ(1, ops.release_calls) << "the proof arrived; release now"; + EXPECT_TRUE(c.mayRestart()); + // The OTA barrier already reported dirty and its caller acted on that, so the + // flash gate stays shut until a clean start/stop cycle. + EXPECT_EQ(1, ops.stop_complete_calls); + EXPECT_FALSE(c.mayBeginFlash()); + EXPECT_TRUE(c.stopTimedOut()); + + // Restarting from the proven stop clears the latch, and a second ack is inert. EXPECT_FALSE(c.onTaskStopped()); EXPECT_EQ(1, ops.release_calls); + ASSERT_TRUE(c.requestStart()); + EXPECT_FALSE(c.stopTimedOut()); } TEST(MQTTLifecycle, TickWithoutPendingStopIsNoop) { @@ -371,7 +426,9 @@ TEST(MQTTLifecycle, OtaFlashBlockedUntilCleanStopAcknowledged) { } // Handoff OTA barrier: "MQTT stop times out: OTA aborts safely rather than -// writing under uncertain ownership." +// writing under uncertain ownership." The barrier is still released so the +// caller aborts, but flashing stays shut and — unlike the pre-F01 contract — +// the bridge cannot be restarted to paper over it. TEST(MQTTLifecycle, OtaAbortsWhenStopTimesOut) { FakeOps ops; L::Coordinator c(ops, kStopTimeoutMs); @@ -382,11 +439,16 @@ TEST(MQTTLifecycle, OtaAbortsWhenStopTimesOut) { ops.now = 500 + kStopTimeoutMs; c.tick(); - EXPECT_EQ(L::State::Stopped, c.state()); - EXPECT_FALSE(c.mayBeginFlash()); // dirty stop => flashing withheld - EXPECT_FALSE(ops.last_stop_clean); + EXPECT_EQ(L::State::StopUnproven, c.state()); + EXPECT_EQ(1, ops.stop_complete_calls); // barrier released... + EXPECT_FALSE(ops.last_stop_clean); // ...with "do not flash" + EXPECT_FALSE(c.mayBeginFlash()); + EXPECT_FALSE(c.requestStart()); // and no restart to hide it - // A fresh clean start/stop cycle clears the latch and re-enables flashing. + // Only the task's late acknowledgement makes the bridge usable again, and + // only a clean cycle after that re-enables flashing. + ASSERT_TRUE(c.onTaskStopped()); + EXPECT_FALSE(c.mayBeginFlash()); ASSERT_TRUE(c.requestStart()); EXPECT_FALSE(c.stopTimedOut()); ASSERT_TRUE(c.onTaskStarted()); @@ -415,8 +477,13 @@ TEST(MQTTLifecycle, NoRestartWhileStopInProgress) { } // Handoff OTA barrier: "Repeated failed OTA attempts do not ... leave the -// bridge permanently stopped." -TEST(MQTTLifecycle, RepeatedFailedStopsLeaveBridgeRestartable) { +// bridge permanently stopped." Re-encoded for the F01 contract: what keeps the +// bridge usable across repeated slow stops is the task's acknowledgement, not +// the deadline. A stop that is merely slow recovers every time; a stop that is +// never acknowledged deliberately does NOT, because restarting on top of +// clients that may still be running is the failure this state exists to +// prevent. That is an availability trade, made knowingly. +TEST(MQTTLifecycle, RepeatedSlowStopsRecoverOnTheirLateAck) { FakeOps ops; L::Coordinator c(ops, kStopTimeoutMs); @@ -427,19 +494,51 @@ TEST(MQTTLifecycle, RepeatedFailedStopsLeaveBridgeRestartable) { ops.now += 1000; ASSERT_TRUE(c.requestStop()); ops.now += kStopTimeoutMs; - c.tick(); // times out (dirty) + c.tick(); // deadline passes with no ack + EXPECT_EQ(L::State::StopUnproven, c.state()); + EXPECT_FALSE(c.mayRestart()); // not until the task proves it finished + EXPECT_EQ(attempt, ops.release_calls); + + ops.now += 1000; + ASSERT_TRUE(c.onTaskStopped()); // the slow teardown completes EXPECT_EQ(L::State::Stopped, c.state()); - EXPECT_TRUE(c.mayRestart()); // never permanently stuck + EXPECT_TRUE(c.mayRestart()); + EXPECT_EQ(attempt + 1, ops.release_calls); } EXPECT_EQ(3, ops.start_task_calls); } +// A never-acknowledged stop stays unusable for the rest of the boot: no +// release, no restart, no flash, however long the owner waits or however many +// times it asks. +TEST(MQTTLifecycle, NeverAcknowledgedStopStaysUnproven) { + FakeOps ops; + L::Coordinator c(ops, kStopTimeoutMs); + bringUpToRunning(c); + + ASSERT_TRUE(c.requestStop()); + ops.now += kStopTimeoutMs; + c.tick(); + + for (int i = 0; i < 5; ++i) { + ops.now += 60'000; + c.tick(); + EXPECT_FALSE(c.requestStart()); + EXPECT_FALSE(c.requestStop()); + EXPECT_EQ(L::State::StopUnproven, c.state()); + } + EXPECT_EQ(0, ops.release_calls); + EXPECT_FALSE(c.mayBeginFlash()); + EXPECT_TRUE(c.mayTouchOwnedState()); +} + // --- Diagnostics ----------------------------------------------------------- TEST(MQTTLifecycle, StateAndEventNamesAreStable) { EXPECT_STREQ("Stopped", L::stateName(L::State::Stopped)); EXPECT_STREQ("Running", L::stateName(L::State::Running)); EXPECT_STREQ("StopRequested", L::stateName(L::State::StopRequested)); + EXPECT_STREQ("StopUnproven", L::stateName(L::State::StopUnproven)); EXPECT_STREQ("StartRequested", L::eventName(L::Event::StartRequested)); EXPECT_STREQ("StopTimedOut", L::eventName(L::Event::StopTimedOut)); } From d38f5c8b9a4024898fcd5d2fab6a494b6d894ec9 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 17:35:49 -0700 Subject: [PATCH 08/19] feat(mqtt): effective-config value type and the recreate decision (F02/F03) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The decision half of the client-configuration fix, as a pure header so every transition is a host test rather than a hardware run. `MqttEffectiveConfig` is the complete owned description of what a slot's client should be configured with — URI (its own copy, because `slot.broker_uri` is rewritten in place), transport, trust policy, auth mode, credential pointers, buffer size, keepalive. Two things are deliberate: - the transport is derived from the URI scheme, and the trust policy is normalised against it: an unencrypted transport verifies nothing, whatever certificate material was requested, so a plaintext endpoint can never look like it retained a verified policy; - absent credentials are represented as nullptr and written as "", never omitted. IDF's `esp_mqtt_set_if_config()` treats NULL as "leave unchanged", so a cleared wrapper pointer cannot erase an SDK-held credential, while an empty string overwrites it and leaves the CONNECT's username flag clear (verified on an ESP32-S3 against a local broker on IDF 4.4). `mqttConfigRecreateDecision()` says whether the existing client can be reconfigured in place. Reuse covers every credential and auth-mode change and any endpoint move within one scheme — the cases that matter for reconnect and token renewal, where a client create/destroy cycle is the fork's documented internal-heap fragmentation driver. Recreation is reserved for the three fields that cannot be overwritten safely: a transport (scheme) change, a trust-policy or CA-certificate change, and growth beyond the allocated buffer capacity, which IDF 4.4 fixes at client init. Client certificates are excluded on purpose: `setClientCertificate()` has no caller in the firmware, so modelling mutual TLS here would be untested configuration surface. Noted in the header. Nothing consumes this yet; the bridge is migrated onto it after the result propagation and generation-guard steps, which it depends on. --- src/helpers/MQTTEffectiveConfig.h | 213 ++++++++++++++++++ .../test_mqtt_effective_config.cpp | 203 +++++++++++++++++ 2 files changed, 416 insertions(+) create mode 100644 src/helpers/MQTTEffectiveConfig.h create mode 100644 test/test_mqtt_effective_config/test_mqtt_effective_config.cpp diff --git a/src/helpers/MQTTEffectiveConfig.h b/src/helpers/MQTTEffectiveConfig.h new file mode 100644 index 000000000..9408d5245 --- /dev/null +++ b/src/helpers/MQTTEffectiveConfig.h @@ -0,0 +1,213 @@ +#pragma once + +#include +#include + +// The complete, owned description of what a slot's MQTT client should be +// configured with, plus the decision of whether the existing SDK client can be +// reconfigured in place or has to be recreated. +// +// Pure logic: no Arduino, esp-mqtt or PsychicMqttClient dependency, so every +// transition in the table below is exercised on the host +// (test/test_mqtt_effective_config). +// +// Why this exists (F02/F03). The bridge used to apply configuration field by +// field, skipping the cleanup of stale fields whenever +// `slot.initial_connect_done` was false — which `teardownSlot()` had just +// cleared, so normal live reconfiguration always skipped it. On hardware that +// sent the previous broker's JWT username in the CONNECT to a newly configured +// anonymous endpoint. Two rules fix it: +// +// 1. Every field is written on every apply. "Absent" is a value that gets +// written (the empty string), never an omission — IDF's +// `esp_mqtt_set_if_config()` treats NULL as "leave unchanged", so a +// cleared wrapper pointer cannot erase an SDK-held credential, while an +// empty string both overwrites it and leaves the CONNECT's username flag +// clear (verified on an ESP32-S3 against a local broker, IDF 4.4). +// 2. Where a field cannot be overwritten safely, the client is recreated. +// That is the exception, not the rule: esp-mqtt's stop/start cycle is the +// fork's documented internal-heap fragmentation driver, so recreation must +// never happen on the reconnect or token-renewal path. + +// Matches MQTTSlot::broker_uri so an effective config can hold its own copy. +#define MQTT_EFFECTIVE_URI_MAX 128 + +enum class MqttTransport : uint8_t { + Unknown = 0, + Tcp, // mqtt:// + Tls, // mqtts:// + Ws, // ws:// + Wss, // wss:// +}; + +enum class MqttTrust : uint8_t { + Plaintext = 0, // unencrypted transport: no server verification exists + Bundle, // shared CA bundle attach callback + PemCert, // one specific CA certificate +}; + +enum class MqttAuth : uint8_t { + None = 0, + UserPass, + Jwt, +}; + +struct MqttEffectiveConfig { + char uri[MQTT_EFFECTIVE_URI_MAX] = {0}; + MqttTransport transport = MqttTransport::Unknown; + MqttTrust trust = MqttTrust::Plaintext; + MqttAuth auth = MqttAuth::None; + // Borrowed pointers with a lifetime at least as long as the client's: preset + // certificates live in flash, credentials in the slot/bridge storage. + const char* pem = nullptr; + const char* username = nullptr; // nullptr == absent, written as "" + const char* password = nullptr; + uint16_t buffer_size = 0; + uint16_t keepalive = 0; + bool valid = false; // false until successfully built +}; + +// Client certificates are deliberately absent: `setClientCertificate()` has no +// caller in the firmware (no broker preset uses mutual TLS), so modelling it +// here would be untested configuration surface. Adding mutual TLS means adding +// it to this struct and to the recreate decision below. + +static inline MqttTransport mqttTransportFromUri(const char* uri) { + if (uri == nullptr) return MqttTransport::Unknown; + if (strncmp(uri, "mqtts://", 8) == 0) return MqttTransport::Tls; + if (strncmp(uri, "mqtt://", 7) == 0) return MqttTransport::Tcp; + if (strncmp(uri, "wss://", 6) == 0) return MqttTransport::Wss; + if (strncmp(uri, "ws://", 5) == 0) return MqttTransport::Ws; + return MqttTransport::Unknown; +} + +static inline bool mqttTransportIsEncrypted(MqttTransport t) { + return t == MqttTransport::Tls || t == MqttTransport::Wss; +} + +static inline const char* mqttTransportName(MqttTransport t) { + switch (t) { + case MqttTransport::Tcp: return "mqtt"; + case MqttTransport::Tls: return "mqtts"; + case MqttTransport::Ws: return "ws"; + case MqttTransport::Wss: return "wss"; + default: return "?"; + } +} + +// A credential the SDK must be told to forget is written as "" rather than +// left NULL. See rule 1 above. +static inline const char* mqttFieldOrEmpty(const char* v) { return v ? v : ""; } + +// Builds an effective config, deriving the transport from the URI and +// normalising the trust policy against it: an unencrypted transport verifies +// nothing, whatever certificate material was requested, so recording anything +// else would make a plaintext endpoint look like a trust change away from a +// verified one (and vice versa). Returns false for an empty or unrecognised +// URI, leaving *out invalid. +static inline bool mqttBuildEffectiveConfig(const char* uri, + MqttAuth auth, + const char* username, + const char* password, + MqttTrust requested_trust, + const char* pem, + uint16_t buffer_size, + uint16_t keepalive, + MqttEffectiveConfig* out) { + if (out == nullptr) return false; + *out = MqttEffectiveConfig(); + if (uri == nullptr || uri[0] == '\0') return false; + if (strlen(uri) >= MQTT_EFFECTIVE_URI_MAX) return false; + + const MqttTransport transport = mqttTransportFromUri(uri); + if (transport == MqttTransport::Unknown) return false; + + strncpy(out->uri, uri, MQTT_EFFECTIVE_URI_MAX - 1); + out->uri[MQTT_EFFECTIVE_URI_MAX - 1] = '\0'; + out->transport = transport; + out->auth = auth; + out->username = username; + out->password = password; + out->buffer_size = buffer_size; + out->keepalive = keepalive; + + if (!mqttTransportIsEncrypted(transport)) { + out->trust = MqttTrust::Plaintext; + out->pem = nullptr; + } else if (requested_trust == MqttTrust::PemCert && pem != nullptr) { + out->trust = MqttTrust::PemCert; + out->pem = pem; + } else if (requested_trust == MqttTrust::Bundle) { + out->trust = MqttTrust::Bundle; + } else { + // Encrypted transport with no usable trust material. Recorded as Plaintext + // trust so it is never confused with a verified policy; whether to connect + // at all is the caller's decision. + out->trust = MqttTrust::Plaintext; + } + + out->valid = true; + return true; +} + +struct MqttRecreateDecision { + bool recreate = false; + const char* reason = "reuse"; // static literal, for logs and tests +}; + +// Whether the SDK client that `applied` was written to can be reconfigured in +// place to reach `desired`. +// +// transport (scheme) change -> recreate. One `wss`->`mqtt` transition was +// observed working by reuse on hardware, but that proves one direction +// once, not that no websocket transport state survives the switch; the +// retained-`frame_state` bug class is real and unfixed upstream even in +// IDF 5.3, and this transition only happens when an operator changes the +// endpoint. +// trust change -> recreate. `cert_pem` cannot be cleared by +// writing "" (an empty PEM is a parse failure, not "no certificate"), and +// the bundle attach is a function pointer whose set_config semantics are +// not established on this build. Verification policy is the one field +// where a stale value silently weakens security. +// capacity growth -> recreate. IDF 4.4 allocates the MQTT buffers +// in `esp_mqtt_client_init()` and `esp_mqtt_set_config()` does not resize +// them; the wrapper's own reassembly buffer is likewise allocated once. +// everything else -> reuse, including every credential and +// auth-mode change, because those are rewritten unconditionally. +static inline MqttRecreateDecision mqttConfigRecreateDecision( + const MqttEffectiveConfig& applied, + const MqttEffectiveConfig& desired, + uint16_t allocated_buffer_size) { + MqttRecreateDecision d; + if (!desired.valid) { + d.recreate = false; + d.reason = "invalid-desired"; + return d; + } + if (!applied.valid) { + // Nothing applied yet: a fresh client needs configuring, not recreating. + d.reason = "first-apply"; + return d; + } + if (applied.transport != desired.transport) { + d.recreate = true; + d.reason = "transport-change"; + return d; + } + if (applied.trust != desired.trust) { + d.recreate = true; + d.reason = "trust-change"; + return d; + } + if (desired.trust == MqttTrust::PemCert && applied.pem != desired.pem) { + d.recreate = true; + d.reason = "ca-cert-change"; + return d; + } + if (desired.buffer_size > allocated_buffer_size) { + d.recreate = true; + d.reason = "buffer-growth"; + return d; + } + return d; +} diff --git a/test/test_mqtt_effective_config/test_mqtt_effective_config.cpp b/test/test_mqtt_effective_config/test_mqtt_effective_config.cpp new file mode 100644 index 000000000..70eadb007 --- /dev/null +++ b/test/test_mqtt_effective_config/test_mqtt_effective_config.cpp @@ -0,0 +1,203 @@ +#include "helpers/MQTTEffectiveConfig.h" + +#include + +#include + +namespace { + +const char kPemA[] = "-----BEGIN CERTIFICATE-----A"; +const char kPemB[] = "-----BEGIN CERTIFICATE-----B"; +const char kJwtUser[] = "v1_CC5D3CFD9C4C7B84"; +const char kToken[] = "eyJhbGciOi..."; + +MqttEffectiveConfig build(const char* uri, + MqttAuth auth = MqttAuth::None, + const char* user = nullptr, + const char* pass = nullptr, + MqttTrust trust = MqttTrust::Plaintext, + const char* pem = nullptr, + uint16_t buffer = 896) { + MqttEffectiveConfig c; + mqttBuildEffectiveConfig(uri, auth, user, pass, trust, pem, buffer, 75, &c); + return c; +} + +MqttRecreateDecision decide(const MqttEffectiveConfig& applied, + const MqttEffectiveConfig& desired, + uint16_t allocated = 896) { + return mqttConfigRecreateDecision(applied, desired, allocated); +} + +} // namespace + +TEST(MqttEffectiveConfig, TransportComesFromTheUriScheme) { + EXPECT_EQ(MqttTransport::Tcp, mqttTransportFromUri("mqtt://broker:1883")); + EXPECT_EQ(MqttTransport::Tls, mqttTransportFromUri("mqtts://broker:8883")); + EXPECT_EQ(MqttTransport::Ws, mqttTransportFromUri("ws://broker/mqtt")); + EXPECT_EQ(MqttTransport::Wss, mqttTransportFromUri("wss://broker:443/mqtt")); + EXPECT_EQ(MqttTransport::Unknown, mqttTransportFromUri("broker:1883")); + EXPECT_EQ(MqttTransport::Unknown, mqttTransportFromUri("")); + EXPECT_EQ(MqttTransport::Unknown, mqttTransportFromUri(nullptr)); + + EXPECT_TRUE(mqttTransportIsEncrypted(MqttTransport::Tls)); + EXPECT_TRUE(mqttTransportIsEncrypted(MqttTransport::Wss)); + EXPECT_FALSE(mqttTransportIsEncrypted(MqttTransport::Tcp)); + EXPECT_FALSE(mqttTransportIsEncrypted(MqttTransport::Ws)); +} + +TEST(MqttEffectiveConfig, BuildRejectsUnusableUris) { + MqttEffectiveConfig c; + EXPECT_FALSE(mqttBuildEffectiveConfig("", MqttAuth::None, nullptr, nullptr, + MqttTrust::Plaintext, nullptr, 896, 75, &c)); + EXPECT_FALSE(c.valid); + EXPECT_FALSE(mqttBuildEffectiveConfig(nullptr, MqttAuth::None, nullptr, nullptr, + MqttTrust::Plaintext, nullptr, 896, 75, &c)); + EXPECT_FALSE(mqttBuildEffectiveConfig("broker:1883", MqttAuth::None, nullptr, nullptr, + MqttTrust::Plaintext, nullptr, 896, 75, &c)); + + char too_long[MQTT_EFFECTIVE_URI_MAX + 16]; + memset(too_long, 'x', sizeof(too_long)); + memcpy(too_long, "mqtt://", 7); + too_long[sizeof(too_long) - 1] = '\0'; + EXPECT_FALSE(mqttBuildEffectiveConfig(too_long, MqttAuth::None, nullptr, nullptr, + MqttTrust::Plaintext, nullptr, 896, 75, &c)); +} + +TEST(MqttEffectiveConfig, BuildOwnsItsUriCopy) { + char uri[64]; + strcpy(uri, "mqtt://192.168.50.231:1883"); + MqttEffectiveConfig c = build(uri); + ASSERT_TRUE(c.valid); + + strcpy(uri, "mqtt://other:1883"); // slot.broker_uri is rewritten in place + EXPECT_STREQ("mqtt://192.168.50.231:1883", c.uri); +} + +// An unencrypted transport verifies nothing, whatever certificate material was +// requested. Recording anything else would make a plaintext endpoint look like +// it kept a verified policy. +TEST(MqttEffectiveConfig, TrustIsNormalisedAgainstTheTransport) { + MqttEffectiveConfig plain = build("mqtt://broker:1883", MqttAuth::None, nullptr, nullptr, + MqttTrust::Bundle, kPemA); + EXPECT_EQ(MqttTrust::Plaintext, plain.trust); + EXPECT_EQ(nullptr, plain.pem); + + MqttEffectiveConfig bundle = build("wss://broker:443/mqtt", MqttAuth::Jwt, kJwtUser, kToken, + MqttTrust::Bundle, nullptr); + EXPECT_EQ(MqttTrust::Bundle, bundle.trust); + + MqttEffectiveConfig pem = build("mqtts://broker:8883", MqttAuth::UserPass, "u", "p", + MqttTrust::PemCert, kPemA); + EXPECT_EQ(MqttTrust::PemCert, pem.trust); + EXPECT_EQ(kPemA, pem.pem); + + // Encrypted transport with no usable material is not a verified policy. + MqttEffectiveConfig none = build("mqtts://broker:8883", MqttAuth::None, nullptr, nullptr, + MqttTrust::PemCert, nullptr); + EXPECT_EQ(MqttTrust::Plaintext, none.trust); + EXPECT_EQ(nullptr, none.pem); +} + +// The six F02 transitions from the review, plus the one reproduced on hardware. +// None of them needs a new client: credentials are rewritten unconditionally. +TEST(MqttEffectiveConfig, CredentialAndAuthChangesReuseTheClient) { + const MqttEffectiveConfig jwt = build("wss://broker:443/mqtt", MqttAuth::Jwt, kJwtUser, kToken, + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig anon = build("wss://broker:443/mqtt", MqttAuth::None, nullptr, nullptr, + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig userpass = build("wss://broker:443/mqtt", MqttAuth::UserPass, "u", "p", + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig renewed = build("wss://broker:443/mqtt", MqttAuth::Jwt, kJwtUser, + "eyJhbGciOi...new", MqttTrust::Bundle, nullptr); + + EXPECT_FALSE(decide(jwt, anon).recreate); // JWT -> anonymous + EXPECT_FALSE(decide(userpass, anon).recreate); // user/pass -> anonymous + EXPECT_FALSE(decide(anon, jwt).recreate); // none -> configured + EXPECT_FALSE(decide(userpass, jwt).recreate); // user/pass -> JWT + EXPECT_FALSE(decide(jwt, renewed).recreate); // token renewal + EXPECT_FALSE(decide(jwt, jwt).recreate); // ordinary reconnect + EXPECT_STREQ("reuse", decide(jwt, jwt).reason); +} + +// Host/port/path within one scheme is an endpoint move, not a structural one. +TEST(MqttEffectiveConfig, EndpointMoveWithinOneSchemeReusesTheClient) { + const MqttEffectiveConfig a = build("mqtt://192.168.50.231:1883"); + const MqttEffectiveConfig b = build("mqtt://192.168.50.9:1884"); + EXPECT_FALSE(decide(a, b).recreate); + + const MqttEffectiveConfig wss_a = build("wss://a.example:443/mqtt", MqttAuth::Jwt, kJwtUser, + kToken, MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig wss_b = build("wss://b.example:443/other", MqttAuth::Jwt, kJwtUser, + kToken, MqttTrust::Bundle, nullptr); + EXPECT_FALSE(decide(wss_a, wss_b).recreate); +} + +TEST(MqttEffectiveConfig, TransportChangeForcesRecreate) { + const MqttEffectiveConfig wss = build("wss://broker:443/mqtt", MqttAuth::Jwt, kJwtUser, kToken, + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig tcp = build("mqtt://192.168.50.231:1883"); + const MqttEffectiveConfig tls = build("mqtts://broker:8883", MqttAuth::UserPass, "u", "p", + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig ws = build("ws://broker/mqtt"); + + EXPECT_TRUE(decide(wss, tcp).recreate); + EXPECT_STREQ("transport-change", decide(wss, tcp).reason); + EXPECT_TRUE(decide(tcp, wss).recreate); + EXPECT_TRUE(decide(wss, tls).recreate); // both encrypted, still a scheme change + EXPECT_TRUE(decide(tcp, ws).recreate); // both plaintext, still a scheme change +} + +TEST(MqttEffectiveConfig, TrustChangeForcesRecreate) { + const MqttEffectiveConfig bundle = build("mqtts://broker:8883", MqttAuth::None, nullptr, nullptr, + MqttTrust::Bundle, nullptr); + const MqttEffectiveConfig pem_a = build("mqtts://broker:8883", MqttAuth::None, nullptr, nullptr, + MqttTrust::PemCert, kPemA); + const MqttEffectiveConfig pem_b = build("mqtts://broker:8883", MqttAuth::None, nullptr, nullptr, + MqttTrust::PemCert, kPemB); + + EXPECT_TRUE(decide(bundle, pem_a).recreate); + EXPECT_STREQ("trust-change", decide(bundle, pem_a).reason); + EXPECT_TRUE(decide(pem_a, bundle).recreate); + EXPECT_TRUE(decide(pem_a, pem_b).recreate); + EXPECT_STREQ("ca-cert-change", decide(pem_a, pem_b).reason); + EXPECT_FALSE(decide(pem_a, pem_a).recreate); +} + +// IDF 4.4 allocates the MQTT buffers at client init and does not resize them, +// and the wrapper's reassembly buffer is allocated once for the client's life. +TEST(MqttEffectiveConfig, BufferGrowthForcesRecreateButShrinkDoesNot) { + const MqttEffectiveConfig small = build("mqtt://broker:1883", MqttAuth::None, nullptr, nullptr, + MqttTrust::Plaintext, nullptr, 512); + const MqttEffectiveConfig large = build("mqtt://broker:1883", MqttAuth::Jwt, kJwtUser, kToken, + MqttTrust::Plaintext, nullptr, 896); + + EXPECT_TRUE(decide(small, large, /*allocated=*/512).recreate); + EXPECT_STREQ("buffer-growth", decide(small, large, 512).reason); + EXPECT_FALSE(decide(small, large, /*allocated=*/896).recreate) + << "a client that already owns the capacity does not need recreating"; + EXPECT_FALSE(decide(large, small, /*allocated=*/896).recreate); +} + +TEST(MqttEffectiveConfig, FirstApplyAndInvalidDesiredNeverRecreate) { + const MqttEffectiveConfig unset; + const MqttEffectiveConfig wss = build("wss://broker:443/mqtt", MqttAuth::Jwt, kJwtUser, kToken, + MqttTrust::Bundle, nullptr); + EXPECT_FALSE(unset.valid); + EXPECT_FALSE(decide(unset, wss).recreate); + EXPECT_STREQ("first-apply", decide(unset, wss).reason); + + EXPECT_FALSE(decide(wss, unset).recreate); + EXPECT_STREQ("invalid-desired", decide(wss, unset).reason); +} + +// Rule 1: absent is a value that gets written, never an omission. +TEST(MqttEffectiveConfig, AbsentFieldsAreWrittenAsEmptyStrings) { + EXPECT_STREQ("", mqttFieldOrEmpty(nullptr)); + EXPECT_STREQ("alice", mqttFieldOrEmpty("alice")); +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From 0d391cea82012152468c793fa0c11aa4be05853b Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 17:36:46 -0700 Subject: [PATCH 09/19] fix(mqtt): size every client's buffers for a JWT CONNECT (F03) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Non-PSRAM boards allocated 512-byte MQTT buffers for non-JWT slots, so the desired buffer size was a per-slot variable while the allocated size was fixed at `esp_mqtt_client_init()`: IDF 4.4 does not resize those buffers in `esp_mqtt_set_config()`, and the wrapper's own reassembly buffer is allocated once for the client's lifetime. A slot reconfigured from non-JWT to JWT therefore kept 512-byte buffers, and a valid JWT CONNECT (frame plus a 768-byte token) could not fit — with no error naming the cause. Stopping and starting the same handle could not change the capacity either. Give every client 896 bytes on every board. The cost is 384 bytes per client on a non-PSRAM board, which caps at 2 active slots, against a TLS handshake that needs 16 KB of contiguous internal DRAM. In exchange the capacity transition stops existing, so the reconfigure path never needs to recreate a client to grow its buffers. --- src/helpers/bridges/MQTTBridge.cpp | 24 ++++++++++++++++-------- 1 file changed, 16 insertions(+), 8 deletions(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 1c5ce4ef9..8c0ee0584 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -4674,15 +4674,23 @@ void MQTTBridge::optimizeMqttClientConfig(PsychicMqttClient* client, bool needs_ // preserving at-least-once delivery while capping duplicates at one. client->setMessageRetransmitTimeout(15000); - // Buffer sizing: 896 is the minimum safe size for JWT clients (CONNECT + 768-byte JWT). - // On PSRAM boards, use a uniform size to reduce fragmentation from mixed allocations. - // On non-PSRAM boards, use smaller buffers for non-JWT slots to reduce heap usage and - // leave smaller holes during teardown/recreate cycles. -#if defined(BOARD_HAS_PSRAM) + // Buffer sizing: 896 is the minimum safe size for a JWT CONNECT (frame plus a + // 768-byte token). Every client gets it, on every board. + // + // Non-PSRAM boards used to get 512 for non-JWT slots, which made the *desired* + // size a per-slot variable while the *allocated* size was fixed at client init + // — IDF 4.4 allocates the MQTT buffers in esp_mqtt_client_init() and + // esp_mqtt_set_config() does not resize them, and the wrapper's own reassembly + // buffer is likewise allocated once (F03). A slot reconfigured from non-JWT to + // JWT therefore kept 512-byte buffers and its valid CONNECT could not fit, + // with no error that named the cause. Sizing every client for the largest + // CONNECT it might ever have to send removes the transition entirely. + // + // The cost is 384 bytes per client on a non-PSRAM board (at most 2 active + // slots there), against a handshake that needs 16 KB of *contiguous* internal + // DRAM — noise, and it buys the removal of a recreate case. static const int MQTT_CLIENT_BUFFER_SIZE = 896; -#else - const int MQTT_CLIENT_BUFFER_SIZE = needs_large_buffer ? 896 : 512; -#endif + (void)needs_large_buffer; // kept: callers still express the intent client->setBufferSize(MQTT_CLIENT_BUFFER_SIZE); From 6d1f2be1f98448c83effe16e80cbcee5700d9f45 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 17:40:45 -0700 Subject: [PATCH 10/19] fix(mqtt): typed results for client operations, and stop advancing state on failure (F06) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `connect()`, `reconnect()`, `disconnect()`, `softDisconnect()` and `forceStop()` all returned void, so every caller in the bridge treated "asked" as "done": - `setupSlot()` marked a slot activated after `connect()` whatever happened. A failed `esp_mqtt_client_start()` therefore consumed one of the scarce active-slot positions, handed the slot to a reconnect ladder that is gated on activation, and was never retried by the deferred-setup path. - `reconnect()` explicitly proceeded after `esp_mqtt_set_config()` failed, reconnecting on the previous configuration — the renewed token in the buffer, the old one on the wire. - the renewal path recorded the new expiry before the bounce succeeded, so a failed bounce left the live session on the old credential with the next renewal not due for a whole token lifetime. - `softDisconnect()` logged its timeout and told its caller nothing. - `disconnect()` waited for the DISCONNECTED event with no bound, on the very task whose stop acknowledgement the shutdown waits for. Now every one of them returns `esp_err_t`, a failed configuration transaction aborts rather than starting or reconnecting on a half-updated config, and `disconnect()`'s wait is bounded (it still stops the client, and reports ESP_ERR_TIMEOUT when the event never arrived). Bridge consequences: - a failed start leaves the slot unactivated, so the existing deferred-setup retry revisits it and it holds no active-slot position; - a failed renewal bounce re-arms the renewal instead of recording it, so the next maintenance pass retries; - a reconnect that fails *locally* rolls back the backoff advance made for it. The ladder and the breaker bound broker and network faults; an uninitialised client or an uncommitted config transaction is neither, and inflating the ladder for it was how a local fault could trip a breaker meant for a broker. --- .../src/PsychicMqttClient.cpp | 133 +++++++++++------- lib/PsychicMqttClient/src/PsychicMqttClient.h | 47 +++++-- src/helpers/bridges/MQTTBridge.cpp | 78 ++++++++-- src/helpers/bridges/MQTTBridge.h | 5 +- 4 files changed, 194 insertions(+), 69 deletions(-) diff --git a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp index ba1dc5f19..cec11177a 100644 --- a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp +++ b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp @@ -371,20 +371,20 @@ bool PsychicMqttClient::connected() return _connected; } -void PsychicMqttClient::connect() +esp_err_t PsychicMqttClient::connect() { #if ESP_IDF_VERSION_MAJOR == 5 if (_mqtt_cfg.broker.address.uri == nullptr) { ESP_LOGE(TAG, "MQTT URI not set."); - return; + return ESP_ERR_INVALID_STATE; } int desired_buffer = _mqtt_cfg.buffer.size > 0 ? _mqtt_cfg.buffer.size : 1024; #else if (_mqtt_cfg.uri == nullptr) { ESP_LOGE(TAG, "MQTT URI not set."); - return; + return ESP_ERR_INVALID_STATE; } int desired_buffer = _mqtt_cfg.buffer_size > 0 ? _mqtt_cfg.buffer_size : 1024; #endif @@ -400,41 +400,44 @@ void PsychicMqttClient::connect() { ESP_LOGE(TAG, "Failed to allocate reassembly buffer (%u bytes)", (unsigned)_buffer_capacity); _buffer_capacity = 0; + return ESP_ERR_NO_MEM; } } if (_client == nullptr) { _client = esp_mqtt_client_init(&_mqtt_cfg); + if (_client == nullptr) + { + ESP_LOGE(TAG, "esp_mqtt_client_init failed"); + return ESP_ERR_NO_MEM; + } // Register event handler only once when client is first created // to avoid memory leak from repeated registrations esp_mqtt_client_register_event(_client, MQTT_EVENT_ANY, _onMqttEventStatic, this); _config_dirty = false; } + else if (_config_dirty) + { + // A failed config update must not be followed by a start: the client + // would come up on a partly-updated configuration, which is how a slot + // connects with the previous broker's credentials. Leave _config_dirty + // set so the next attempt retries the whole transaction. + esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); + if (cfg_result != ESP_OK) + { + ESP_LOGE(TAG, "connect(): failed to apply mqtt config: %s", esp_err_to_name(cfg_result)); + return cfg_result; + } + _config_dirty = false; + ESP_LOGD(TAG, "connect(): applied mqtt config update"); + } else { - if (_config_dirty) - { - esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); - ESP_ERROR_CHECK_WITHOUT_ABORT(cfg_result); - if (cfg_result == ESP_OK) - { - _config_dirty = false; - ESP_LOGD(TAG, "connect(): applied mqtt config update"); - } - else - { - ESP_LOGW(TAG, "connect(): failed to apply mqtt config, will retry"); - } - } - else - { - ESP_LOGD(TAG, "connect(): mqtt config unchanged, skipping set_config"); - } + ESP_LOGD(TAG, "connect(): mqtt config unchanged, skipping set_config"); } esp_err_t start_result = esp_mqtt_client_start(_client); - ESP_ERROR_CHECK_WITHOUT_ABORT(start_result); if (start_result == ESP_OK) { _started = true; @@ -445,76 +448,103 @@ void PsychicMqttClient::connect() // Reporting success here hides the one state reconnect() cannot recover from. ESP_LOGE(TAG, "MQTT client failed to start: %s", esp_err_to_name(start_result)); } + return start_result; } -void PsychicMqttClient::reconnect() +esp_err_t PsychicMqttClient::reconnect() { if (_client == nullptr) { ESP_LOGW(TAG, "MQTT client not initialized, cannot reconnect."); - return; + return ESP_ERR_INVALID_STATE; } if (_config_dirty) { - // Apply config only when mutating setters changed _mqtt_cfg. + // Apply config only when mutating setters changed _mqtt_cfg. A failure + // aborts the reconnect: reconnecting on the previous config was how a + // renewed token silently failed to reach the connection. esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); - ESP_ERROR_CHECK_WITHOUT_ABORT(cfg_result); - if (cfg_result == ESP_OK) + if (cfg_result != ESP_OK) { - _config_dirty = false; - ESP_LOGD(TAG, "reconnect(): applied mqtt config update"); - } - else - { - ESP_LOGW(TAG, "reconnect(): failed to apply mqtt config, reconnecting with previous config"); + ESP_LOGE(TAG, "reconnect(): failed to apply mqtt config: %s", esp_err_to_name(cfg_result)); + return cfg_result; } + _config_dirty = false; + ESP_LOGD(TAG, "reconnect(): applied mqtt config update"); } else { ESP_LOGD(TAG, "reconnect(): mqtt config unchanged, skipping set_config"); } - ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mqtt_client_reconnect(_client)); + esp_err_t r = esp_mqtt_client_reconnect(_client); + if (r != ESP_OK) + { + ESP_LOGE(TAG, "MQTT reconnect request failed: %s", esp_err_to_name(r)); + return r; + } ESP_LOGI(TAG, "MQTT client reconnect requested."); + return ESP_OK; } -void PsychicMqttClient::disconnect() +esp_err_t PsychicMqttClient::disconnect(unsigned long timeout_ms) { if (_client == nullptr) { ESP_LOGW(TAG, "MQTT client not started."); - return; + return ESP_ERR_INVALID_STATE; } + bool clean = true; if (_connected) { ESP_LOGI(TAG, "Disconnecting MQTT client."); _stopMqttClient = false; esp_mqtt_client_disconnect(_client); - // Wait for all disconnect events to be processed - while (!_stopMqttClient) + // Bounded, unlike the original: this runs on the MQTT task whose stop + // acknowledgement the bridge's shutdown waits for, so a lost + // DISCONNECTED event used to wedge the whole teardown. + unsigned long waited = 0; + while (!_stopMqttClient && waited < timeout_ms) { vTaskDelay(10 / portTICK_PERIOD_MS); + waited += 10; + } + if (!_stopMqttClient) + { + ESP_LOGW(TAG, "disconnect: no DISCONNECTED event in %lums; stopping anyway", timeout_ms); + clean = false; } } - esp_mqtt_client_stop(_client); - _started = false; - ESP_LOGI(TAG, "MQTT client stopped."); + esp_err_t stop_result = esp_mqtt_client_stop(_client); + if (stop_result == ESP_OK) + { + _started = false; + ESP_LOGI(TAG, "MQTT client stopped."); + } + else + { + // The SDK task was not joined. Saying otherwise is what let the caller + // destroy the client from under a live task. + ESP_LOGE(TAG, "esp_mqtt_client_stop failed: %s", esp_err_to_name(stop_result)); + return stop_result; + } + return clean ? ESP_OK : ESP_ERR_TIMEOUT; } -void PsychicMqttClient::softDisconnect(unsigned long timeout_ms) +esp_err_t PsychicMqttClient::softDisconnect(unsigned long timeout_ms) { if (_client == nullptr) { ESP_LOGW(TAG, "MQTT client not started."); - return; + return ESP_ERR_INVALID_STATE; } if (!_connected) { // Nothing to close; leaving the task alone is the whole point. - return; + return ESP_OK; } ESP_LOGI(TAG, "Disconnecting MQTT transport (client task retained)."); @@ -530,25 +560,34 @@ void PsychicMqttClient::softDisconnect(unsigned long timeout_ms) if (!_stopMqttClient) { ESP_LOGW(TAG, "softDisconnect: no DISCONNECTED event in %lums", timeout_ms); + return ESP_ERR_TIMEOUT; } + return ESP_OK; } -void PsychicMqttClient::forceStop() +esp_err_t PsychicMqttClient::forceStop() { if (_client == nullptr) { ESP_LOGW(TAG, "MQTT client not started."); - return; + return ESP_ERR_INVALID_STATE; } if (_connected) { ESP_LOGI(TAG, "Forced stop MQTT client."); } - ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mqtt_client_stop(_client)); + esp_err_t r = esp_mqtt_client_stop(_client); + if (r != ESP_OK) + { + // The SDK task was not joined: the caller must not destroy this client. + ESP_LOGE(TAG, "forceStop: esp_mqtt_client_stop failed: %s", esp_err_to_name(r)); + return r; + } _connected = false; _started = false; ESP_LOGI(TAG, "MQTT client forcefully stopped."); + return ESP_OK; } int PsychicMqttClient::subscribe(const char *topic, int qos) diff --git a/lib/PsychicMqttClient/src/PsychicMqttClient.h b/lib/PsychicMqttClient/src/PsychicMqttClient.h index 28e53fc3a..5d214679e 100644 --- a/lib/PsychicMqttClient/src/PsychicMqttClient.h +++ b/lib/PsychicMqttClient/src/PsychicMqttClient.h @@ -349,8 +349,17 @@ public: * @brief Connects the MQTT client to the server. * * @note All parameters must be set before calling this method. + * + * @return ESP_OK when esp_mqtt_client_start() accepted the client. + * ESP_ERR_INVALID_STATE if no URI is set, ESP_ERR_NO_MEM if the + * client or its reassembly buffer could not be allocated, or the + * error from esp_mqtt_set_config()/esp_mqtt_client_start(). + * + * A failed configuration update does NOT start the client: starting with a + * half-updated config is how a slot ends up connected with the previous + * broker's credentials. */ - void connect(); + esp_err_t connect(); /** * @brief Reconnects a previously started MQTT client. @@ -359,14 +368,28 @@ public: * re-initiating a connection on an already-started client, especially * when auto-reconnect is disabled. Updates config before reconnecting * so credential changes (e.g., refreshed JWT tokens) take effect. + * + * @return ESP_OK when the reconnect was requested, ESP_ERR_INVALID_STATE on + * an uninitialised client, or the error from esp_mqtt_set_config(). + * A failed config update aborts the reconnect rather than + * reconnecting with the previous configuration. */ - void reconnect(); + esp_err_t reconnect(); /** - * @brief Disconnects the MQTT client from the server. - * This call might be blocking until the client is stopped cleanly + * @brief Disconnects the MQTT client and stops its task. + * + * Blocks until the DISCONNECTED event arrives or timeout_ms elapses, then + * stops the client either way. The wait used to be unbounded, which turned + * a lost event into a wedged caller — and that caller is the MQTT task + * whose acknowledgement the bridge's shutdown waits on. + * + * @return ESP_OK when the client stopped after a clean disconnect, + * ESP_ERR_TIMEOUT when the DISCONNECTED event never arrived (the + * stop still ran), ESP_ERR_INVALID_STATE on an uninitialised + * client, or the error from esp_mqtt_client_stop(). */ - void disconnect(); + esp_err_t disconnect(unsigned long timeout_ms = 10000); /** * @brief Closes the transport but leaves the client task running. @@ -380,8 +403,12 @@ public: * @param timeout_ms how long to wait for the DISCONNECTED event before * giving up. Bounded on purpose: disconnect()'s wait is * unbounded and a lost event would wedge the caller. + * + * @return ESP_OK when the DISCONNECTED event arrived, ESP_ERR_TIMEOUT if it + * did not (the transport may still be open), ESP_ERR_INVALID_STATE + * on an uninitialised client, ESP_OK when already disconnected. */ - void softDisconnect(unsigned long timeout_ms = 5000); + esp_err_t softDisconnect(unsigned long timeout_ms = 5000); /** * @brief True once esp_mqtt_client_start() has succeeded and no stop has run. @@ -392,10 +419,14 @@ public: bool isStarted() const { return _started; } /** - * @brief Forcefully stops the MQTT client and disconnects from the server. + * @brief Stops the MQTT client without waiting for a DISCONNECTED event. * This does not trigger the onDisconnect callbacks. + * + * @return the result of esp_mqtt_client_stop(), or ESP_ERR_INVALID_STATE on + * an uninitialised client. A non-OK result means the SDK task was + * NOT joined: the caller must not destroy the client after it. */ - void forceStop(); + esp_err_t forceStop(); /** * @brief Subscribes to a topic. Server must be connected diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 8c0ee0584..97ecd867e 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -2091,7 +2091,19 @@ bool MQTTBridge::setupSlot(int index) { } } - slot.client->connect(); + // Activation is now conditional on the client actually starting. A failed + // esp_mqtt_set_config()/esp_mqtt_client_start() used to be invisible: the slot + // was marked activated, so it consumed one of the scarce active-slot + // positions, the reconnect ladder (which is gated on activation) governed it, + // and nothing retried the setup. Leaving it unactivated hands it to the + // existing deferred-setup retry in maintainSlotConnections() instead. + const esp_err_t connect_result = slot.client->connect(); + if (connect_result != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d start failed (%s) - will retry", index + 1, + esp_err_to_name(connect_result)); + slot.last_reconnect_attempt = millis(); + return false; + } slot.initial_connect_done = true; return true; } @@ -2137,17 +2149,16 @@ void MQTTBridge::teardownSlot(int index) { // which only stops slots still marked connected: a publishing slot's socket fails first, so // the guard skips it — measured across a 62 s deauth, five slots, zero stops. An idle slot // with no traffic to fail on is the one case that could still reach here that way. -void MQTTBridge::reconnectSlotClient(int index) { - if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return; +esp_err_t MQTTBridge::reconnectSlotClient(int index) { + if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return ESP_ERR_INVALID_ARG; MQTTSlot& slot = _slots[index]; - if (slot.client == nullptr) return; + if (slot.client == nullptr) return ESP_ERR_INVALID_STATE; if (!slot.client->isStarted()) { MQTT_DEBUG_PRINTLN("MQTT%d start (client was stopped)", index + 1); - slot.client->connect(); - return; + return slot.client->connect(); } - slot.client->reconnect(); + return slot.client->reconnect(); } @@ -2304,21 +2315,40 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns // to avoid internal heap leak/fragmentation from destroy/create cycles MQTT_DEBUG_PRINTLN("MQTT%d token renewal: reconnecting with fresh credentials", index + 1); MQTT_TRACE_HEAP("renewal:before-bounce", index); + esp_err_t bounce_result; if (slot.client->isStarted()) { // Keep the esp-mqtt task alive across the handshake. disconnect() // would stop it, returning its 6 KiB stack into the hole the two // 16 KiB mbedTLS record buffers just vacated — which is what walks // the largest free block down 16 KiB at a time on non-PSRAM boards. - slot.client->softDisconnect(); + const esp_err_t soft = slot.client->softDisconnect(); + if (soft != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d renewal: soft disconnect did not complete (%s)", + index + 1, esp_err_to_name(soft)); + } MQTT_TRACE_HEAP("renewal:after-disconnect", index); slot.client->setCredentials(_jwt_username, slot.auth_token); MQTT_TRACE_HEAP("renewal:after-credentials", index); - slot.client->reconnect(); + bounce_result = slot.client->reconnect(); } else { // Client was stopped (teardown/reconfigure). reconnect() is a no-op // on a stopped client, so this path must start it. slot.client->setCredentials(_jwt_username, slot.auth_token); - slot.client->connect(); + bounce_result = slot.client->connect(); + } + if (bounce_result != ESP_OK) { + // The fresh token is in the buffer but did not reach the + // connection: the config transaction failed, or the client would + // not start. Recording this as a completed renewal would leave the + // live session on the old credential until the broker enforced exp, + // with the next renewal not due for a whole token lifetime. Re-arm + // the renewal instead so the next maintenance pass retries the + // bounce, and leave the reconnect ladder alone — this is a local + // failure, not a broker fault. + MQTT_DEBUG_PRINTLN("MQTT%d renewal bounce failed (%s) - retrying next pass", + index + 1, esp_err_to_name(bounce_result)); + slot.last_token_renewal = 0; + return; } MQTT_TRACE_HEAP("renewal:after-reconnect", index); reconnect_attempted = true; @@ -2439,6 +2469,9 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns static_cast(now_millis), static_cast(slot.last_reconnect_attempt), slot.reconnect_backoff, static_cast(index))) { slot.last_reconnect_attempt = now_millis; + const uint8_t backoff_before = slot.reconnect_backoff; + const uint8_t failures_before = slot.max_backoff_failures; + const bool breaker_before = slot.circuit_breaker_tripped; MQTTConnectionPolicy::BackoffAdvance advance = MQTTConnectionPolicy::advanceBackoff( slot.reconnect_backoff, slot.max_backoff_failures); slot.reconnect_backoff = advance.reconnect_backoff; @@ -2463,7 +2496,18 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns } // Via the helper: reconnect() is a no-op on a client whose start failed, // which would back off forever without ever starting it. - reconnectSlotClient(index); + const esp_err_t r = reconnectSlotClient(index); + if (r != ESP_OK) { + // A local failure — uninitialised client, or a config transaction that + // did not commit — is not a broker fault. The ladder and the breaker + // exist to bound broker/network faults, so roll back the advance made + // above; the retry interval still paces the next attempt. + MQTT_DEBUG_PRINTLN("MQTT%d reconnect not accepted locally (%s) - backoff unchanged", + index + 1, esp_err_to_name(r)); + slot.reconnect_backoff = backoff_before; + slot.max_backoff_failures = failures_before; + slot.circuit_breaker_tripped = breaker_before; + } } } } @@ -4367,8 +4411,16 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { reconnectSlotClient(i); } else if (action == MQTTConnectionPolicy::StaleTokenAction::Bounce) { MQTT_DEBUG_PRINTLN("MQTT%d bouncing for the corrected-clock token", i + 1); - _slots[i].client->softDisconnect(); - _slots[i].client->reconnect(); + const esp_err_t soft = _slots[i].client->softDisconnect(); + if (soft != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d soft disconnect did not complete (%s)", i + 1, + esp_err_to_name(soft)); + } + const esp_err_t rc = _slots[i].client->reconnect(); + if (rc != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d corrected-clock reconnect failed (%s)", i + 1, + esp_err_to_name(rc)); + } } else { MQTT_DEBUG_PRINTLN("MQTT%d token re-created, no bounce (broker does not enforce exp)", i + 1); diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 0ec28cccd..4450a4f3d 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -490,7 +490,10 @@ private: void teardownSlot(int index); // Disconnect the slot's client (keeps the object alive) // Reconnect a slot, starting it instead when the client is stopped (reconnect() is a // no-op on a stopped client). See the definition. - void reconnectSlotClient(int index); + // ESP_OK when the reconnect/start was accepted by the SDK. A local failure + // (uninitialised client, failed config transaction) is not a broker fault and + // must not advance this slot's backoff ladder — see maintainSlotConnection(). + esp_err_t reconnectSlotClient(int index); void maintainSlotConnections(); // Maintain all slot connections (token renewal, reconnect) void maintainSlotConnection(int index, unsigned long now_millis, unsigned long current_time, bool time_synced, bool& reconnect_attempted, bool& teardown_attempted); bool createSlotAuthToken(int index); // Create/renew JWT token for a slot From 11f8cf1c58b433685ae0e4dbca8304f34025d9a3 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 17:46:20 -0700 Subject: [PATCH 11/19] fix(mqtt): decide slot teardown by SDK lifecycle state, not connectivity (F04) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `client->connected()` answers "is the network up", and it was being used for "is there anything to stop". A client resolving DNS, negotiating TLS or waiting after a failed CONNECT reports not-connected, so `teardownSlot()` skipped it: selecting `none` cleared the bridge flags while the SDK task kept running, and when the in-flight handshake completed the callback marked the disabled slot connected and scheduled its status. Each slot now carries the client's SDK lifecycle state (Absent, Configured, Starting, Connected, Disconnected, Stopped, Quarantined) and a generation counter for the logs. The bridge task owns that state, which makes it the authority the callbacks consult: - a CONNECTED event for a slot that is disabled, never started, or already stopped is logged and dropped instead of marking the slot connected; - teardown stops any *live* client, so a mid-handshake client can no longer outlive its configuration. Teardown also gains a reason, because "stop the task" and "close the transport" are different needs: - `Disable` (preset `none`, shutdown) stops the client — the stop is the point; - `Reconfigure` closes the transport with `softDisconnect()` and keeps the esp-mqtt task. Stopping it there would return its 6 KiB stack into the hole the two 16 KiB mbedTLS record buffers just vacated, which is the fork's documented internal-heap fragmentation driver — and per the soak campaign's own conclusion, feeding `softDisconnect()` into the reconfigure path is the fix for it, not serialisation. The campaign closed 2026-08-20, so the reconfigure churn is no longer anyone's measurement lever. A stop that does not complete now quarantines that client: its SDK task was never joined, so it is never reused, never destroyed, and the token buffer its config still points at is never freed. `get mqttN.diag` reports `quarantined`. Two knock-ons this required: - `setupSlot()` starts or reconnects according to the SDK state. `esp_mqtt_client_start()` fails on an already-started client, and now that its result is honoured, a reconfigure that kept the task would otherwise leave the slot permanently unactivated. - the active-slot cap counts resource holders as well as configured ones. It keyed off `initial_connect_done`, which teardown clears, so a started or quarantined client stopped counting against the cap and a board could oversubscribe past the concurrent-TLS limit the cap exists to enforce. --- src/helpers/bridges/MQTTBridge.cpp | 172 ++++++++++++++++++++++++++--- src/helpers/bridges/MQTTBridge.h | 41 ++++++- 2 files changed, 194 insertions(+), 19 deletions(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 97ecd867e..3e3cdf76a 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -463,6 +463,19 @@ void MQTTBridge::applyWifiPowerSave() { #endif } +const char* MQTTBridge::clientStateName(ClientState st) { + switch (st) { + case ClientState::Absent: return "absent"; + case ClientState::Configured: return "configured"; + case ClientState::Starting: return "starting"; + case ClientState::Connected: return "connected"; + case ClientState::Disconnected: return "disconnected"; + case ClientState::Stopped: return "stopped"; + case ClientState::Quarantined: return "quarantined"; + } + return "?"; +} + bool MQTTBridge::stopUnprovenLatched() { return s_stop_unproven; } uint8_t MQTTBridge::getLastWifiDisconnectReason() { return s_wifi_disconnect_reason; } @@ -561,6 +574,11 @@ void MQTTBridge::formatSlotDiagReply(char* buf, size_t bufsize, int slot_index) // is configured but missing a token/IATA/credential, so it was never set up and // has no client yet. Previously reported "disc", which read as a network fault. state = "wait"; + } else if (slot.client && slot.client_state == ClientState::Quarantined) { + // Its stop did not complete, so the SDK task was never joined: the slot is + // out of service for the rest of the boot and its resources are retained + // on purpose. + state = "quarantined"; } else if (!slot.client) { // Ready to connect but the client object could not be allocated. state = "no client"; @@ -1723,10 +1741,24 @@ bool MQTTBridge::ensureSlotClient(int index) { MQTT_DEBUG_PRINTLN("MQTT%d: out of memory allocating client", index + 1); return false; } + slot.client_state = ClientState::Configured; slot.client->setAutoReconnect(false); // we handle reconnect with our own backoff slot.client->onConnect([this, index](bool sessionPresent) { + // A CONNECT started before this slot was disabled or reconfigured can still + // complete afterwards. Accepting it marked a slot connected that the + // operator had switched off, scheduled its status publish, and published + // through the old session (F04). The bridge task owns client_state, so it + // is the authority on whether this event was asked for. + const ClientState st = _slots[index].client_state; + if (!_slots[index].enabled || !(st == ClientState::Starting || st == ClientState::Disconnected)) { + MQTT_DEBUG_PRINTLN("MQTT%d ignoring late CONNECTED (state=%s, gen=%lu, enabled=%d)", + index + 1, clientStateName(st), + (unsigned long)_slots[index].generation, (int)_slots[index].enabled); + return; + } MQTT_DEBUG_PRINTLN("MQTT%d connected", index + 1); + _slots[index].client_state = ClientState::Connected; _slots[index].connected = true; _slot_force_jwt_mint[index] = false; // NOTE: reconnect_backoff / max_backoff_failures are NOT reset here. @@ -1759,6 +1791,11 @@ bool MQTTBridge::ensureSlotClient(int index) { }); slot.client->onDisconnect([this, index](bool sessionPresent) { MQTT_DEBUG_PRINTLN("MQTT%d disconnected", index + 1); + // Only a live client's disconnect is news. One arriving for a client we + // already stopped (or quarantined) must not resurrect its state. + if (clientStateIsLive(_slots[index].client_state)) { + _slots[index].client_state = ClientState::Disconnected; + } _slots[index].disconnect_count++; if (_slots[index].first_disconnect_time == 0) { _slots[index].first_disconnect_time = millis(); @@ -1841,20 +1878,42 @@ void MQTTBridge::releaseSlotAuthToken(int index) { void MQTTBridge::destroySlotClients() { for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { MQTTSlot& slot = _slots[i]; - if (slot.client != nullptr) { - if (slot.client->connected()) { - slot.client->disconnect(); + if (slot.client == nullptr) { + releaseSlotAuthToken(i); + continue; + } + + if (slot.client_state == ClientState::Quarantined) { + // A previous stop failed, so this client's SDK task was never joined. + // Deleting it now is the use-after-free F01 is about, and freeing its + // token would pull the buffer out from under a config the task may still + // read. Leak both, deliberately, until the node reboots. + MQTT_DEBUG_PRINTLN("MQTT%d client quarantined - not destroyed, token retained", i + 1); + continue; + } + + if (clientStateIsLive(slot.client_state)) { + const esp_err_t r = slot.client->disconnect(); + if (r != ESP_OK && r != ESP_ERR_TIMEOUT) { + MQTT_DEBUG_PRINTLN("MQTT%d stop FAILED during shutdown (%s) - not destroying", i + 1, + esp_err_to_name(r)); + slot.client_state = ClientState::Quarantined; + continue; } + slot.client_state = ClientState::Stopped; #ifdef ESP_PLATFORM vTaskDelay(pdMS_TO_TICKS(50)); #else delay(50); #endif - delete slot.client; - slot.client = nullptr; } - // Unconditional: only now is the token unreachable from the client's stored - // config, and a token without a client would otherwise leak. + + delete slot.client; + slot.client = nullptr; + slot.client_state = ClientState::Absent; + slot.generation++; + // Only now is the token unreachable from the client's stored config, and a + // token without a client would otherwise leak. releaseSlotAuthToken(i); } } @@ -1862,7 +1921,18 @@ void MQTTBridge::destroySlotClients() { int MQTTBridge::activatedSlotCount() const { int n = 0; for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { - if (_slots[i].enabled && _slots[i].initial_connect_done) n++; + const MQTTSlot& s = _slots[i]; + // Two ways to hold a position, and the cap must respect both. The original + // one is the configuration view: enabled and through a successful setup. + // The second is the resource view: a client that has been started still + // owns a task, a socket and an mbedTLS context — which is what the cap + // actually protects — and a quarantined one owns them for the rest of the + // boot. `initial_connect_done` alone missed those, because teardown clears + // it, so a board could oversubscribe past _max_active_slots. + const bool holds_config_position = s.enabled && s.initial_connect_done; + const bool holds_resources = s.client != nullptr && + (clientStateIsLive(s.client_state) || s.client_state == ClientState::Quarantined); + if (holds_config_position || holds_resources) n++; } return n; } @@ -1909,8 +1979,17 @@ bool MQTTBridge::setupSlot(int index) { // them. setCredentials / setServer below overwrite the config fields in place // before connect() restarts the ESP-IDF client. if (slot.initial_connect_done) { - if (slot.client->connected()) { - slot.client->disconnect(); + // Close the transport (keeping the task) if this client is live, for the + // same reason applySlotPreset() does: a handshake in flight against the + // previous endpoint must not complete after the new config is applied. + if (clientStateIsLive(slot.client_state)) { + const esp_err_t r = slot.client->softDisconnect(); + if (r != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d re-apply: transport did not close cleanly (%s)", + index + 1, esp_err_to_name(r)); + } + slot.client_state = ClientState::Disconnected; + slot.generation++; } // Clear TLS verification fields so a stale CA-bundle attach or cert // pointer from a prior preset doesn't override the new one. @@ -2097,13 +2176,20 @@ bool MQTTBridge::setupSlot(int index) { // positions, the reconnect ladder (which is gated on activation) governed it, // and nothing retried the setup. Leaving it unactivated hands it to the // existing deferred-setup retry in maintainSlotConnections() instead. - const esp_err_t connect_result = slot.client->connect(); + // Start or reconnect according to what the SDK client actually is, not what + // the network is doing. esp_mqtt_client_start() fails on an already-started + // client, so a reconfigure that kept the task (TeardownReason::Reconfigure) + // has to reconnect instead — and with connect()'s result now honoured, using + // the wrong one would leave the slot permanently unactivated. + const esp_err_t connect_result = reconnectSlotClient(index); if (connect_result != ESP_OK) { MQTT_DEBUG_PRINTLN("MQTT%d start failed (%s) - will retry", index + 1, esp_err_to_name(connect_result)); slot.last_reconnect_attempt = millis(); return false; } + slot.client_state = ClientState::Starting; + slot.generation++; slot.initial_connect_done = true; return true; } @@ -2112,12 +2198,43 @@ bool MQTTBridge::setupSlot(int index) { // the client object alive so a subsequent setupSlot() can reuse its mbedTLS // context. This is called both on reconfigure (preset change) and at shutdown; // destruction of the underlying client happens once in destroySlotClients(). -void MQTTBridge::teardownSlot(int index) { +void MQTTBridge::teardownSlot(int index, TeardownReason reason) { if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return; MQTTSlot& slot = _slots[index]; - if (slot.client && slot.client->connected()) { - slot.client->disconnect(); + // Gated on the SDK lifecycle state, not on connectivity: a client resolving + // DNS, negotiating TLS or waiting after a failed CONNECT reports + // not-connected, and the old `connected()` gate left exactly those running — + // free to complete their handshake against an endpoint the operator had + // already replaced or switched off (F04). + if (slot.client && clientStateIsLive(slot.client_state)) { + if (reason == TeardownReason::Reconfigure) { + // Close the transport, keep the task. The in-flight handshake cannot + // complete against the old endpoint any more, and the esp-mqtt task's + // 6 KiB stack does not get returned into the hole the mbedTLS record + // buffers just vacated (the documented fragmentation driver). + const esp_err_t r = slot.client->softDisconnect(); + if (r != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d reconfigure: transport did not close cleanly (%s)", + index + 1, esp_err_to_name(r)); + } + slot.client_state = ClientState::Disconnected; + } else { + const esp_err_t r = slot.client->disconnect(); + if (r == ESP_OK || r == ESP_ERR_TIMEOUT) { + // ESP_ERR_TIMEOUT: no DISCONNECTED event, but the stop itself returned + // OK, so the SDK task is joined and the object is safe to reuse. + slot.client_state = ClientState::Stopped; + } else { + // The stop did not complete: the SDK task was not joined. Never touch + // this client again — not to reuse it, not to destroy it, and do not + // free the token buffer its config still points at. + MQTT_DEBUG_PRINTLN("MQTT%d stop FAILED (%s) - client quarantined for this boot", + index + 1, esp_err_to_name(r)); + slot.client_state = ClientState::Quarantined; + } + } + slot.generation++; #ifdef ESP_PLATFORM vTaskDelay(pdMS_TO_TICKS(50)); #else @@ -2154,11 +2271,24 @@ esp_err_t MQTTBridge::reconnectSlotClient(int index) { MQTTSlot& slot = _slots[index]; if (slot.client == nullptr) return ESP_ERR_INVALID_STATE; + if (slot.client_state == ClientState::Quarantined) { + // Its SDK task was never joined; touching it again is exactly what F01 + // forbids. + return ESP_ERR_INVALID_STATE; + } + + esp_err_t r; if (!slot.client->isStarted()) { MQTT_DEBUG_PRINTLN("MQTT%d start (client was stopped)", index + 1); - return slot.client->connect(); + r = slot.client->connect(); + } else { + r = slot.client->reconnect(); } - return slot.client->reconnect(); + if (r == ESP_OK) { + slot.client_state = ClientState::Starting; + slot.generation++; + } + return r; } @@ -2841,9 +2971,15 @@ void MQTTBridge::applySlotPreset(int slot_index, const char* preset_name) { if (slot_index < 0 || slot_index >= RUNTIME_MQTT_SLOTS) return; MQTTSlot& slot = _slots[slot_index]; - teardownSlot(slot_index); + const bool disabling = (strcmp(preset_name, MQTT_PRESET_NONE) == 0 || preset_name[0] == '\0'); + // Selecting `none` must actually stop the client: clearing the bridge flags + // used to leave its task and transport running until full shutdown, and an + // in-flight handshake could still complete and mark the disabled slot + // connected (F04). Every other case keeps the task and only closes the + // transport. + teardownSlot(slot_index, disabling ? TeardownReason::Disable : TeardownReason::Reconfigure); - if (strcmp(preset_name, MQTT_PRESET_NONE) == 0 || preset_name[0] == '\0') { + if (disabling) { slot.enabled = false; slot.preset = nullptr; return; diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 4450a4f3d..0e9eeb066 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -98,9 +98,38 @@ private: static const uint32_t kNtpMinValidEpoch = 1767225600UL; // 2026-01-01 UTC static const uint32_t kNtpMaxValidEpoch = 4102444800UL; // 2100-01-01 UTC + // What the SDK client is doing, as opposed to whether the network is up. + // `client->connected()` answers the second question and was being used for + // the first: a client resolving DNS, negotiating TLS or waiting after a + // failed CONNECT reports not-connected, so teardown skipped it and left its + // task running (F04). Absent is 0 so a memset-initialised slot is correct. + enum class ClientState : uint8_t { + Absent = 0, // no client object + Configured, // client allocated, never started + Starting, // start/reconnect requested, awaiting CONNECTED + Connected, // CONNECTED received + Disconnected, // started, no session (our reconnect ladder governs it) + Stopped, // stop completed; the SDK task is joined and gone + Quarantined, // stop failed: the SDK task was NOT joined. Never destroy, + // never reuse, never free anything it still points at. + }; + + static const char* clientStateName(ClientState s); + // True while the SDK client has been started and not proven stopped, i.e. + // while it may still own a task, a socket and a TLS context. + static bool clientStateIsLive(ClientState s) { + return s == ClientState::Starting || s == ClientState::Connected || + s == ClientState::Disconnected; + } + // Connection slot - each slot holds one MQTT connection struct MQTTSlot { PsychicMqttClient* client; + ClientState client_state; + // Bumped on every start/stop. Only used for diagnostics and log lines: the + // accept/reject decision for a late callback is made on client_state, which + // the bridge task owns. + uint32_t generation; const MQTTPresetDef* preset; // Points to MQTT_PRESETS[] entry, nullptr for custom/none bool enabled; // true when preset is not "none" bool connected; // Updated in callbacks @@ -487,7 +516,17 @@ private: int activatedSlotCount() const; bool canActivateSlot(int index) const; // force as in destroySlotClients(): skip the unbounded wait, dirty-stop path only. - void teardownSlot(int index); // Disconnect the slot's client (keeps the object alive) + // Why a slot is being torn down. The distinction is not cosmetic: + // - Reconfigure: the slot is about to connect somewhere else, so the + // transport must close (or an in-flight handshake could complete against + // the OLD endpoint) but the esp-mqtt task should stay. Stopping it returns + // its 6 KiB stack into the hole the two 16 KiB mbedTLS record buffers just + // vacated, which is the fork's documented internal-heap fragmentation + // driver; softDisconnect() avoids exactly that. + // - Disable: the slot is going away, so the task and its transport must go + // with it. Here the stop IS the point. + enum class TeardownReason : uint8_t { Reconfigure, Disable }; + void teardownSlot(int index, TeardownReason reason = TeardownReason::Disable); // Reconnect a slot, starting it instead when the client is stopped (reconnect() is a // no-op on a stopped client). See the definition. // ESP_OK when the reconnect/start was accepted by the SDK. A local failure From 3afd7ebedb466de0b30b80aaf610cd470ecfaf19 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 18:03:59 -0700 Subject: [PATCH 12/19] fix(mqtt): write every owned field on every apply; recreate only where needed (F02) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The stale-configuration fix, and the reason the four preceding commits went first. `setupSlot()` applied configuration field by field, interleaved with the decisions that produced it, and cleared stale fields only when `slot.initial_connect_done` was set — which `teardownSlot()` clears at the top of every reconfigure. So live reconfiguration always skipped the cleanup. On a 5-slot board this was reproducible in one command: moving a slot from a JWT preset to an anonymous custom endpoint sent the previous configuration's `v1_` username in the CONNECT to the new broker (95-byte CONNECT captured at a throwaway broker on the LAN). The same config after a reboot sent 26 bytes with no username, which is what pinned it to the reconfigure path. That cleanup could not have worked anyway: it nulled the wrapper's pointers, and IDF's `esp_mqtt_set_if_config()` treats NULL as "leave unchanged", so an SDK-held credential survives it. An empty string does overwrite it, and leaves the CONNECT's username flag clear. So configuration is now decided in full first, then applied in one place: - every owned field is written on every apply — server, trust material, username, password — with absent credentials written as "" rather than omitted; - `mqttConfigRecreateDecision()` (previous commit) picks reuse or recreation. Credentials, auth-mode changes and endpoint moves within one scheme reuse the client, because a create/destroy cycle on the reconnect and renewal paths is the fork's documented internal-heap fragmentation driver. A transport (scheme) change, a trust-policy or CA change, and buffer-capacity growth recreate it, because those are the fields a write cannot safely replace; - `recreateSlotClient()` will not destroy a client whose stop was not proven — it quarantines it and fails the setup instead; - the applied configuration is recorded only after the client actually starts. Verified on hardware (Heltec V4, 5 live slots, both paths): - reuse path — a custom JWT slot (639-byte CONNECT carrying `v1_` plus the token) with its audience cleared now sends 26 bytes with no credentials, with no client recreation; - recreate path — `mqtt://` to `wss://` logged `recreating client (transport-change)` and reconnected. Also fixes a cap regression the hardware run caught: `canActivateSlot()` now counts the positions held by the *other* slots. A slot being reconfigured keeps its esp-mqtt task alive, so once the count included live clients it counted itself out of its own position and a full board refused to reconfigure a slot — disabling it instead. Asking "is there room for this slot" rather than "is there room for one more" is also what makes a resource-based count safe. --- src/helpers/bridges/MQTTBridge.cpp | 180 +++++++++++++++++++++++------ src/helpers/bridges/MQTTBridge.h | 20 ++++ 2 files changed, 165 insertions(+), 35 deletions(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 3e3cdf76a..da0fa3022 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -783,6 +783,10 @@ MQTTBridge::MQTTBridge(NodePrefs *prefs, MQTTPrefs *obs, mesh::PacketManager *mg _slots[i].last_reconnect_attempt = 0; _slots[i].last_log_time = 0; _slots[i].port = 1883; + _slots[i].client_state = ClientState::Absent; + _slots[i].generation = 0; + _slots[i].applied_config = MqttEffectiveConfig(); + _slots[i].allocated_buffer_size = 0; _slot_reconfigure_pending[i] = false; _slot_force_jwt_mint[i] = false; _status_publish_pending[i] = false; @@ -1742,6 +1746,11 @@ bool MQTTBridge::ensureSlotClient(int index) { return false; } slot.client_state = ClientState::Configured; + // The SDK allocates its buffers in esp_mqtt_client_init() (inside the first + // connect()) from the size set before it, and never resizes them. Record what + // this client will therefore own, so a later config that needs more capacity + // is recognised as needing a new client rather than silently truncating. + slot.allocated_buffer_size = kMqttClientBufferSize; slot.client->setAutoReconnect(false); // we handle reconnect with our own backoff slot.client->onConnect([this, index](bool sessionPresent) { @@ -1918,9 +1927,12 @@ void MQTTBridge::destroySlotClients() { } } -int MQTTBridge::activatedSlotCount() const { +int MQTTBridge::activatedSlotCount() const { return activatedSlotCountExcluding(-1); } + +int MQTTBridge::activatedSlotCountExcluding(int skip) const { int n = 0; for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { + if (i == skip) continue; const MQTTSlot& s = _slots[i]; // Two ways to hold a position, and the cap must respect both. The original // one is the configuration view: enabled and through a successful setup. @@ -1939,9 +1951,14 @@ int MQTTBridge::activatedSlotCount() const { bool MQTTBridge::canActivateSlot(int index) const { if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return false; - // Already holding a position (a reconfigure of a live slot) — no new position needed. - if (_slots[index].enabled && _slots[index].initial_connect_done) return true; - return activatedSlotCount() < _max_active_slots; + // Count what the OTHER slots hold. A slot being set up or reconfigured must + // not count itself out of its own position — and it can now hold resources + // while being reconfigured, because a reconfigure keeps the esp-mqtt task + // alive (TeardownReason::Reconfigure). Asking "is there room for this slot" + // rather than "is there room for one more" is also what makes the count safe + // to base on live resources instead of on initial_connect_done, which + // teardown clears. + return activatedSlotCountExcluding(index) < _max_active_slots; } // Returns true only when the slot reached connect(). A false result leaves the slot @@ -1991,22 +2008,13 @@ bool MQTTBridge::setupSlot(int index) { slot.client_state = ClientState::Disconnected; slot.generation++; } - // Clear TLS verification fields so a stale CA-bundle attach or cert - // pointer from a prior preset doesn't override the new one. - esp_mqtt_client_config_t* cfg = slot.client->getMqttConfig(); - #if ESP_IDF_VERSION_MAJOR == 5 - cfg->broker.verification.certificate = nullptr; - cfg->broker.verification.certificate_len = 0; - cfg->broker.verification.crt_bundle_attach = nullptr; - cfg->credentials.username = nullptr; - cfg->credentials.authentication.password = nullptr; - #else - cfg->cert_pem = nullptr; - cfg->cert_len = 0; - cfg->crt_bundle_attach = nullptr; - cfg->username = nullptr; - cfg->password = nullptr; - #endif + // The config fields are NOT cleared here any more. Two reasons: this block + // only ran when initial_connect_done was set, which teardownSlot() clears + // first, so live reconfiguration always skipped it (F02); and nulling a + // wrapper pointer cannot clear an SDK-held string anyway, because IDF's + // esp_mqtt_set_if_config() treats NULL as "leave unchanged". Every owned + // field is written unconditionally below instead, with absent credentials + // written as "" — which does clear them. if (slot.auth_token) slot.auth_token[0] = '\0'; slot.connected = false; slot.token_expires_at = 0; @@ -2032,11 +2040,25 @@ bool MQTTBridge::setupSlot(int index) { #endif #endif + // What this slot should be configured with. Decided first, in full, and + // applied in one place below: field-by-field application interleaved with + // decisions is what let a stale credential survive a reconfigure (F02). + // Every pointer here must outlive the client — esp-mqtt stores the pointer + // and re-reads it whenever a later connect() re-applies the config — so these + // are preset literals in flash, or slot/bridge members, never locals. + const char* cfg_uri = nullptr; + MqttAuth cfg_auth = MqttAuth::None; + const char* cfg_user = nullptr; + const char* cfg_pass = nullptr; + MqttTrust cfg_trust = MqttTrust::Plaintext; + const char* cfg_pem = nullptr; + if (slot.preset) { // Preset-based slot - slot.client->setServer(slot.preset->server_url); + cfg_uri = slot.preset->server_url; if (slot.preset->ca_cert) { - slot.client->setCACert(slot.preset->ca_cert); + cfg_trust = MqttTrust::PemCert; + cfg_pem = slot.preset->ca_cert; } // A JWT slot with no usable token would connect unauthenticated and be rejected. @@ -2048,7 +2070,9 @@ bool MQTTBridge::setupSlot(int index) { slot.last_reconnect_attempt = millis(); return false; } - slot.client->setCredentials(_jwt_username, slot.auth_token); + cfg_auth = MqttAuth::Jwt; + cfg_user = _jwt_username; + cfg_pass = slot.auth_token; } else if (slot.preset->auth_type == MQTT_AUTH_USERPASS) { const char* user = nullptr; const char* pass = slot.preset->userpass_password @@ -2062,7 +2086,9 @@ bool MQTTBridge::setupSlot(int index) { user = slot.username; } if (user && user[0] != '\0' && pass && pass[0] != '\0') { - slot.client->setCredentials(user, pass); + cfg_auth = MqttAuth::UserPass; + cfg_user = user; + cfg_pass = pass; } } } else { @@ -2115,7 +2141,7 @@ bool MQTTBridge::setupSlot(int index) { } snprintf(slot.broker_uri, sizeof(slot.broker_uri), "%s://%s:%d", proto, slot.host, slot.port); } - slot.client->setServer(slot.broker_uri); + cfg_uri = slot.broker_uri; MQTT_DEBUG_PRINTLN("MQTT%d custom broker URI: %s (host='%s', port=%u)", index + 1, slot.broker_uri, slot.host, (unsigned)slot.port); @@ -2124,8 +2150,7 @@ bool MQTTBridge::setupSlot(int index) { // a use-after-free race: connect() launches an async FreeRTOS task, and // calling setCACertBundle() again from a later slot would free the global // crts array while a prior slot's TLS handshake may still be reading it. - bool needs_tls = (strncmp(slot.broker_uri, "mqtts://", 8) == 0 || - strncmp(slot.broker_uri, "wss://", 6) == 0); + const bool needs_tls = mqttTransportIsEncrypted(mqttTransportFromUri(slot.broker_uri)); if (needs_tls) { if (!s_ca_bundle_loaded) { size_t bundle_len = 0; @@ -2138,8 +2163,10 @@ bool MQTTBridge::setupSlot(int index) { if (bundle_len > 0) { MQTT_DEBUG_PRINTLN("MQTT global CA bundle init: embedded bundle (%u bytes)", (unsigned)bundle_len); - // Load the bundle into the global s_crt_bundle via the first client. - // This is a one-time operation; subsequent clients reuse via attachArduinoCACertBundle. + // Load the bundle into the global s_crt_bundle via this client. The + // load is global and one-shot (calling it again would free the crts + // array while another slot's handshake may still be reading it); the + // per-client attach pointer is set uniformly in the apply step below. slot.client->setCACertBundle(rootca_crt_bundle_start, bundle_len); s_ca_bundle_loaded = true; } else { @@ -2151,6 +2178,7 @@ bool MQTTBridge::setupSlot(int index) { } MQTT_DEBUG_PRINTLN("MQTT%d TLS verify: CA bundle %s", index + 1, s_ca_bundle_loaded ? "active" : "unavailable"); + if (s_ca_bundle_loaded) cfg_trust = MqttTrust::Bundle; } else { MQTT_DEBUG_PRINTLN("MQTT%d custom broker uses non-TLS transport", index + 1); } @@ -2163,11 +2191,19 @@ bool MQTTBridge::setupSlot(int index) { slot.last_reconnect_attempt = millis(); return false; } - slot.client->setCredentials(_jwt_username, slot.auth_token); + cfg_auth = MqttAuth::Jwt; + cfg_user = _jwt_username; + cfg_pass = slot.auth_token; MQTT_DEBUG_PRINTLN("MQTT%d custom broker using JWT auth (audience: %s)", index + 1, slot.audience); - } else if (strlen(slot.username) > 0) { - slot.client->setCredentials(slot.username, slot.password); + } else if (slot.username[0] != '\0') { + cfg_auth = MqttAuth::UserPass; + cfg_user = slot.username; + cfg_pass = slot.password; } + // No else: an anonymous endpoint gets empty credentials written to it, so + // whatever the previous configuration left in the SDK is overwritten. This + // exact transition (JWT preset -> anonymous custom) was observed sending + // the old v1_ username to the new broker. } // Activation is now conditional on the client actually starting. A failed @@ -2176,6 +2212,49 @@ bool MQTTBridge::setupSlot(int index) { // positions, the reconnect ladder (which is gated on activation) governed it, // and nothing retried the setup. Leaving it unactivated hands it to the // existing deferred-setup retry in maintainSlotConnections() instead. + // --- one apply, every field ------------------------------------------------ + MqttEffectiveConfig desired; + // Keepalive is recorded as 0: optimizeMqttClientConfig() owns it, it is + // rewritten on every apply, and it plays no part in the recreate decision. + if (!mqttBuildEffectiveConfig(cfg_uri, cfg_auth, cfg_user, cfg_pass, cfg_trust, cfg_pem, + kMqttClientBufferSize, 0, &desired)) { + MQTT_DEBUG_PRINTLN("MQTT%d: unusable broker URI '%s' - not connecting", index + 1, + cfg_uri ? cfg_uri : "(none)"); + slot.last_reconnect_attempt = millis(); + return false; + } + + // Recreate only where a field cannot be overwritten: a transport (scheme) + // change, a trust-policy or CA change, or growth past the allocated buffer + // capacity. Everything else — credentials, auth mode, an endpoint move within + // one scheme — is reconfigured in place, because a client create/destroy cycle + // on the reconnect/renewal path is the documented fragmentation driver. + const MqttRecreateDecision decision = + mqttConfigRecreateDecision(slot.applied_config, desired, slot.allocated_buffer_size); + if (decision.recreate) { + MQTT_DEBUG_PRINTLN("MQTT%d recreating client (%s)", index + 1, decision.reason); + if (!recreateSlotClient(index)) { + slot.last_reconnect_attempt = millis(); + return false; + } + } + + // Write every owned field, in one place, whether or not it changed. Absent + // credentials are written as "" rather than left alone: NULL means "leave + // unchanged" to esp_mqtt_set_config(), while an empty string clears the + // stored value and leaves the CONNECT's username flag clear. + slot.client->setServer(cfg_uri); + if (desired.trust == MqttTrust::PemCert) { + slot.client->setCACert(desired.pem); + slot.client->attachArduinoCACertBundle(false); + } else if (desired.trust == MqttTrust::Bundle) { + slot.client->attachArduinoCACertBundle(true); + } else { + slot.client->attachArduinoCACertBundle(false); + } + slot.client->setCredentials(mqttFieldOrEmpty(desired.username), + mqttFieldOrEmpty(desired.password)); + // Start or reconnect according to what the SDK client actually is, not what // the network is doing. esp_mqtt_client_start() fails on an already-started // client, so a reconfigure that kept the task (TeardownReason::Reconfigure) @@ -2188,12 +2267,43 @@ bool MQTTBridge::setupSlot(int index) { slot.last_reconnect_attempt = millis(); return false; } - slot.client_state = ClientState::Starting; - slot.generation++; + // reconnectSlotClient() moved the state to Starting and bumped the generation. + // Record what the client is now configured with, so the next apply can tell + // an in-place change from a structural one. + slot.applied_config = desired; slot.initial_connect_done = true; return true; } +// Destroy and re-create this slot's client, for the configuration changes that +// cannot be applied to a live SDK client (see mqttConfigRecreateDecision). +// +// The stop must be PROVEN before the object is freed: a client whose +// esp_mqtt_client_stop() did not return OK still has a task, and deleting it +// then is the use-after-free F01 is about. Such a client is quarantined and this +// returns false — the slot stays unactivated and its resources are retained +// until the node reboots, rather than being freed under a live task. +bool MQTTBridge::recreateSlotClient(int index) { + if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return false; + MQTTSlot& slot = _slots[index]; + if (slot.client == nullptr) return ensureSlotClient(index); + + teardownSlot(index, TeardownReason::Disable); // stop, do not just close the transport + if (slot.client_state == ClientState::Quarantined) { + MQTT_DEBUG_PRINTLN("MQTT%d cannot recreate: previous stop unproven", index + 1); + return false; + } + + delete slot.client; + slot.client = nullptr; + slot.client_state = ClientState::Absent; + slot.applied_config = MqttEffectiveConfig(); // nothing is applied to a client that does not exist + slot.allocated_buffer_size = 0; + // The token buffer survives: the new client is configured from it below, and + // its lifetime is the slot's, not the client's (see MQTTSlot::auth_token). + return ensureSlotClient(index); +} + // Disconnect the slot's MQTT client and clear per-connection state, but leave // the client object alive so a subsequent setupSlot() can reuse its mbedTLS // context. This is called both on reconfigure (preset change) and at shutdown; @@ -4877,7 +4987,7 @@ void MQTTBridge::optimizeMqttClientConfig(PsychicMqttClient* client, bool needs_ // The cost is 384 bytes per client on a non-PSRAM board (at most 2 active // slots there), against a handshake that needs 16 KB of *contiguous* internal // DRAM — noise, and it buys the removal of a recreate case. - static const int MQTT_CLIENT_BUFFER_SIZE = 896; + static const int MQTT_CLIENT_BUFFER_SIZE = kMqttClientBufferSize; (void)needs_large_buffer; // kept: callers still express the intent client->setBufferSize(MQTT_CLIENT_BUFFER_SIZE); diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 0e9eeb066..6c81cfc2b 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -11,6 +11,7 @@ #include "helpers/MQTTPresets.h" #include "helpers/MQTTLifecycle.h" #include "helpers/AlertFaultPolicy.h" +#include "helpers/MQTTEffectiveConfig.h" #include #ifdef WITH_SNMP @@ -91,6 +92,12 @@ public: private: static const size_t AUTH_TOKEN_SIZE = 768; + // Every client gets buffers sized for a JWT CONNECT (frame + 768-byte token), + // on every board: the SDK fixes the allocation at client init and does not + // resize it, so a per-slot size made the desired and allocated capacities + // disagree (F03). + static const uint16_t kMqttClientBufferSize = 896; + // NTP acceptance bounds. A reply outside them is rejected outright rather // than allowed to set the clock, the RTC and every JWT minted afterwards. static const uint16_t kNtpPort = 123; @@ -126,6 +133,12 @@ private: struct MQTTSlot { PsychicMqttClient* client; ClientState client_state; + // What this client was last successfully configured with, and the buffer + // capacity it actually owns (the SDK fixes that at client init). Together + // they answer "can the next configuration be applied in place?" — the + // question `initial_connect_done` was standing in for, wrongly. + MqttEffectiveConfig applied_config; + uint16_t allocated_buffer_size; // Bumped on every start/stop. Only used for diagnostics and log lines: the // accept/reject decision for a late callback is made on client_state, which // the bridge task owns. @@ -501,6 +514,10 @@ private: // This avoids delete/new cycles that shed ~40 KB of mbedTLS buffers per // reconfigure and fragment the internal heap on non-PSRAM boards. bool ensureSlotClient(int index); // Allocate this slot's persistent client + callbacks on first use + // Stop, destroy and re-allocate this slot's client. Only for configuration + // changes that cannot be applied to a live client, and only after the stop is + // proven — false means the client is quarantined and must not be reused. + bool recreateSlotClient(int index); bool ensureSlotAuthToken(int index); // Allocate this slot's JWT token buffer on first token creation void releaseSlotAuthToken(int index);// Free the token buffer (only with the client — see MQTTSlot) // No force variant: the only caller that ever passed one was the dirty-stop @@ -514,6 +531,9 @@ private: // setup-retry path, and live reconfigure all gate on these so the cap cannot be // exceeded by one route while another enforces it. int activatedSlotCount() const; + // Positions held by every slot except `skip` (-1 for none). canActivateSlot() + // excludes the candidate so a live reconfigure cannot fail its own cap check. + int activatedSlotCountExcluding(int skip) const; bool canActivateSlot(int index) const; // force as in destroySlotClients(): skip the unbounded wait, dirty-stop path only. // Why a slot is being torn down. The distinction is not cosmetic: From e2673f79e488342dbe3130a9176881a0c80cc9f5 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 20:03:13 -0700 Subject: [PATCH 13/19] fix(mqtt): close the review's P1 and P2 findings on the F01/F04/F06 work MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review of the branch found one merge-blocking lifecycle hole and three correctness gaps where the implementation stopped short of contracts the design had already written down. All four are real; each was confirmed against the source (two of them against hardware) before anything changed. **P1 — a quarantined client could still produce a clean bridge stop.** The cooperative teardown set `_teardown_complete` unconditionally, so a slot whose `esp_mqtt_client_stop()` had not completed — deliberately skipped by `destroySlotClients()` and marked Quarantined — still let the trampoline publish the acknowledgement. The owner then freed the queue and buffers and allowed a restart while that SDK task might still be running: exactly the ownership ambiguity StopUnproven exists to remove. The ack is now withheld unless EVERY client is proven stopped, so one unproven client leaves the whole bridge unproven. The rule lives in MQTTClientState.h (`mqttStopMayBeAcknowledged`) with host tests, alongside the state predicates moved out of the bridge. **P2 — the F04 protection did not cover a client that was still connecting.** `softDisconnect()` returns ESP_OK immediately when the client is not connected, so for a slot mid-DNS/TLS/CONNECT it cancelled nothing: the attempt ran on and its CONNECTED event arrived after the new configuration was applied, and with callbacks registered once per client and esp-mqtt events carrying no generation, nothing could tell it from the new attempt's. A reconfigure that lands on a `Starting` client now stops it, joining its SDK task, before applying the new configuration. A Connected client still takes the cheap softDisconnect path, which is where the fragmentation argument applies. One helper (`closeLiveClientForReconfigure`) so the two call sites cannot drift. **P2 — a failed renewal bounce still advanced the effective expiry.** Minting updates `token_expires_at` immediately and the renewal decision read it, so a bounce that failed looked complete: the next pass saw a fresh future expiry and never retried, and clearing `last_token_renewal` re-armed nothing. Slots now carry `applied_token_expires_at` — the expiry of the credential the CONNECTION is using — which only advances when a connect or reconnect has carried it. A failed bounce leaves it on the old credential, so the renewal stays due. **P2 — config-committed and start-accepted were conflated.** `connect()` returned one result for both, so a start that failed after the configuration had committed left `applied_config` describing the previous configuration, and the next recreate-or-reuse decision could reuse a client whose trust policy was not the one it believed. `applyConfig()` is now its own wrapper operation; `applied_config` records the commit, activation records the start. The reconnect ladder resets there too rather than in `teardownSlot()` — the old endpoint's history still applies until a replacement configuration actually commits. Two of my own bugs surfaced on hardware while testing this, both fixed here: - `recreateSlotClient()` called the full `teardownSlot()`, which cleared `broker_uri`, the just-minted token and both expiries out from under a configuration that had already been decided, so a recreate handed the SDK an empty URI and an empty token. It now stops the client and swaps the object, touching nothing else, and the apply step refuses to configure a URI that changed under it rather than passing it on. - `stopSlotClient()` quarantined on any non-OK result, but `ESP_FAIL` from `esp_mqtt_client_stop()` means "client is in invalid state", i.e. not started: there was no task to join, the safest state there is. It was observed quarantining healthy clients on hardware. The case that genuinely cannot be proven is a stop that never RETURNS, which cannot surface here at all — it hangs the task, which is what the bridge-level timeout contains. Hardware (Heltec V4, 5 live slots): a reconfigure landing on a connecting client logs `reconfigure during connect - stopping to cancel the attempt`; a broker holding the CONNACK sees the client close the socket and the disabled slot never connects; `wss`→`mqtt`→`wss` recreate cycles reconnect each way; a blackholed endpoint recovers. 499/499 native tests, four envs clean. --- .../src/PsychicMqttClient.cpp | 110 ++++---- lib/PsychicMqttClient/src/PsychicMqttClient.h | 16 ++ src/helpers/MQTTClientState.h | 82 ++++++ src/helpers/bridges/MQTTBridge.cpp | 263 +++++++++++++----- src/helpers/bridges/MQTTBridge.h | 42 ++- .../test_mqtt_client_state.cpp | 89 ++++++ 6 files changed, 458 insertions(+), 144 deletions(-) create mode 100644 src/helpers/MQTTClientState.h create mode 100644 test/test_mqtt_client_state/test_mqtt_client_state.cpp diff --git a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp index cec11177a..ccd11341d 100644 --- a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp +++ b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp @@ -371,21 +371,59 @@ bool PsychicMqttClient::connected() return _connected; } -esp_err_t PsychicMqttClient::connect() +esp_err_t PsychicMqttClient::applyConfig() { #if ESP_IDF_VERSION_MAJOR == 5 if (_mqtt_cfg.broker.address.uri == nullptr) - { - ESP_LOGE(TAG, "MQTT URI not set."); - return ESP_ERR_INVALID_STATE; - } - int desired_buffer = _mqtt_cfg.buffer.size > 0 ? _mqtt_cfg.buffer.size : 1024; #else if (_mqtt_cfg.uri == nullptr) +#endif { ESP_LOGE(TAG, "MQTT URI not set."); return ESP_ERR_INVALID_STATE; } + + if (_client == nullptr) + { + // esp_mqtt_client_init() takes the whole configuration, including the + // buffer sizes it allocates once and never resizes. + _client = esp_mqtt_client_init(&_mqtt_cfg); + if (_client == nullptr) + { + ESP_LOGE(TAG, "esp_mqtt_client_init failed"); + return ESP_ERR_NO_MEM; + } + // Register event handler only once when client is first created + // to avoid memory leak from repeated registrations + esp_mqtt_client_register_event(_client, MQTT_EVENT_ANY, _onMqttEventStatic, this); + _config_dirty = false; + return ESP_OK; + } + + if (!_config_dirty) + { + ESP_LOGD(TAG, "applyConfig(): mqtt config unchanged, skipping set_config"); + return ESP_OK; + } + + esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); + if (cfg_result != ESP_OK) + { + // Leave _config_dirty set so the next attempt retries the whole + // transaction rather than starting on a partly-updated configuration. + ESP_LOGE(TAG, "applyConfig(): failed to apply mqtt config: %s", esp_err_to_name(cfg_result)); + return cfg_result; + } + _config_dirty = false; + ESP_LOGD(TAG, "applyConfig(): applied mqtt config update"); + return ESP_OK; +} + +esp_err_t PsychicMqttClient::connect() +{ +#if ESP_IDF_VERSION_MAJOR == 5 + int desired_buffer = _mqtt_cfg.buffer.size > 0 ? _mqtt_cfg.buffer.size : 1024; +#else int desired_buffer = _mqtt_cfg.buffer_size > 0 ? _mqtt_cfg.buffer_size : 1024; #endif @@ -404,38 +442,11 @@ esp_err_t PsychicMqttClient::connect() } } - if (_client == nullptr) - { - _client = esp_mqtt_client_init(&_mqtt_cfg); - if (_client == nullptr) - { - ESP_LOGE(TAG, "esp_mqtt_client_init failed"); - return ESP_ERR_NO_MEM; - } - // Register event handler only once when client is first created - // to avoid memory leak from repeated registrations - esp_mqtt_client_register_event(_client, MQTT_EVENT_ANY, _onMqttEventStatic, this); - _config_dirty = false; - } - else if (_config_dirty) - { - // A failed config update must not be followed by a start: the client - // would come up on a partly-updated configuration, which is how a slot - // connects with the previous broker's credentials. Leave _config_dirty - // set so the next attempt retries the whole transaction. - esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); - if (cfg_result != ESP_OK) - { - ESP_LOGE(TAG, "connect(): failed to apply mqtt config: %s", esp_err_to_name(cfg_result)); - return cfg_result; - } - _config_dirty = false; - ESP_LOGD(TAG, "connect(): applied mqtt config update"); - } - else - { - ESP_LOGD(TAG, "connect(): mqtt config unchanged, skipping set_config"); - } + // A failed config transaction must not be followed by a start: the client + // would come up on a partly-updated configuration, which is how a slot + // connects with the previous broker's credentials. + esp_err_t cfg_result = applyConfig(); + if (cfg_result != ESP_OK) return cfg_result; esp_err_t start_result = esp_mqtt_client_start(_client); if (start_result == ESP_OK) @@ -458,24 +469,11 @@ esp_err_t PsychicMqttClient::reconnect() ESP_LOGW(TAG, "MQTT client not initialized, cannot reconnect."); return ESP_ERR_INVALID_STATE; } - if (_config_dirty) - { - // Apply config only when mutating setters changed _mqtt_cfg. A failure - // aborts the reconnect: reconnecting on the previous config was how a - // renewed token silently failed to reach the connection. - esp_err_t cfg_result = esp_mqtt_set_config(_client, &_mqtt_cfg); - if (cfg_result != ESP_OK) - { - ESP_LOGE(TAG, "reconnect(): failed to apply mqtt config: %s", esp_err_to_name(cfg_result)); - return cfg_result; - } - _config_dirty = false; - ESP_LOGD(TAG, "reconnect(): applied mqtt config update"); - } - else - { - ESP_LOGD(TAG, "reconnect(): mqtt config unchanged, skipping set_config"); - } + // A failed config update aborts the reconnect: reconnecting on the previous + // config was how a renewed token silently failed to reach the connection. + esp_err_t cfg_result = applyConfig(); + if (cfg_result != ESP_OK) return cfg_result; + esp_err_t r = esp_mqtt_client_reconnect(_client); if (r != ESP_OK) { diff --git a/lib/PsychicMqttClient/src/PsychicMqttClient.h b/lib/PsychicMqttClient/src/PsychicMqttClient.h index 5d214679e..93b85a437 100644 --- a/lib/PsychicMqttClient/src/PsychicMqttClient.h +++ b/lib/PsychicMqttClient/src/PsychicMqttClient.h @@ -345,6 +345,22 @@ public: */ bool connected(); + /** + * @brief Commits the pending configuration to the SDK client, creating it + * if it does not exist yet, WITHOUT starting it. + * + * Exists so a caller can tell "the configuration is now what I asked for" + * from "the client started": esp_mqtt_client_start() can fail after the + * configuration has been committed, and a caller that cannot distinguish + * those records a stale view of what the SDK actually holds. + * + * @return ESP_OK when the SDK client holds this configuration. + * ESP_ERR_INVALID_STATE if no URI is set, ESP_ERR_NO_MEM if the + * client could not be allocated, or the error from + * esp_mqtt_set_config() (which leaves the update pending). + */ + esp_err_t applyConfig(); + /** * @brief Connects the MQTT client to the server. * diff --git a/src/helpers/MQTTClientState.h b/src/helpers/MQTTClientState.h new file mode 100644 index 000000000..dd1fee44d --- /dev/null +++ b/src/helpers/MQTTClientState.h @@ -0,0 +1,82 @@ +#pragma once + +#include + +// What a slot's MQTT client is doing, as opposed to whether its network is up, +// and the two decisions that hang off it. +// +// Pure logic: no Arduino, esp-mqtt or bridge dependency, so the shutdown +// contract below is a host test rather than a hardware run. +// +// `client->connected()` answers "is the network up" and was being used for "is +// there anything to stop": a client resolving DNS, negotiating TLS or waiting +// after a failed CONNECT reports not-connected, so teardown skipped it and left +// its task running (F04). + +enum class MqttClientState : uint8_t { + Absent = 0, // no client object + Configured, // client allocated, never started + Starting, // start/reconnect requested, awaiting CONNECTED + Connected, // CONNECTED received + Disconnected, // started, no session (our reconnect ladder governs it) + Stopped, // stop completed; the SDK task is joined and gone + Quarantined, // stop failed: the SDK task was NOT joined. Never destroy, + // never reuse, never free anything it still points at. +}; + +static inline const char* mqttClientStateName(MqttClientState s) { + switch (s) { + case MqttClientState::Absent: return "absent"; + case MqttClientState::Configured: return "configured"; + case MqttClientState::Starting: return "starting"; + case MqttClientState::Connected: return "connected"; + case MqttClientState::Disconnected: return "disconnected"; + case MqttClientState::Stopped: return "stopped"; + case MqttClientState::Quarantined: return "quarantined"; + } + return "?"; +} + +// The client has been started and not proven stopped: it may still own a task, +// a socket and a TLS context. Quarantined is deliberately NOT live — it is +// worse: it may own them and we can never find out. +static inline bool mqttClientStateIsLive(MqttClientState s) { + return s == MqttClientState::Starting || s == MqttClientState::Connected || + s == MqttClientState::Disconnected; +} + +// A connection attempt is in flight, so an event for it can still arrive. +// Closing the transport is not enough here: PsychicMqttClient::softDisconnect() +// returns immediately when the client is not yet connected, which means an +// in-progress DNS/TLS/CONNECT is left to complete on its own. Cancelling one +// requires a real stop. +static inline bool mqttClientStateHasAttemptInFlight(MqttClientState s) { + return s == MqttClientState::Starting; +} + +// The SDK task is known to be gone (or never existed), so the object may be +// destroyed and anything it pointed at may be freed. +static inline bool mqttClientStateIsProvenStopped(MqttClientState s) { + return s == MqttClientState::Absent || s == MqttClientState::Configured || + s == MqttClientState::Stopped; +} + +// The bridge's cooperative stop may only be acknowledged when EVERY client is +// proven stopped. +// +// This is the invariant the whole shutdown contract rests on: the owner treats +// the acknowledgement as proof that the task destroyed its clients, and only +// then frees the queue and buffers and allows a restart. One client whose +// esp_mqtt_client_stop() never completed makes that false — its SDK task may +// still be running — so the acknowledgement must be withheld and the bridge +// left in its unproven state, however many other slots stopped cleanly. +static inline bool mqttStopMayBeAcknowledged(const MqttClientState* states, int count) { + // An empty set is trivially proven (no slots, nothing to stop); a null array + // with a nonzero count is a caller bug and must not read as proof. + if (count <= 0) return true; + if (states == nullptr) return false; + for (int i = 0; i < count; i++) { + if (!mqttClientStateIsProvenStopped(states[i])) return false; + } + return true; +} diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index da0fa3022..9e176c4b4 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -463,19 +463,6 @@ void MQTTBridge::applyWifiPowerSave() { #endif } -const char* MQTTBridge::clientStateName(ClientState st) { - switch (st) { - case ClientState::Absent: return "absent"; - case ClientState::Configured: return "configured"; - case ClientState::Starting: return "starting"; - case ClientState::Connected: return "connected"; - case ClientState::Disconnected: return "disconnected"; - case ClientState::Stopped: return "stopped"; - case ClientState::Quarantined: return "quarantined"; - } - return "?"; -} - bool MQTTBridge::stopUnprovenLatched() { return s_stop_unproven; } uint8_t MQTTBridge::getLastWifiDisconnectReason() { return s_wifi_disconnect_reason; } @@ -1444,6 +1431,29 @@ void MQTTBridge::mqttTaskLoop() { teardownSlot(i); } destroySlotClients(); + + // The acknowledgement means "every client is destroyed, nothing I own is + // still running". One client whose esp_mqtt_client_stop() never completed + // makes that false — destroySlotClients() deliberately skipped it and its + // SDK task may still be executing — so the ack must be WITHHELD, whatever + // the other slots did. Publishing it anyway would tell the owner to free + // the queue and buffers and allow a restart while that task lives, which + // is the ownership ambiguity this whole contract exists to remove. + MqttClientState states[RUNTIME_MQTT_SLOTS]; + for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) states[i] = _slots[i].client_state; + if (!mqttStopMayBeAcknowledged(states, RUNTIME_MQTT_SLOTS)) { + for (int i = 0; i < RUNTIME_MQTT_SLOTS; i++) { + if (!mqttClientStateIsProvenStopped(states[i])) { + MQTT_DEBUG_PRINTLN("MQTT%d stop unproven (%s) - withholding the bridge stop ack", + i + 1, mqttClientStateName(states[i])); + } + } + // Leave _teardown_complete false: the trampoline publishes no ack, the + // owner's stop times out into StopUnproven, and nothing is released or + // restarted for the rest of this boot. + return; + } + // Record that the ordered teardown finished, but do NOT publish the ack // here: the owner treats the ack as permission to free everything this // task can reach, and between this point and vTaskDelete(nullptr) the task @@ -1881,6 +1891,7 @@ void MQTTBridge::releaseSlotAuthToken(int index) { slot.auth_token = static_cast( MQTTRuntimeBufferLifecycle::release(slot.auth_token, psram_free)); slot.token_expires_at = 0; + slot.applied_token_expires_at = 0; slot.last_token_renewal = 0; } @@ -1902,14 +1913,11 @@ void MQTTBridge::destroySlotClients() { } if (clientStateIsLive(slot.client_state)) { - const esp_err_t r = slot.client->disconnect(); - if (r != ESP_OK && r != ESP_ERR_TIMEOUT) { - MQTT_DEBUG_PRINTLN("MQTT%d stop FAILED during shutdown (%s) - not destroying", i + 1, - esp_err_to_name(r)); - slot.client_state = ClientState::Quarantined; + stopSlotClient(i); + if (slot.client_state == ClientState::Quarantined) { + MQTT_DEBUG_PRINTLN("MQTT%d not destroyed: stop unproven during shutdown", i + 1); continue; } - slot.client_state = ClientState::Stopped; #ifdef ESP_PLATFORM vTaskDelay(pdMS_TO_TICKS(50)); #else @@ -1996,17 +2004,17 @@ bool MQTTBridge::setupSlot(int index) { // them. setCredentials / setServer below overwrite the config fields in place // before connect() restarts the ESP-IDF client. if (slot.initial_connect_done) { - // Close the transport (keeping the task) if this client is live, for the - // same reason applySlotPreset() does: a handshake in flight against the - // previous endpoint must not complete after the new config is applied. + // Same rule as applySlotPreset(): a handshake in flight against the previous + // endpoint must not survive the new configuration, and only a stop can + // cancel one. One helper so the two paths cannot drift apart. if (clientStateIsLive(slot.client_state)) { - const esp_err_t r = slot.client->softDisconnect(); - if (r != ESP_OK) { - MQTT_DEBUG_PRINTLN("MQTT%d re-apply: transport did not close cleanly (%s)", - index + 1, esp_err_to_name(r)); - } - slot.client_state = ClientState::Disconnected; + closeLiveClientForReconfigure(index); slot.generation++; + if (slot.client_state == ClientState::Quarantined) { + MQTT_DEBUG_PRINTLN("MQTT%d: cannot re-apply, stop unproven", index + 1); + slot.last_reconnect_attempt = millis(); + return false; + } } // The config fields are NOT cleared here any more. Two reasons: this block // only ran when initial_connect_done was set, which teardownSlot() clears @@ -2018,11 +2026,10 @@ bool MQTTBridge::setupSlot(int index) { if (slot.auth_token) slot.auth_token[0] = '\0'; slot.connected = false; slot.token_expires_at = 0; + slot.applied_token_expires_at = 0; slot.last_token_renewal = 0; - slot.reconnect_backoff = 0; - slot.max_backoff_failures = 0; - slot.circuit_breaker_tripped = false; slot.last_reconnect_attempt = 0; + // Ladder reset happens after the new configuration commits, below. // The refusal that set this belonged to the credentials being cleared here. _slot_force_jwt_mint[index] = false; } @@ -2243,6 +2250,18 @@ bool MQTTBridge::setupSlot(int index) { // credentials are written as "" rather than left alone: NULL means "leave // unchanged" to esp_mqtt_set_config(), while an empty string clears the // stored value and leaves the CONNECT's username flag clear. + // cfg_uri points at storage the slot owns (slot.broker_uri) or at flash + // (preset->server_url), and esp-mqtt keeps the pointer, so it must still hold + // what `desired` was built from. This caught a real bug: an earlier version of + // recreateSlotClient() ran the full slot teardown, which cleared broker_uri + // out from under the configuration that had already been decided, and the SDK + // was then handed an empty URI. + if (cfg_uri == nullptr || strcmp(cfg_uri, desired.uri) != 0) { + MQTT_DEBUG_PRINTLN("MQTT%d: broker URI changed under the config apply - not connecting", + index + 1); + slot.last_reconnect_attempt = millis(); + return false; + } slot.client->setServer(cfg_uri); if (desired.trust == MqttTrust::PemCert) { slot.client->setCACert(desired.pem); @@ -2255,6 +2274,29 @@ bool MQTTBridge::setupSlot(int index) { slot.client->setCredentials(mqttFieldOrEmpty(desired.username), mqttFieldOrEmpty(desired.password)); + // Commit the configuration as its own transaction, and record it as applied + // the moment it commits — not after the client starts. The SDK really does + // hold this configuration once set_config/init returns OK, so a start that + // fails afterwards must not leave the bridge believing the PREVIOUS config is + // applied: the next recreate-or-reuse decision would compare against it and + // could reuse a client whose trust policy is not the one it thinks. + const esp_err_t config_result = slot.client->applyConfig(); + if (config_result != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d config transaction failed (%s) - will retry", index + 1, + esp_err_to_name(config_result)); + slot.last_reconnect_attempt = millis(); + return false; + } + slot.applied_config = desired; + + // The new endpoint's history starts here, now that the configuration it + // belongs to is committed. Resetting the ladder in teardownSlot() cleared it + // before there was any replacement config — so a reconfigure that then failed + // to commit lost the backoff state that still applied to the old endpoint. + slot.reconnect_backoff = 0; + slot.max_backoff_failures = 0; + slot.circuit_breaker_tripped = false; + // Start or reconnect according to what the SDK client actually is, not what // the network is doing. esp_mqtt_client_start() fails on an already-started // client, so a reconfigure that kept the task (TeardownReason::Reconfigure) @@ -2268,9 +2310,8 @@ bool MQTTBridge::setupSlot(int index) { return false; } // reconnectSlotClient() moved the state to Starting and bumped the generation. - // Record what the client is now configured with, so the next apply can tell - // an in-place change from a structural one. - slot.applied_config = desired; + // applied_config was recorded at the commit above; activation records that the + // client also started. slot.initial_connect_done = true; return true; } @@ -2288,11 +2329,25 @@ bool MQTTBridge::recreateSlotClient(int index) { MQTTSlot& slot = _slots[index]; if (slot.client == nullptr) return ensureSlotClient(index); - teardownSlot(index, TeardownReason::Disable); // stop, do not just close the transport + // Stop the client only. NOT teardownSlot(): that is the "this slot is going + // away" path, and it clears the very state the in-flight setup is holding — + // broker_uri (which cfg_uri points at), the token just minted for this + // configuration, and both expiries. Recreation swaps the client object under + // a configuration that has already been decided; it must not disturb it. + if (clientStateIsLive(slot.client_state)) { + stopSlotClient(index); + slot.generation++; + #ifdef ESP_PLATFORM + vTaskDelay(pdMS_TO_TICKS(50)); + #else + delay(50); + #endif + } if (slot.client_state == ClientState::Quarantined) { MQTT_DEBUG_PRINTLN("MQTT%d cannot recreate: previous stop unproven", index + 1); return false; } + slot.connected = false; delete slot.client; slot.client = nullptr; @@ -2308,6 +2363,80 @@ bool MQTTBridge::recreateSlotClient(int index) { // the client object alive so a subsequent setupSlot() can reuse its mbedTLS // context. This is called both on reconfigure (preset change) and at shutdown; // destruction of the underlying client happens once in destroySlotClients(). +// Close a live client for a reconfigure: cheap where that is safe, a real stop +// where it is not. +// +// softDisconnect() cannot cancel a connection that has not completed. +// esp_mqtt_client_disconnect() acts on a live session, and the wrapper returns +// ESP_OK immediately when the client is not connected — so for a client +// mid-DNS/TLS/CONNECT nothing is closed and nothing is cancelled. That attempt +// would run to completion against the OLD endpoint and deliver its CONNECTED +// event after the new configuration was applied, indistinguishable from the new +// attempt's (F04): esp-mqtt gives events no generation of their own, and the +// callbacks are registered once per client, so there is nothing in the event to +// tell them apart. The only way to separate them is to make sure the old +// attempt is dead first, which means stopping the client and joining its task. +// +// That costs a stop/start cycle, but only when an operator reconfigures a slot +// *while it is connecting*. A Connected client still takes the cheap route, +// which is where the fragmentation argument actually applies. +void MQTTBridge::closeLiveClientForReconfigure(int index) { + MQTTSlot& slot = _slots[index]; + if (mqttClientStateHasAttemptInFlight(slot.client_state)) { + MQTT_DEBUG_PRINTLN("MQTT%d reconfigure during connect - stopping to cancel the attempt", + index + 1); + stopSlotClient(index); + return; + } + const esp_err_t r = slot.client->softDisconnect(); + if (r != ESP_OK) { + MQTT_DEBUG_PRINTLN("MQTT%d reconfigure: transport did not close cleanly (%s)", + index + 1, esp_err_to_name(r)); + } + slot.client_state = ClientState::Disconnected; +} + +// Stop a live client and record whether the stop was proven. ESP_ERR_TIMEOUT +// means no DISCONNECTED event arrived but esp_mqtt_client_stop() itself +// returned OK, so the SDK task is joined and the object is safe to reuse; any +// other error means it was NOT joined, and that client is out of service for +// the rest of the boot. +void MQTTBridge::stopSlotClient(int index) { + MQTTSlot& slot = _slots[index]; + const esp_err_t r = slot.client->disconnect(); + + // What the SDK's results actually mean here (mqtt_client.h documents + // esp_mqtt_client_stop as "ESP_OK on success, ESP_ERR_INVALID_ARG on wrong + // initialization, ESP_FAIL if client is in invalid state"): + // + // ESP_OK the SDK task was joined. + // ESP_ERR_TIMEOUT our own wrapper's code for "no DISCONNECTED event, but + // the stop itself returned OK" — the task is still joined. + // ESP_FAIL the client was not started. There was no task to join, + // which is the safest state of all. Treating this as a + // failure quarantined perfectly healthy clients — observed + // on hardware when a reconfigure landed on a slot whose + // connect attempt had already failed. + // + // The case that genuinely cannot be proven is a stop that never RETURNS: the + // SDK waits on its API mutex and the task's stopped event without a bound. + // That does not surface here at all — it hangs this task, which is exactly + // what the bridge-level stop timeout (StopUnproven) exists to contain. So + // with IDF 4.4's contract the branch below should be unreachable; it stays + // because acting on an unexpected result by not touching the client again is + // the only safe response if that ever changes. + if (r == ESP_OK || r == ESP_ERR_TIMEOUT || r == ESP_FAIL) { + if (r == ESP_FAIL) { + MQTT_DEBUG_PRINTLN("MQTT%d stop: client was not started (nothing to join)", index + 1); + } + slot.client_state = ClientState::Stopped; + return; + } + MQTT_DEBUG_PRINTLN("MQTT%d stop returned %s - client quarantined for this boot", + index + 1, esp_err_to_name(r)); + slot.client_state = ClientState::Quarantined; +} + void MQTTBridge::teardownSlot(int index, TeardownReason reason) { if (index < 0 || index >= RUNTIME_MQTT_SLOTS) return; MQTTSlot& slot = _slots[index]; @@ -2319,30 +2448,9 @@ void MQTTBridge::teardownSlot(int index, TeardownReason reason) { // already replaced or switched off (F04). if (slot.client && clientStateIsLive(slot.client_state)) { if (reason == TeardownReason::Reconfigure) { - // Close the transport, keep the task. The in-flight handshake cannot - // complete against the old endpoint any more, and the esp-mqtt task's - // 6 KiB stack does not get returned into the hole the mbedTLS record - // buffers just vacated (the documented fragmentation driver). - const esp_err_t r = slot.client->softDisconnect(); - if (r != ESP_OK) { - MQTT_DEBUG_PRINTLN("MQTT%d reconfigure: transport did not close cleanly (%s)", - index + 1, esp_err_to_name(r)); - } - slot.client_state = ClientState::Disconnected; + closeLiveClientForReconfigure(index); } else { - const esp_err_t r = slot.client->disconnect(); - if (r == ESP_OK || r == ESP_ERR_TIMEOUT) { - // ESP_ERR_TIMEOUT: no DISCONNECTED event, but the stop itself returned - // OK, so the SDK task is joined and the object is safe to reuse. - slot.client_state = ClientState::Stopped; - } else { - // The stop did not complete: the SDK task was not joined. Never touch - // this client again — not to reuse it, not to destroy it, and do not - // free the token buffer its config still points at. - MQTT_DEBUG_PRINTLN("MQTT%d stop FAILED (%s) - client quarantined for this boot", - index + 1, esp_err_to_name(r)); - slot.client_state = ClientState::Quarantined; - } + stopSlotClient(index); } slot.generation++; #ifdef ESP_PLATFORM @@ -2359,10 +2467,13 @@ void MQTTBridge::teardownSlot(int index, TeardownReason reason) { slot.initial_connect_done = false; slot.broker_uri[0] = '\0'; slot.token_expires_at = 0; + slot.applied_token_expires_at = 0; slot.last_token_renewal = 0; - slot.reconnect_backoff = 0; - slot.max_backoff_failures = 0; - slot.circuit_breaker_tripped = false; + // The reconnect ladder is deliberately NOT cleared here. It describes the + // endpoint this slot has been failing against, and that history still applies + // until a replacement configuration actually commits — setupSlot() clears it + // there. Clearing it on teardown meant a reconfigure that never committed + // (bad URI, failed config transaction) also forgave a tripped breaker. slot.last_reconnect_attempt = 0; slot.last_log_time = 0; slot.last_deferred_log_ms = 0; @@ -2397,6 +2508,9 @@ esp_err_t MQTTBridge::reconnectSlotClient(int index) { if (r == ESP_OK) { slot.client_state = ClientState::Starting; slot.generation++; + // The attempt carries whatever credential is configured right now, so this + // is the point at which a freshly minted token becomes the one in use. + slot.applied_token_expires_at = slot.token_expires_at; } return r; } @@ -2513,9 +2627,15 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns // exp on live sessions (waev's 55-minute tokens). const unsigned long renewal_buffer = MQTTConnectionPolicy::renewalBufferSecs( static_cast(slotTokenLifetime(index))); + // Against the APPLIED expiry — the credential the live connection is using — + // not the one sitting in the token buffer. Minting updates the buffer's + // expiry immediately, so reading that here meant a renewal whose bounce + // failed looked complete: the next pass saw a fresh future expiry, decided + // no renewal was due, and never retried the bounce. The connection stayed on + // the old credential until the broker enforced exp (F06). bool token_needs_renewal = MQTTConnectionPolicy::tokenNeedsRenewal( time_synced, static_cast(current_time), - static_cast(slot.token_expires_at), + static_cast(slot.applied_token_expires_at), static_cast(renewal_buffer)); // Throttle renewal attempts to once per minute @@ -2525,7 +2645,7 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns if (token_needs_renewal && can_attempt_renewal) { slot.last_token_renewal = now_millis; - unsigned long old_token_expires_at = slot.token_expires_at; + unsigned long old_token_expires_at = slot.applied_token_expires_at; if (createSlotAuthToken(index)) { MQTT_DEBUG_PRINTLN("MQTT%d token renewed", index + 1); @@ -2549,6 +2669,11 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns if (!exp_forces_bounce && old_token_expired_or_imminent && slot.client->connected()) { MQTT_DEBUG_PRINTLN("MQTT%d token renewed, no bounce (broker does not enforce exp)", index + 1); + // This broker does not act on exp, so the live session's older + // credential is not a problem and the renewal is complete. Recording + // it stops the renewal from staying due and re-attempting every + // minute for the rest of the token's life. + slot.applied_token_expires_at = slot.token_expires_at; } if (exp_forces_bounce || !slot.client->connected()) { // Disconnect + reconnect with fresh credentials, reusing existing client @@ -2585,9 +2710,13 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns // the renewal instead so the next maintenance pass retries the // bounce, and leave the reconnect ladder alone — this is a local // failure, not a broker fault. - MQTT_DEBUG_PRINTLN("MQTT%d renewal bounce failed (%s) - retrying next pass", + // Leave applied_token_expires_at pointing at the OLD credential: + // that is still what the connection is using, so the renewal stays + // due and the next pass retries the bounce (paced by the one-a- + // minute renewal throttle). The freshly minted token stays in the + // buffer and will be used by that retry, or by the next reconnect. + MQTT_DEBUG_PRINTLN("MQTT%d renewal bounce failed (%s) - still due, retrying", index + 1, esp_err_to_name(bounce_result)); - slot.last_token_renewal = 0; return; } MQTT_TRACE_HEAP("renewal:after-reconnect", index); @@ -2601,10 +2730,14 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns } else { // Token renewed but old one still valid — just update credentials for next reconnect slot.client->setCredentials(_jwt_username, slot.auth_token); + // Staged for the next reconnect, and the credential in use is still + // valid, so the renewal decision is settled for this token. + slot.applied_token_expires_at = slot.token_expires_at; } } else { MQTT_DEBUG_PRINTLN("MQTT%d token renewal failed", index + 1); slot.token_expires_at = 0; + slot.applied_token_expires_at = 0; } return; // Token renewal handled connect; skip backoff logic below } diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 6c81cfc2b..d919211de 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -12,6 +12,7 @@ #include "helpers/MQTTLifecycle.h" #include "helpers/AlertFaultPolicy.h" #include "helpers/MQTTEffectiveConfig.h" +#include "helpers/MQTTClientState.h" #include #ifdef WITH_SNMP @@ -105,29 +106,12 @@ private: static const uint32_t kNtpMinValidEpoch = 1767225600UL; // 2026-01-01 UTC static const uint32_t kNtpMaxValidEpoch = 4102444800UL; // 2100-01-01 UTC - // What the SDK client is doing, as opposed to whether the network is up. - // `client->connected()` answers the second question and was being used for - // the first: a client resolving DNS, negotiating TLS or waiting after a - // failed CONNECT reports not-connected, so teardown skipped it and left its - // task running (F04). Absent is 0 so a memset-initialised slot is correct. - enum class ClientState : uint8_t { - Absent = 0, // no client object - Configured, // client allocated, never started - Starting, // start/reconnect requested, awaiting CONNECTED - Connected, // CONNECTED received - Disconnected, // started, no session (our reconnect ladder governs it) - Stopped, // stop completed; the SDK task is joined and gone - Quarantined, // stop failed: the SDK task was NOT joined. Never destroy, - // never reuse, never free anything it still points at. - }; - - static const char* clientStateName(ClientState s); - // True while the SDK client has been started and not proven stopped, i.e. - // while it may still own a task, a socket and a TLS context. - static bool clientStateIsLive(ClientState s) { - return s == ClientState::Starting || s == ClientState::Connected || - s == ClientState::Disconnected; - } + // Per-slot SDK client state and the shutdown contract live in + // MQTTClientState.h so both are host-testable; ClientState is an alias so the + // bridge code reads naturally. + using ClientState = MqttClientState; + static const char* clientStateName(ClientState s) { return mqttClientStateName(s); } + static bool clientStateIsLive(ClientState s) { return mqttClientStateIsLive(s); } // Connection slot - each slot holds one MQTT connection struct MQTTSlot { @@ -158,7 +142,14 @@ private: // esp-mqtt re-reads it whenever a later connect() re-applies a dirtied config. // Freed only alongside the client in destroySlotClients(). char* auth_token; // nullptr or empty string = no valid token + // Two expiries, deliberately. token_expires_at describes the token in the + // buffer (minting updates it immediately); applied_token_expires_at + // describes the credential the CONNECTION is actually using, and only + // advances when a connect/reconnect has carried it. The renewal decision + // reads the applied one, so a renewal whose bounce failed stays due and is + // retried instead of looking complete (F06). unsigned long token_expires_at; + unsigned long applied_token_expires_at; unsigned long last_token_renewal; // Custom broker settings (only used when preset_name is "custom") @@ -547,6 +538,11 @@ private: // with it. Here the stop IS the point. enum class TeardownReason : uint8_t { Reconfigure, Disable }; void teardownSlot(int index, TeardownReason reason = TeardownReason::Disable); + // Close a live client for a reconfigure: softDisconnect where that is enough, + // a real stop where an in-flight connection attempt has to be cancelled. + void closeLiveClientForReconfigure(int index); + // Stop a live client, recording Stopped (proven) or Quarantined (not joined). + void stopSlotClient(int index); // Reconnect a slot, starting it instead when the client is stopped (reconnect() is a // no-op on a stopped client). See the definition. // ESP_OK when the reconnect/start was accepted by the SDK. A local failure diff --git a/test/test_mqtt_client_state/test_mqtt_client_state.cpp b/test/test_mqtt_client_state/test_mqtt_client_state.cpp new file mode 100644 index 000000000..9b0f7c36c --- /dev/null +++ b/test/test_mqtt_client_state/test_mqtt_client_state.cpp @@ -0,0 +1,89 @@ +#include "helpers/MQTTClientState.h" + +#include + +#include +#include + +namespace { + +const MqttClientState kAllStates[] = { + MqttClientState::Absent, MqttClientState::Configured, + MqttClientState::Starting, MqttClientState::Connected, + MqttClientState::Disconnected, MqttClientState::Stopped, + MqttClientState::Quarantined, +}; + +bool ack(std::vector states) { + return mqttStopMayBeAcknowledged(states.data(), (int)states.size()); +} + +} // namespace + +TEST(MqttClientState, LiveMeansStartedAndNotProvenStopped) { + EXPECT_TRUE(mqttClientStateIsLive(MqttClientState::Starting)); + EXPECT_TRUE(mqttClientStateIsLive(MqttClientState::Connected)); + EXPECT_TRUE(mqttClientStateIsLive(MqttClientState::Disconnected)); + + EXPECT_FALSE(mqttClientStateIsLive(MqttClientState::Absent)); + EXPECT_FALSE(mqttClientStateIsLive(MqttClientState::Configured)); + EXPECT_FALSE(mqttClientStateIsLive(MqttClientState::Stopped)); + // Quarantined is not "live": it is worse. It may own a task and we can never + // find out, which is why it is not simply lumped in with the live states. + EXPECT_FALSE(mqttClientStateIsLive(MqttClientState::Quarantined)); +} + +TEST(MqttClientState, OnlyStartingHasAnAttemptInFlight) { + for (MqttClientState s : kAllStates) { + EXPECT_EQ(s == MqttClientState::Starting, mqttClientStateHasAttemptInFlight(s)) + << mqttClientStateName(s); + } +} + +TEST(MqttClientState, ProvenStoppedIsTheComplementOfLiveAndQuarantined) { + for (MqttClientState s : kAllStates) { + const bool proven = mqttClientStateIsProvenStopped(s); + EXPECT_EQ(!mqttClientStateIsLive(s) && s != MqttClientState::Quarantined, proven) + << mqttClientStateName(s); + } +} + +// The invariant the shutdown contract rests on: the acknowledgement means the +// task destroyed its clients, so it may not be published while any client's +// stop is unproven. +TEST(MqttClientState, StopIsAcknowledgedOnlyWhenEveryClientIsProvenStopped) { + EXPECT_TRUE(ack({})); // no slots configured at all + EXPECT_TRUE(ack({MqttClientState::Absent, MqttClientState::Stopped, + MqttClientState::Configured})); + + // One quarantined client withholds the acknowledgement, whatever the others did. + EXPECT_FALSE(ack({MqttClientState::Quarantined})); + EXPECT_FALSE(ack({MqttClientState::Stopped, MqttClientState::Stopped, + MqttClientState::Quarantined, MqttClientState::Absent})); + EXPECT_FALSE(ack({MqttClientState::Quarantined, MqttClientState::Absent, + MqttClientState::Absent, MqttClientState::Absent, + MqttClientState::Absent, MqttClientState::Absent})); + + // So does a client that is merely still live: teardown did not finish it. + EXPECT_FALSE(ack({MqttClientState::Stopped, MqttClientState::Connected})); + EXPECT_FALSE(ack({MqttClientState::Starting})); + EXPECT_FALSE(ack({MqttClientState::Disconnected})); + + // An empty set is trivially proven; a null array with a nonzero count is a + // caller bug and must never read as proof. + EXPECT_TRUE(mqttStopMayBeAcknowledged(nullptr, 0)); + EXPECT_FALSE(mqttStopMayBeAcknowledged(nullptr, 3)); +} + +TEST(MqttClientState, EveryStateHasAName) { + for (MqttClientState s : kAllStates) { + ASSERT_NE(nullptr, mqttClientStateName(s)); + EXPECT_GT(strlen(mqttClientStateName(s)), 0u); + } + EXPECT_STREQ("quarantined", mqttClientStateName(MqttClientState::Quarantined)); +} + +int main(int argc, char** argv) { + ::testing::InitGoogleTest(&argc, argv); + return RUN_ALL_TESTS(); +} From e600d1a39838c5fdc364d4f9f29d76f211036ad2 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 9 Sep 2026 20:03:13 -0700 Subject: [PATCH 14/19] fix(mqtt): stop accepting time from lwIP SNTP, which validates nothing here (F07) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The review asked for the pinned SNTP implementation's response checking to be established rather than assumed. It is `SNTP_CHECK_RESPONSE = 0`: the lwIP default in `lwip/src/include/lwip/apps/sntp_opts.h`, not overridden in this build's ESP32 `lwipopts.h` or any sdkconfig — and lwIP ships precompiled in the SDK, so no `-D` of ours can change it. At 0 it checks neither that the reply came from the server it queried nor that the originate timestamp matches the request it sent. Those are two of the checks that make the new validated probe trustworthy, so SNTP was strictly weaker than the path it backed up. It was reachable three ways, all of which set the system clock: - the fallback inside `syncTimeWithNTP()`, which ran precisely when the validated probe had failed — i.e. when interference is most likely; - `refreshNTP()`, hourly, for the life of the node; - `configTime()` after a *successful* validated sync, whose timezone side effect was all that was wanted but which also left a background SNTP poller running that would go on accepting unvalidated replies. All three are gone. The periodic refresh runs the same validated probe as every other sync, and the timezone is set directly with `setenv("TZ", "UTC0")` + `tzset()`. Nothing is lost operationally: SNTP queried the same servers over the same UDP/123 with a weaker parser. The RTC/system-clock fallback is a separate decision and stays. --- src/helpers/bridges/MQTTBridge.cpp | 90 ++++++++++++------------------ src/helpers/bridges/MQTTBridge.h | 4 +- 2 files changed, 37 insertions(+), 57 deletions(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 9e176c4b4..d1c866e22 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -25,7 +25,6 @@ #include #include #include -#include #include #include #include @@ -4490,13 +4489,14 @@ void MQTTBridge::storeRawRadioData(const uint8_t* raw_data, int len, float snr, // NTP time sync // --------------------------------------------------------------------------- +// Periodic refresh. This used to call configTime(), i.e. start lwIP's SNTP and +// let it set the system clock asynchronously — an acceptance path with NO +// validation of its own (see the syncTimeWithNTP() note below), running every +// hour for the life of the node. It now goes through the same validated probe +// as every other sync, which costs the MQTT task about a second per attempt and +// touches nothing until a reply passes every check. void MQTTBridge::refreshNTP() { - // Lightweight periodic refresh: just restart SNTP which runs async in the background. - // No blocking DNS, no UDP sockets, no retry loops on the MQTT task loop. - // The heavy syncTimeWithNTP() is only used for initial sync and WiFi reconnect recovery. - configTime(0, 0, effectiveNtpPrimary(_obs)); - _last_ntp_sync = millis(); - MQTT_DEBUG_PRINTLN("NTP refresh triggered (async SNTP)"); + syncTimeWithNTP(/*force=*/true, /*primary_only=*/false); } // One validated NTP exchange with one named server, on a fresh ephemeral socket. @@ -4656,48 +4656,27 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { } } - // Fallback: use ESP32 built-in SNTP (configTime) when no server passed validation - #ifdef ESP_PLATFORM - if (!ntp_ok) { - MQTT_DEBUG_PRINTLN("NTP client failed, trying SNTP fallback..."); - for (int s = 0; s < server_count && !ntp_ok; s++) { - const char* server = servers[s]; - MQTT_DEBUG_PRINTLN("SNTP fallback trying %s...", server); - // A plausible clock is not evidence this server answered. The device usually - // already holds valid time here — from an earlier sync, or the RTC — so polling - // time(nullptr) declared the very first server successful without a packet ever - // arriving, stopped the fallback walk there, and refreshed _last_ntp_sync. Worse - // on the `set mqtt.ntp` validation path, where a typo is supposed to fail fast. - // Wait for SNTP itself to report completion. The status is one-shot — reading - // COMPLETED clears it — so drop any result an earlier sync left behind, and do - // that *before* starting this one: configTime() returns after sntp_init(), so a - // fast reply can complete inside it, and clearing afterwards would erase the - // very result being waited for. - if (sntp_enabled()) { - sntp_stop(); - } - sntp_set_sync_status(SNTP_SYNC_STATUS_RESET); - configTime(0, 0, server); - for (int i = 0; i < 20; i++) { - delay(500); - if (sntp_get_sync_status() != SNTP_SYNC_STATUS_COMPLETED) continue; - epochTime = (unsigned long)time(nullptr); - if (epochTime >= kMinValidEpoch) { - ntp_ok = true; - ntp_server_used = server; - MQTT_DEBUG_PRINTLN("SNTP fallback succeeded on %s: %lu", server, epochTime); - } else { - MQTT_DEBUG_PRINTLN("SNTP fallback: %s synced an implausible epoch %lu", server, epochTime); - } - break; - } - } - } - #endif + // There is deliberately no SNTP fallback here any more. + // + // It used to call configTime() and accept SNTP_SYNC_STATUS_COMPLETED plus a + // plausible epoch. lwIP's SNTP checks its own response only as far as + // SNTP_CHECK_RESPONSE allows, and in this build that is **0**: the default in + // lwip/src/include/lwip/apps/sntp_opts.h, not overridden in the ESP32 + // lwipopts.h or any sdkconfig here — and lwIP is shipped precompiled in the + // SDK, so a -D from our build cannot change it. At 0 it verifies neither that + // the reply came from the server it queried nor that the originate timestamp + // matches the request it sent. Those are exactly the two checks that make the + // probe above trustworthy, so the fallback was strictly weaker than the path + // it backed up — and it ran precisely when the validated path had failed, + // which is when interference is most likely. + // + // Nothing is lost operationally: it queried the same servers over the same + // UDP/123 with a weaker parser. The RTC/system-clock fallback below is a + // separate decision and stays. - // No server answered, but the clock itself may still be usable. Requiring a real - // SNTP completion above removed something the plausible-clock test was doing by - // accident: an RTC-backed device on a network that blocks NTP (UDP/123) while + // No server answered, but the clock itself may still be usable. Requiring a + // validated reply above removed something the old plausible-clock test was + // doing by accident: an RTC-backed device on a network that blocks NTP (UDP/123) while // allowing the broker (443) stayed synced and kept minting JWTs. _ntp_synced gates // slot setup outright, so losing that strands those deployments with no slots at // all. Keep the behaviour, but as its own decision rather than as a claim about a @@ -4734,13 +4713,14 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { accepted.tv_usec = 0; settimeofday(&accepted, nullptr); - // Only when a server supplied the accepted epoch. The fallback above necessarily - // points configTime() at each server before knowing whether it replies; this is - // the post-acceptance call, and there is nothing to re-point it at when the epoch - // came from a local clock. - if (ntp_server_used) { - configTime(0, 0, ntp_server_used); - } + // Keep the process timezone at UTC without starting lwIP's SNTP. This used + // to be configTime(0, 0, ntp_server_used), whose timezone side effect is all + // that was wanted here — the rest of it starts a background SNTP poller that + // would go on setting the clock from replies nothing validates, for the life + // of the node (see the note where the SNTP fallback used to be). System time + // is UTC; the prefs Timezone is applied separately by the message builders. + setenv("TZ", "UTC0", 1); + tzset(); if (_rtc) { _rtc->setCurrentTime(epochTime); diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index d919211de..8d180a48b 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -285,7 +285,7 @@ private: volatile bool _status_publish_pending[RUNTIME_MQTT_SLOTS]; // CLI-requested forced NTP sync, marshalled onto the MQTT task (Core 0). - // All NTP I/O (_ntp_client, configTime) must run on Core 0; the CLI thread + // All NTP I/O must run on Core 0; the CLI thread // (Core 1) sets _ntp_force_requested and blocks in requestForcedNtpSync() // until the task publishes the outcome via _ntp_force_result/_ntp_force_done. // Single-requester assumption: CLI commands are serialized, so at most one @@ -296,7 +296,7 @@ private: // CLI-requested NTP connectivity diagnostic, marshalled onto the MQTT task (Core 0) // with the same handshake as the forced sync. Probe-only: it queries each server and - // records the reported time but never calls configTime()/setCurrentTime(), so the + // records the reported time but never sets the system clock or the RTC, so the // system clock is left untouched. Results are written by the task and read by the CLI // thread once _ntp_diag_done is set. volatile bool _ntp_diag_requested; From 0ff3408564f3a509360f99b8900b3c26e1c381a0 Mon Sep 17 00:00:00 2001 From: agessaman Date: Sat, 19 Sep 2026 11:27:01 -0700 Subject: [PATCH 15/19] fix(wifi): keep the legacy power-save default off; store explicit min as 3 Stored 0 was the shipped default from 2026-01-02 to 2026-03-28, and every association path has run it with power save off since. Reading it as MIN_MODEM, as F11 did, would have put every node set up in that window into modem sleep on its next association. 0 now reads as `none`, and `set wifi.powersave min` stores a new value 3. /mqtt.json accepts 0..3; older firmware repairs 3 to `none` on load. Binary snapshots are no longer written, so 3 never reaches a legacy layout. --- src/helpers/MQTTPrefsSerializer.h | 3 ++- src/helpers/WifiPowerSavePolicy.h | 15 +++++++++------ .../test_wifi_power_save_policy.cpp | 14 ++++++++++++-- 3 files changed, 23 insertions(+), 9 deletions(-) diff --git a/src/helpers/MQTTPrefsSerializer.h b/src/helpers/MQTTPrefsSerializer.h index f783b52c4..e256e6a9d 100644 --- a/src/helpers/MQTTPrefsSerializer.h +++ b/src/helpers/MQTTPrefsSerializer.h @@ -4,6 +4,7 @@ #include #include #include +#include #ifdef WITH_MQTT_BRIDGE @@ -50,7 +51,7 @@ class MQTTPrefsSerializer : public ConfigSerializer { public: explicit WifiPrefs(MQTTPrefs* prefs) : _prefs(prefs), _power_save(prefs->wifi_power_save) {} bool apply(bool* repaired) { - if (_power_save < 0 || _power_save > 2) { + if (_power_save < 0 || _power_save > WifiPowerSavePolicy::kMaxStoredValue) { _power_save = 1; *repaired = true; } diff --git a/src/helpers/WifiPowerSavePolicy.h b/src/helpers/WifiPowerSavePolicy.h index bdebd57e1..bb8a35719 100644 --- a/src/helpers/WifiPowerSavePolicy.h +++ b/src/helpers/WifiPowerSavePolicy.h @@ -11,15 +11,18 @@ // to `min` silently ran with power save off after its first reconnect while // `get wifi.powersave` still said min. // -// Stored values are fleet state — never renumber them. The product default is -// `none`, which is a *default* (MQTTDefaults.h), not a reinterpretation of an -// operator's explicit `min`. +// Stored values are fleet state — never renumber them. 0 was the shipped +// default from 2026-01-02 to 2026-03-28, and every association path ran it with +// power save off, so it keeps meaning `none`; an explicit `min` is stored as 3. +// Older firmware repairs 3 to `none` when it loads /mqtt.json. namespace WifiPowerSavePolicy { enum StoredValue : uint8_t { - kMin = 0, // WIFI_PS_MIN_MODEM - kNone = 1, // WIFI_PS_NONE (default) - kMax = 2, // WIFI_PS_MAX_MODEM + kLegacyDefault = 0, // WIFI_PS_NONE: the old default, never an operator choice + kNone = 1, // WIFI_PS_NONE (default) + kMax = 2, // WIFI_PS_MAX_MODEM + kMin = 3, // WIFI_PS_MIN_MODEM + kMaxStoredValue = kMin, }; // Mirrors wifi_ps_type_t. MQTTBridge.cpp static_asserts these against the SDK. diff --git a/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp b/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp index 66803aa5e..35eb39f94 100644 --- a/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp +++ b/test/test_wifi_power_save_policy/test_wifi_power_save_policy.cpp @@ -13,8 +13,18 @@ TEST(WifiPowerSavePolicy, StoredValuesMapToOneModeEach) { EXPECT_EQ(kModeMaxModem, modeFor(kMax)); } +// Stored 0 was the default for nodes set up 2026-01-02..03-28, and they have +// always run with power save off; reading it as `min` would put them to sleep. +TEST(WifiPowerSavePolicy, LegacyDefaultKeepsPowerSaveOff) { + EXPECT_EQ(kModeNone, modeFor(kLegacyDefault)); + EXPECT_STREQ("none", nameFor(kLegacyDefault)); + uint8_t parsed = 0xFF; + ASSERT_TRUE(parseName("min", &parsed)); + EXPECT_NE(kLegacyDefault, parsed); +} + TEST(WifiPowerSavePolicy, NamesRoundTripWithStoredValues) { - for (uint8_t stored = 0; stored <= 2; stored++) { + for (uint8_t stored = kNone; stored <= kMaxStoredValue; stored++) { uint8_t parsed = 0xFF; ASSERT_TRUE(parseName(nameFor(stored), &parsed)) << "stored " << (int)stored; EXPECT_EQ(stored, parsed); @@ -25,7 +35,7 @@ TEST(WifiPowerSavePolicy, NamesRoundTripWithStoredValues) { // A byte outside the stored range must read as the product default, not as // whatever mode happens to sit at that index. TEST(WifiPowerSavePolicy, OutOfRangeStoredValueReadsAsDefault) { - for (int stored = 3; stored <= 255; stored++) { + for (int stored = kMaxStoredValue + 1; stored <= 255; stored++) { EXPECT_EQ(kModeNone, modeFor((uint8_t)stored)) << "stored " << stored; EXPECT_STREQ("none", nameFor((uint8_t)stored)); } From 3c03254aa2619e2952b7ac7a6e11b041fa52caa1 Mon Sep 17 00:00:00 2001 From: agessaman Date: Sat, 19 Sep 2026 11:27:01 -0700 Subject: [PATCH 16/19] fix(mqtt): resume after a late stop ack; bound the hourly NTP refresh - A stop that timed out into StopUnproven refused begin(), and only a later begin() honoured the task's late acknowledgement. Nothing called it, so restartBridge() (any `set mqtt...` restart) or an aborted OTA left the observer offline for the rest of the boot. MyMesh now records that a start was refused and restarts the bridge once stopAcknowledgedLate() reports the ack. The OTA-abort alert no longer claims "bridge resumed" when the restart was refused. - refreshNTP() now runs the validated probe with one attempt per server. With two attempts and a 1 s pause it blocked the MQTT task ~18 s every hour on networks that drop UDP/123, where the old async SNTP cost nothing. Loop comment and docs updated to match. --- MQTT_IMPLEMENTATION.md | 2 +- examples/simple_repeater/MyMesh.cpp | 12 +++++++++++- examples/simple_repeater/MyMesh.h | 7 +++++++ examples/simple_room_server/MyMesh.cpp | 9 +++++++++ examples/simple_room_server/MyMesh.h | 7 +++++++ src/helpers/bridges/MQTTBridge.cpp | 25 +++++++++++++++++-------- src/helpers/bridges/MQTTBridge.h | 5 ++++- 7 files changed, 56 insertions(+), 11 deletions(-) diff --git a/MQTT_IMPLEMENTATION.md b/MQTT_IMPLEMENTATION.md index 56f43569a..b46714877 100644 --- a/MQTT_IMPLEMENTATION.md +++ b/MQTT_IMPLEMENTATION.md @@ -883,7 +883,7 @@ the radio actually performs in that case. ### NTP Time Synchronization - Automatic time synchronization with NTP servers (required for JWT authentication) - Default primary: `pool.ntp.org`; built-in fallbacks (tried sequentially on failure): `time.google.com`, `time.cloudflare.com`, `time.aws.com`, `time.nist.gov` -- Periodic time updates (every hour) on the effective primary only; system time is kept in UTC +- Periodic time updates (every hour) through the same validated probe, one attempt per server in list order; system time is kept in UTC - Replies are validated before they are trusted: the datagram must be a full-length NTPv3/v4 server reply from the queried address and port, from a synchronised server (stratum 1-15, no leap alarm), echoing the random transmit timestamp of the request, with a plausible epoch. Anything else is discarded and the clock, the RTC and JWT issuance are left alone - Configure and diagnose with `set mqtt.ntp` / `get mqtt.ntp` / `get mqtt.ntp.diag` — see [MQTT Shared Commands](#mqtt-shared-commands) diff --git a/examples/simple_repeater/MyMesh.cpp b/examples/simple_repeater/MyMesh.cpp index 75d9fb4ee..93dbe2790 100644 --- a/examples/simple_repeater/MyMesh.cpp +++ b/examples/simple_repeater/MyMesh.cpp @@ -1699,6 +1699,15 @@ void MyMesh::loop() { // MQTT processing runs in a separate FreeRTOS task on Core 0, so we don't call bridge.loop() here mesh::Mesh::loop(); +#ifdef WITH_MQTT_BRIDGE + // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; + // once that late ack lands, restart the bridge that was meant to be running. + if (_bridge_resume_pending && bridge && bridge->stopAcknowledgedLate()) { + Serial.println("MQTT: stop acknowledged late - resuming bridge"); + setBridgeState(true); + } +#endif + #ifdef WITH_BRIDGE // bridge.loop() is now handled by FreeRTOS task on Core 0 - no need to call it here #endif @@ -1752,8 +1761,9 @@ void MyMesh::loop() { // resume the bridge instead of flashing under uncertain ownership. if (bridge && !bridge->canFlashAfterStop()) { Serial.println("OTA: aborted, MQTT stop did not complete cleanly - resuming bridge"); - otaAlert("OTA aborted: MQTT stop unclean, bridge resumed"); setBridgeState(true); + otaAlert(bridge->isRunning() ? "OTA aborted: MQTT stop unclean, bridge resumed" + : "OTA aborted: MQTT stop unproven, bridge resumes when it completes"); } else if (!_cli.getBoard()->otaFromManifest(getFirmwareVer(), false, ota_reply)) { Serial.print("OTA: aborted, resuming bridge - "); Serial.println(ota_reply); char ota_alert_msg[160]; diff --git a/examples/simple_repeater/MyMesh.h b/examples/simple_repeater/MyMesh.h index 539a17154..3dd8587b6 100644 --- a/examples/simple_repeater/MyMesh.h +++ b/examples/simple_repeater/MyMesh.h @@ -137,6 +137,8 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks ESPNowBridge bridge; #elif defined(WITH_MQTT_BRIDGE) MQTTBridge* bridge; + // begin() was refused after an unproven stop; restart once the task acknowledges. + bool _bridge_resume_pending = false; #endif #ifdef WITH_SNMP MeshSNMPAgent _snmp_agent; @@ -368,6 +370,7 @@ public: bridge->begin(); #ifdef WITH_MQTT_BRIDGE _alerter.setBridge(bridge); + _bridge_resume_pending = !bridge->isRunning() && bridge->isStopUnproven(); #endif } else @@ -375,6 +378,7 @@ public: bridge->end(); #ifdef WITH_MQTT_BRIDGE _alerter.setBridge(nullptr); + _bridge_resume_pending = false; #endif } } @@ -400,6 +404,9 @@ public: bridge->setStatsSources(this, _radio, _cli.getBoard(), _ms); #endif bridge->begin(); +#ifdef WITH_MQTT_BRIDGE + _bridge_resume_pending = !bridge->isRunning() && bridge->isStopUnproven(); +#endif } void restartBridgeSlot(int slot) override { diff --git a/examples/simple_room_server/MyMesh.cpp b/examples/simple_room_server/MyMesh.cpp index e6bed7d60..956b59596 100644 --- a/examples/simple_room_server/MyMesh.cpp +++ b/examples/simple_room_server/MyMesh.cpp @@ -1514,6 +1514,15 @@ void MyMesh::loop() { // Check radio FIRST to ensure we don't miss incoming packets // MQTT processing can take time, so we prioritize radio reception mesh::Mesh::loop(); + +#ifdef WITH_MQTT_BRIDGE + // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; + // once that late ack lands, restart the bridge that was meant to be running. + if (_bridge_resume_pending && bridge && bridge->stopAcknowledgedLate()) { + Serial.println("MQTT: stop acknowledged late - resuming bridge"); + setBridgeState(true); + } +#endif #ifdef WITH_MQTT_BRIDGE // bridge.loop() is now handled by FreeRTOS task on Core 0 - no need to call it here #endif diff --git a/examples/simple_room_server/MyMesh.h b/examples/simple_room_server/MyMesh.h index 47f2f68d7..0139fa5a7 100644 --- a/examples/simple_room_server/MyMesh.h +++ b/examples/simple_room_server/MyMesh.h @@ -205,6 +205,8 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks #endif #ifdef WITH_MQTT_BRIDGE MQTTBridge* bridge; + // begin() was refused after an unproven stop; restart once the task acknowledges. + bool _bridge_resume_pending = false; #endif #ifdef WITH_SNMP MeshSNMPAgent _snmp_agent; @@ -385,6 +387,7 @@ public: bridge->begin(); #ifdef WITH_MQTT_BRIDGE _alerter.setBridge(bridge); + _bridge_resume_pending = !bridge->isRunning() && bridge->isStopUnproven(); #endif } else @@ -392,6 +395,7 @@ public: bridge->end(); #ifdef WITH_MQTT_BRIDGE _alerter.setBridge(nullptr); + _bridge_resume_pending = false; #endif } } @@ -416,6 +420,9 @@ public: bridge->setStatsSources(this, _radio, _cli.getBoard(), _ms); #endif bridge->begin(); +#ifdef WITH_MQTT_BRIDGE + _bridge_resume_pending = !bridge->isRunning() && bridge->isStopUnproven(); +#endif } void restartBridgeSlot(int slot) override { diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index d1c866e22..2f8d69ef1 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -464,6 +464,14 @@ void MQTTBridge::applyWifiPowerSave() { bool MQTTBridge::stopUnprovenLatched() { return s_stop_unproven; } +bool MQTTBridge::stopAcknowledgedLate() const { +#ifdef ESP_PLATFORM + return _lifecycle.isStopUnproven() && _stop_acked.load(std::memory_order_acquire); +#else + return false; +#endif +} + uint8_t MQTTBridge::getLastWifiDisconnectReason() { return s_wifi_disconnect_reason; } unsigned long MQTTBridge::getLastWifiDisconnectTime() { return s_wifi_disconnect_time; } @@ -1644,9 +1652,9 @@ void MQTTBridge::mqttTaskLoop() { // Periodic configuration check (throttled to avoid spam) checkConfigurationMismatch(); - // Periodic NTP refresh (every hour) — lightweight, non-blocking. - // Uses async SNTP instead of the heavy syncTimeWithNTP() which blocks Core 0 - // for up to 20+ seconds with DNS lookups, UDP sockets, and retry loops. + // Periodic NTP refresh (every hour): a validated probe, one attempt per + // server. Blocks this task for about one probe timeout per server that does + // not answer (see refreshNTP()). if (WiFi.status() == WL_CONNECTED && now - _last_ntp_sync > 3600000) { refreshNTP(); } @@ -4493,10 +4501,11 @@ void MQTTBridge::storeRawRadioData(const uint8_t* raw_data, int len, float snr, // let it set the system clock asynchronously — an acceptance path with NO // validation of its own (see the syncTimeWithNTP() note below), running every // hour for the life of the node. It now goes through the same validated probe -// as every other sync, which costs the MQTT task about a second per attempt and -// touches nothing until a reply passes every check. +// as every other sync and touches nothing until a reply passes every check. +// One attempt per server bounds the blocking walk on a network that drops +// UDP/123 to about one probe timeout per server, instead of three. void MQTTBridge::refreshNTP() { - syncTimeWithNTP(/*force=*/true, /*primary_only=*/false); + syncTimeWithNTP(/*force=*/true, /*primary_only=*/false, /*attempts_per_server=*/1); } // One validated NTP exchange with one named server, on a fresh ephemeral socket. @@ -4599,7 +4608,7 @@ bool MQTTBridge::probeNtpServer(const char* server, uint32_t min_epoch, return accepted; } -bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { +bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only, int attempts_per_server) { if (!WiFi.isConnected()) { MQTT_DEBUG_PRINTLN("Cannot sync time - WiFi not connected"); return false; @@ -4634,7 +4643,7 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only) { const uint32_t kMinValidEpoch = kNtpMinValidEpoch; const char* ntp_server_used = nullptr; - const int kMaxNtpRetriesPerServer = 2; + const int kMaxNtpRetriesPerServer = attempts_per_server > 0 ? attempts_per_server : 1; for (int s = 0; s < server_count && !ntp_ok; s++) { const char* server = servers[s]; diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 8d180a48b..e733044ff 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -743,6 +743,9 @@ public: // the bridge is down, nothing was released, and it will not restart until the // task acknowledges late (pollLateStopAck) or the node reboots. bool isStopUnproven() const { return _lifecycle.isStopUnproven(); } + // The unproven stop has since been acknowledged, so begin() will release the + // withheld resources and start. Loop task only. + bool stopAcknowledgedLate() const; // Survives end() clearing the diagnostic singleton, so `get mqtt.status` can // still explain why a stopped bridge will not come back without a reboot. static bool stopUnprovenLatched(); @@ -787,7 +790,7 @@ public: * mistyped hostname fails fast instead of blocking through the whole fallback list. * Performs blocking NTP I/O and must only be called from the MQTT task (Core 0). * Other tasks (e.g. the CLI on Core 1) must use requestForcedNtpSync() instead. */ - bool syncTimeWithNTP(bool force = false, bool primary_only = false); + bool syncTimeWithNTP(bool force = false, bool primary_only = false, int attempts_per_server = 2); /** Request a forced NTP sync from another task (e.g. CLI on Core 1). Marshals the * work onto the MQTT task so all NTP I/O stays on Core 0, then blocks up to * timeout_ms for the result. Returns true if the sync succeeded, false on failure, From 109d7d6128fe250ecdec19598d2829a711213a1f Mon Sep 17 00:00:00 2001 From: agessaman Date: Sat, 19 Sep 2026 11:48:43 -0700 Subject: [PATCH 17/19] fix(mqtt): record the renewed token as applied after a successful bounce The renewal bounce called reconnect()/connect() directly, so a successful bounce never advanced applied_token_expires_at. The renewal decision reads that value, so a renewed slot stayed due and, on a broker that enforces exp, minted and reconnected every minute for the rest of the token's life. Both the renewal bounce and the corrected-clock bounce now go through reconnectSlotClient(), which starts a stopped client, refuses a quarantined one, moves the slot to Starting and records the token in use. The corrected-clock no-bounce case settles the renewal as the renewal path already does. --- src/helpers/bridges/MQTTBridge.cpp | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 2f8d69ef1..1e807d414 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -2687,7 +2687,6 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns // to avoid internal heap leak/fragmentation from destroy/create cycles MQTT_DEBUG_PRINTLN("MQTT%d token renewal: reconnecting with fresh credentials", index + 1); MQTT_TRACE_HEAP("renewal:before-bounce", index); - esp_err_t bounce_result; if (slot.client->isStarted()) { // Keep the esp-mqtt task alive across the handshake. disconnect() // would stop it, returning its 6 KiB stack into the hole the two @@ -2699,15 +2698,13 @@ void MQTTBridge::maintainSlotConnection(int index, unsigned long now_millis, uns index + 1, esp_err_to_name(soft)); } MQTT_TRACE_HEAP("renewal:after-disconnect", index); - slot.client->setCredentials(_jwt_username, slot.auth_token); - MQTT_TRACE_HEAP("renewal:after-credentials", index); - bounce_result = slot.client->reconnect(); - } else { - // Client was stopped (teardown/reconfigure). reconnect() is a no-op - // on a stopped client, so this path must start it. - slot.client->setCredentials(_jwt_username, slot.auth_token); - bounce_result = slot.client->connect(); } + slot.client->setCredentials(_jwt_username, slot.auth_token); + MQTT_TRACE_HEAP("renewal:after-credentials", index); + // Via the helper: it starts a stopped client, refuses a quarantined one, + // and on success records the fresh token as the one in use, which is + // what keeps the renewal from coming due again a minute later. + const esp_err_t bounce_result = reconnectSlotClient(index); if (bounce_result != ESP_OK) { // The fresh token is in the buffer but did not reach the // connection: the config transaction failed, or the client would @@ -4784,7 +4781,8 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only, int attempts_per MQTT_DEBUG_PRINTLN("MQTT%d soft disconnect did not complete (%s)", i + 1, esp_err_to_name(soft)); } - const esp_err_t rc = _slots[i].client->reconnect(); + // Via the helper, so the re-created token is recorded as applied. + const esp_err_t rc = reconnectSlotClient(i); if (rc != ESP_OK) { MQTT_DEBUG_PRINTLN("MQTT%d corrected-clock reconnect failed (%s)", i + 1, esp_err_to_name(rc)); @@ -4792,6 +4790,8 @@ bool MQTTBridge::syncTimeWithNTP(bool force, bool primary_only, int attempts_per } else { MQTT_DEBUG_PRINTLN("MQTT%d token re-created, no bounce (broker does not enforce exp)", i + 1); + // As in the renewal path: this broker ignores exp, so the renewal is settled. + _slots[i].applied_token_expires_at = _slots[i].token_expires_at; } } } From 0b75cb9314a32ccbd4d77dbb761b841879bd066d Mon Sep 17 00:00:00 2001 From: agessaman Date: Sat, 19 Sep 2026 13:58:49 -0700 Subject: [PATCH 18/19] fix(mqtt): an explicit bridge stop cancels a pending late-ack resume setBridgeState(false) returned early when the bridge was already down, so `set bridge.enabled off` after a timed-out restart left the resume pending and MQTT restarted against the operator's choice once the task acknowledged. Disabling now clears the pending resume before that early return, and the resume also requires bridge_enabled. The StopUnproven log and `get mqtt.status` no longer say only "reboot to recover", since a late ack now recovers on its own. Hardware (Heltec V4, 5 live slots, 1 s test stop deadline): a restart went StopUnproven, the task acknowledged 27 s later and the bridge resumed with all slots reconnecting; with `set bridge.enabled off` in between it stayed stopped until `set bridge.enabled on`. --- examples/simple_repeater/MyMesh.cpp | 3 ++- examples/simple_repeater/MyMesh.h | 3 +++ examples/simple_room_server/MyMesh.cpp | 3 ++- examples/simple_room_server/MyMesh.h | 3 +++ src/helpers/bridges/MQTTBridge.cpp | 6 +++--- 5 files changed, 13 insertions(+), 5 deletions(-) diff --git a/examples/simple_repeater/MyMesh.cpp b/examples/simple_repeater/MyMesh.cpp index 93dbe2790..f9bdf7a18 100644 --- a/examples/simple_repeater/MyMesh.cpp +++ b/examples/simple_repeater/MyMesh.cpp @@ -1702,7 +1702,8 @@ void MyMesh::loop() { #ifdef WITH_MQTT_BRIDGE // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; // once that late ack lands, restart the bridge that was meant to be running. - if (_bridge_resume_pending && bridge && bridge->stopAcknowledgedLate()) { + if (_bridge_resume_pending && _prefs.bridge_enabled && bridge && + bridge->stopAcknowledgedLate()) { Serial.println("MQTT: stop acknowledged late - resuming bridge"); setBridgeState(true); } diff --git a/examples/simple_repeater/MyMesh.h b/examples/simple_repeater/MyMesh.h index 3dd8587b6..4b12f6d0c 100644 --- a/examples/simple_repeater/MyMesh.h +++ b/examples/simple_repeater/MyMesh.h @@ -353,6 +353,9 @@ public: #endif if (!bridge) return; } +#ifdef WITH_MQTT_BRIDGE + if (!enable) _bridge_resume_pending = false; // an explicit stop cancels a pending resume +#endif if (enable == bridge->isRunning()) return; if (enable) { diff --git a/examples/simple_room_server/MyMesh.cpp b/examples/simple_room_server/MyMesh.cpp index 956b59596..62fe821b2 100644 --- a/examples/simple_room_server/MyMesh.cpp +++ b/examples/simple_room_server/MyMesh.cpp @@ -1518,7 +1518,8 @@ void MyMesh::loop() { #ifdef WITH_MQTT_BRIDGE // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; // once that late ack lands, restart the bridge that was meant to be running. - if (_bridge_resume_pending && bridge && bridge->stopAcknowledgedLate()) { + if (_bridge_resume_pending && _prefs.bridge_enabled && bridge && + bridge->stopAcknowledgedLate()) { Serial.println("MQTT: stop acknowledged late - resuming bridge"); setBridgeState(true); } diff --git a/examples/simple_room_server/MyMesh.h b/examples/simple_room_server/MyMesh.h index 0139fa5a7..34cb29591 100644 --- a/examples/simple_room_server/MyMesh.h +++ b/examples/simple_room_server/MyMesh.h @@ -364,6 +364,9 @@ public: #endif if (!bridge) return; } +#ifdef WITH_MQTT_BRIDGE + if (!enable) _bridge_resume_pending = false; // an explicit stop cancels a pending resume +#endif if (enable == bridge->isRunning()) return; if (enable) { diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 1e807d414..a21a75c6c 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -272,7 +272,7 @@ void MQTTBridge::formatMqttStatusReply(char* buf, size_t bufsize, const MQTTPref const char* msgs = (obs && obs->mqtt_status_enabled) ? "on" : "off"; if (s_mqtt_bridge_instance == nullptr || !s_mqtt_bridge_instance->_initialized) { snprintf(buf, bufsize, "> msgs: %s (bridge %s)", msgs, - s_stop_unproven ? "stopped: previous stop unproven, reboot to recover" + s_stop_unproven ? "stopped: waiting for the previous stop to finish; reboot if it persists" : "not running"); return; } @@ -903,7 +903,7 @@ void MQTTBridge::begin() { // refuse. Recovery is the task finishing, or a reboot. pollLateStopAck(); if (!_lifecycle.mayRestart()) { - MQTT_DEBUG_PRINTLN("MQTT Bridge start refused: previous stop unproven (%s) - reboot to recover", + MQTT_DEBUG_PRINTLN("MQTT Bridge start refused: previous stop unproven (%s) - waiting for the task to acknowledge", MQTTLifecycle::stateName(_lifecycle.state())); return; } @@ -1230,7 +1230,7 @@ void MQTTBridge::end() { s_stop_unproven = _lifecycle.isStopUnproven(); if (_lifecycle.isStopUnproven()) { MQTT_DEBUG_PRINTLN("MQTT Bridge stop UNPROVEN after %lu ms: task did not acknowledge. " - "Nothing released, restart refused, OTA blocked - reboot to recover.", + "Nothing released, OTA blocked; restart waits for its late ack (reboot if it never comes).", (unsigned long)_lifecycle.stopTimeoutMs()); } else { MQTT_DEBUG_PRINTLN("MQTT Bridge stopped (clean)"); From 172ef36843d6395b69be0250fff2a0bd01e141ef Mon Sep 17 00:00:00 2001 From: agessaman Date: Sat, 19 Sep 2026 14:22:00 -0700 Subject: [PATCH 19/19] fix(mqtt): gate room-server OTA on an unproven stop; reap late acks - The room server checked canFlashAfterStop() only when the bridge was running at OTA time. After a timed-out restart the bridge reads as stopped while its unacknowledged task may still own TLS/client state, so an OTA could erase and write flash under it. It now refuses while the stop is unproven, after first reaping any late ack. The repeater already gated unconditionally. - MyMesh::loop() now reaps a late stop acknowledgement whenever it lands, releasing the withheld queue and buffers, and restarts only when a resume is pending and the bridge is enabled. Before, a bridge disabled during StopUnproven kept those resources until re-enabled or rebooted. pollLateStopAck() is public for this. - The wrapper's destructor no longer stops an already-stopped client: destroySlotClients() had just stopped it, so every shutdown logged five spurious "esp_mqtt_client_stop failed: ESP_FAIL" errors. Hardware (Heltec V4, 1 s test stop deadline): restart -> StopUnproven -> `set bridge.enabled off`; the late ack was reaped ("releasing withheld resources"), status read "not running", and `set bridge.enabled on` started cleanly without a second release. --- examples/simple_repeater/MyMesh.cpp | 15 ++++++----- examples/simple_room_server/MyMesh.cpp | 25 ++++++++++++------- .../src/PsychicMqttClient.cpp | 3 ++- src/helpers/bridges/MQTTBridge.h | 6 ++--- 4 files changed, 30 insertions(+), 19 deletions(-) diff --git a/examples/simple_repeater/MyMesh.cpp b/examples/simple_repeater/MyMesh.cpp index f9bdf7a18..a8a0b2018 100644 --- a/examples/simple_repeater/MyMesh.cpp +++ b/examples/simple_repeater/MyMesh.cpp @@ -1700,12 +1700,15 @@ void MyMesh::loop() { mesh::Mesh::loop(); #ifdef WITH_MQTT_BRIDGE - // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; - // once that late ack lands, restart the bridge that was meant to be running. - if (_bridge_resume_pending && _prefs.bridge_enabled && bridge && - bridge->stopAcknowledgedLate()) { - Serial.println("MQTT: stop acknowledged late - resuming bridge"); - setBridgeState(true); + // A timed-out stop keeps the bridge down until the MQTT task acknowledges it. + // Release the withheld resources whenever that late ack lands, and restart + // only a bridge that is still meant to be running. + if (bridge && bridge->stopAcknowledgedLate()) { + bridge->pollLateStopAck(); + if (_bridge_resume_pending && _prefs.bridge_enabled) { + Serial.println("MQTT: stop acknowledged late - resuming bridge"); + setBridgeState(true); + } } #endif diff --git a/examples/simple_room_server/MyMesh.cpp b/examples/simple_room_server/MyMesh.cpp index 62fe821b2..7c13018c8 100644 --- a/examples/simple_room_server/MyMesh.cpp +++ b/examples/simple_room_server/MyMesh.cpp @@ -1516,12 +1516,15 @@ void MyMesh::loop() { mesh::Mesh::loop(); #ifdef WITH_MQTT_BRIDGE - // A timed-out stop keeps the bridge down until the MQTT task acknowledges it; - // once that late ack lands, restart the bridge that was meant to be running. - if (_bridge_resume_pending && _prefs.bridge_enabled && bridge && - bridge->stopAcknowledgedLate()) { - Serial.println("MQTT: stop acknowledged late - resuming bridge"); - setBridgeState(true); + // A timed-out stop keeps the bridge down until the MQTT task acknowledges it. + // Release the withheld resources whenever that late ack lands, and restart + // only a bridge that is still meant to be running. + if (bridge && bridge->stopAcknowledgedLate()) { + bridge->pollLateStopAck(); + if (_bridge_resume_pending && _prefs.bridge_enabled) { + Serial.println("MQTT: stop acknowledged late - resuming bridge"); + setBridgeState(true); + } } #endif #ifdef WITH_MQTT_BRIDGE @@ -1619,14 +1622,18 @@ void MyMesh::loop() { drainOutbound(OTA_TX_DRAIN_TIMEOUT_MS); bool may_flash = true; + if (bridge) bridge->pollLateStopAck(); if (bridge_was_running) { setBridgeState(false); // OTA must not write after a forced/timed-out MQTT shutdown: its TLS/heap // ownership is uncertain until a subsequent clean start/stop cycle. may_flash = bridge && bridge->canFlashAfterStop(); - if (!may_flash) { - Serial.println("OTA: aborted, MQTT stop did not complete cleanly"); - } + } else if (bridge && bridge->isStopUnproven()) { + // Reads as stopped, but an unacknowledged MQTT task may still own TLS/client state. + may_flash = false; + } + if (!may_flash) { + Serial.println("OTA: aborted, MQTT stop did not complete cleanly"); } char ota_reply[160]; diff --git a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp index ccd11341d..01efb194b 100644 --- a/lib/PsychicMqttClient/src/PsychicMqttClient.cpp +++ b/lib/PsychicMqttClient/src/PsychicMqttClient.cpp @@ -20,7 +20,8 @@ PsychicMqttClient::PsychicMqttClient() : _mqtt_cfg() PsychicMqttClient::~PsychicMqttClient() { - disconnect(); + // Owners stop the client before deleting it; stopping it again only logs ESP_FAIL. + if (_started) disconnect(); if (_client != nullptr) { esp_mqtt_client_destroy(_client); diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index e733044ff..b88b35a63 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -602,9 +602,6 @@ private: void logMemoryStatus(); void refreshOriginFromPrefs(); void applyWifiPowerSave(); // one mapping, applied on every association - // Honours a stop acknowledgement that arrived after the deadline: releases the - // withheld resources and makes the bridge restartable. Loop task only. - void pollLateStopAck(); // begin()/end()-scoped PSRAM buffers. Each allocation is independent so a // transient heap shortage degrades to the existing stack fallback instead // of making the bridge unusable. @@ -746,6 +743,9 @@ public: // The unproven stop has since been acknowledged, so begin() will release the // withheld resources and start. Loop task only. bool stopAcknowledgedLate() const; + // Honours a stop acknowledgement that arrived after the deadline: releases the + // withheld resources and makes the bridge restartable. Loop task only. + void pollLateStopAck(); // Survives end() clearing the diagnostic singleton, so `get mqtt.status` can // still explain why a stopped bridge will not come back without a reboot. static bool stopUnprovenLatched();