feat(mqtt): report slot connection health so an outage is visible - #61
Merged
Merged
Conversation
A slot that cannot establish TLS reported nothing. The per-slot counters track publish successes and failures, and a slot that never connects never attempts a publish -- so its ok count freezes and its error count stays at zero for the entire outage. Observed on hardware: a slot sat dead for over five hours while `sN=` showed 0 errors and the published status payload carried no indication at all. Two surfaces gain the missing signal: - `get mqtt.stats` gains `down=<n>` (omitted when zero, like `filt=`) and marks each disconnected slot with a trailing `!`. The marker goes after the counts so existing "s(\d)=(\d+)/(\d+)" parsers keep matching. - The published status payload gains `mqtt_slots_up`, `mqtt_slots_total`, `heap_largest`, and `mqtt_outage_secs`. These ride on every healthy slot's status message, because the slot that is down cannot report itself. `mqtt_slots_up < mqtt_slots_total` is the condition to alert on. `mqtt_outage_secs` is detail: it is present only when the outage has a known start, so its absence does not imply health -- a slot that has never connected since boot has no outage start time. `heap_largest` is included because free heap alone does not predict a failed connection. A slot needs one contiguous 16,384-byte block for its TLS record buffers; measured immediately before an attempt this value predicted the outcome in every observed case, while total free heap was 85 KB throughout a multi-hour outage. A low value with every slot up is normal rather than a fault -- established sessions already hold their buffers. Publish-error semantics are unchanged: connect failures are not folded into them. Adds host coverage for the new fields, for the outage key's presence rule, and for worst-case payload size. That last one matters because serializeComplete() returns 0 and clears the buffer on overflow and the bridge publishes only a positive length, so exceeding the 768-byte status buffer would silently stop status publication -- the same blindness this change exists to remove.
The worst-case test added with the connection-health fields did not model production maxima -- it used a 28-byte model and a 24-byte firmware string, while MQTTBridge permits _origin[32], _device_id[65], _board_model[64], _firmware_version[64] and derives a 63-byte client version. isValidName() rejects [ ] / \ : , ? * but permits '"', so a 31-character node name of quotes is legal and every quote escapes to two bytes. Measured at those real maxima: without connection-health fields 762 bytes with connection-health fields 851 bytes buffer 768 bytes So the 768-byte buffer already had only six bytes of headroom before this work, and the four new fields overflow it. Overflow is silent: serializeComplete() returns 0 and clears the buffer, and the bridge publishes only a positive length, so a device would simply stop publishing status with no error anywhere -- the same blindness the connection-health fields exist to remove. Raises STATUS_JSON_BUFFER_SIZE to 1024 and corrects the test to use the actual maxima. Status serializes into the shared 2048-byte publish scratch buffer, so this costs no extra RAM; only the PSRAM-allocation-failed stack fallback grows by 256 bytes. A static_assert keeps the status ceiling within the shared buffer. Found by adversarial review of the preceding commit.
Two gaps remained after the first connection-health commit. A slot retrying into a heap that cannot satisfy its TLS allocation moved no counter at all. disconnect_count rose, but it also rises for dropped live sessions, so it could not separate "actively failing to connect" from "was connected, dropped once". Adds a per-slot connect_failures, incremented in onDisconnect when the event arrives while the client is Starting -- meaning it ended an attempt that never reached onConnect. Late events from a stopped or quarantined client, and soft-disconnects of a live session, are in other states and are not miscounted. A slot parked by the circuit breaker also looked identical to one still retrying, despite being materially worse: the breaker only probes every 30 minutes, so recovery is far slower and an operator may need to intervene. Surfaces both: - `mqttN.diag` gains `cf:<n>` beside the existing `dc:<n>`. - the status payload gains `mqtt_connect_failures` (summed across slots) and `mqtt_slots_breaker` (count of tripped slots), each emitted only when non-zero so a healthy board's payload does not grow. The counter is what distinguishes a retrying slot from a quiet one: while a slot is down its publish counters cannot move by definition, so this is the only value that shows the device is still trying. Both suggested by adversarial review.
The Starting-state gate raced the event task: client_state becomes Starting only after connect()/reconnect() returns, so a fast failure could deliver DISCONNECTED first and go uncounted, while a deliberate stop of an attempt in flight was counted as a failure. A per-slot flag is now raised before the call and cleared by onConnect, a failed start, or stopSlotClient(). Also stops zero-valued connect_failures/slots_breaker from creating an empty stats object.
connect()/reconnect() returning an error started no attempt, so no event arrived and the failure went uncounted -- the low-heap case the counter exists for. Counted now in a bridge-task-only start_failures, summed into cf: and mqtt_connect_failures. A renewal or corrected-clock bounce whose softDisconnect() times out gets its old session's DISCONNECTED after the new attempt raised the flag. That session is still marked connected until the handler runs, so the gate now also requires !connected. An ignored late CONNECTED clears the flag too. cf: no longer depends on dc being non-zero. Comments corrected for the PSRAM-fallback stack cost and heap_largest's sampling point; the worst-case test now models 6 slots.
reconnect() on a started client returns ESP_FAIL while an attempt is already in progress. On a Heltec V3, a live reconfigure hit exactly that and the attempt then connected, yet cf read 1. Count start_failures only when connect() on a stopped client fails, and restore the attempt flag to its prior value on any failed call so the in-progress attempt is still judged by its own outcome.
A slot waiting on a token/IATA/credential stays enabled but never attempts a connection, so it held mqtt_slots_up below mqtt_slots_total (and down= at 1) permanently -- a standing false alert on a node that is merely unconfigured. slots_total and down= now count only ready slots, matching the CLI's "wait". mqtt_connect_failures summed only enabled slots, so disabling a failing slot made it drop. It now sums every slot, monotonic within a boot. cf: moves after the error tail in mqttN.diag so a clamped 160-byte reply loses the count rather than the refusal/TLS detail. A failed start now clears the attempt flag instead of restoring a possibly stale one. Outage comments corrected: the clock starts at a slot's first DISCONNECTED, not first connect.
agessaman
marked this pull request as ready for review
September 26, 2026 20:55
Owner
Author
|
Post-merge status-payload capture on the Heltec V4 (`v1.17-connhealth-7d0a602b`, local mosquitto, 1-min status interval for the test):
Board restored to its original presets and 5-minute interval afterwards. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
A slot that cannot reach its broker cannot report its own outage, and the existing publish counters cannot show one either: a slot that never connects never publishes, so its
okfreezes and itserrstays 0 for the whole outage. This carries connection health on every healthy slot's status message and in the CLI.Rebased from the soak-rig branch (closed 2026-09-26) onto current
observer-firmware-dev, adapted to the lazyensureSlotClient()/ClientStaterewrite and the shared JSON scratch buffer.CLI
get mqtt.stats:down=<n>(ready slots not connected, omitted while 0; slots inwaitare excluded) and a trailing!on each disconnectedsN=ok/errentry.mqttN.diag:cf:<n>(after the error tail, beforefilter:) — connect attempts that never reached onConnect, plusconnect()/reconnect()calls that failed outright.Status payload
stats(new keys)heap_largest— largest free internal block; the leading indicator for whether the next TLS handshake (one contiguous 16 KiB block) can succeed. A trend, sampled at publish time.mqtt_slots_up,mqtt_slots_total—up < totalis the signal to alert on.totalcounts enabled slots that are ready (not waiting on a token/IATA/credential), so an unconfigured slot is not a standing alert.mqtt_outage_secs— longest current outage of known duration; only emitted while something is down.mqtt_connect_failures(summed over all slots, monotonic within a boot),mqtt_slots_breaker— only emitted when non-zero, so a healthy board's payload does not grow.Buffer:
STATUS_JSON_BUFFER_SIZE768 → 1024. At real field maxima the status doc measured 762/768 before these fields and 851 after; overflow is silent (status stops entirely). Status serializes into the shared 2048 B scratch buffer, so no extra RAM except +256 B of bridge-task stack in the PSRAM-allocation-failed fallback.Review
Reviewed by Codex and opencode (space-bunny-free) after the rebase; fixes are in the last two commits:
cfgate reworked: a per-slot_slot_attempt_pendingflag is raised beforeconnect()/reconnect()(the event task can deliver a fast failure before the call returns), cleared by onConnect, an ignored late CONNECTED, a failed start, orstopSlotClient(). A disconnect counts only if the flag is set and the slot is not connected, so a renewal/corrected-clock bounce whosesoftDisconnect()times out does not charge the old session's late DISCONNECTED to the new attempt.connect()on a stopped client that fails outright (buffer/task allocation) is counted via a bridge-task-onlystart_failures. Areconnect()rejected withESP_FAILbecause an attempt is already in progress is not counted — hardware testing caught that miscount (last commit)."stats":{}.Second opencode pass (fixes in
7d0a602b):mqtt_slots_total/down=, a permanent false alert on a node with an unfinished MeshRank slot. Now filtered withisSlotReady(). (opencode proposedisSlotEnabledAndAttempted(); that would hide a slot whose firstconnect()fails on low heap, the case this PR exists for.)mqtt_connect_failuresdropped when a failing slot was disabled; it now sums all slots.cf:moved after the error tail so a clamped 160 B diag reply loses the count, not the TLS/refusal detail.mqtt_outage_secs.Known and accepted:
get mqtt.statsis bounded at 160 bytes. With 5+ active slots and 8-digit counters during an outage, the addeddown=/!bytes can clip the lastsN=entry — the per-slot list was already what gets clamped first (same asfilt=). Complete entries still match a search-styles(\d)=(\d+)/(\d+); a fully anchored per-token parser would not.collectConnHealth()reads callback-written scalars without synchronization — same pattern as existingconnected/disconnect_count; a snapshot can be transiently inconsistent by one event.statsis now present on every bridge status publish (health keys are always supplied). Additive only.entry a1, 0x640= 1600 B on V4, 8192 B task stack).Test plan
pio test -e native— 549/549 (re-run after7d0a602b)Heltec_v3_repeater_observer_mqtt(non-PSRAM) buildsheltec_v4_repeater_observer_mqtt(PSRAM) builds (re-run after7d0a602b)down=1ands4=0/0!throughout;cftracked every refused attempt exactly (2 → 4 → 8, equal todc); breaker tripped at the 3rd failure at max backoff and the status published that second carriedmqtt_slots_breaker: 1. Captured status:mqtt_slots_up 4 / total 5,mqtt_outage_secs284 → 584 → 1484,mqtt_connect_failures5 → 8,heap_largestpresent. Healthy baseline before and after: nodown=, no!, nocf, no outage/failure/breaker keys.down=1,s2=0/0!,cf:5after 5 refused attempts (including the initial start). A capped-off slot 3 is correctly not counted as down.reconnect()calls whose in-flight attempt then connected are not counted, and the one genuine failure (WebSocket upgrade error to the broker, retried 13 s later) is.7d0a602b(both boards flashed withv1.17-connhealth-7d0a602b):5: meshrank (wait),get mqtt.statsshows nodown=(previously would have readdown=1).down=1,s5=0/0!; diagmqtt5: disc, dc:3, first_disc:101s, connect failed (0x8004), sock:104, 54s ago, cf:3—cfnow after the error tail and equal todc.wait, capped slot 3 activates and connects, nodown=.okwith nodown=/!/cf.mqtt_slots_totaluses the same readiness filter asdown=.cfmoves while a slot cannot get its TLS buffers (not reproduced; TLS buffers are allocated on the esp-mqtt task, so that failure arrives as a DISCONNECTED event, which the event path counts)