From fdb644e0b7c1d3626f62bb8bba5900397bd62248 Mon Sep 17 00:00:00 2001 From: Tom <116762865+NomDeTom@users.noreply.github.com> Date: Wed, 12 Aug 2026 23:49:17 +0200 Subject: [PATCH] Fix `millis()` rollover in deadline, interval, and timestamp handling (#11291) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * Add native test coverage for the UptimeClock monotonic seam src/UptimeClock.{h,cpp} shipped without a dedicated test suite. Port the six tests from the monotonic-time branch (test/test_time), retargeted to the renamed header. The wrap test crosses 0xFFFFFFFF via advanceTestMillis() rather than a second setTestMillis(): setTestMillis() sets clockSourceChanged, which makes getMillis64() rebase its accumulator and swallow the wrap. * NextHopRouter: fix 49.7-day millis() rollover in retransmission timing Resolves the "FIXME, handle 51 day rolloever here!!!" in NextHopRouter::doRetransmissions() by switching the retransmission-due comparison from plain unsigned <= to a signed-difference cast. The previous p.nextTxMsec <= now comparison silently breaks across the ~49.7 day millis() wraparound: pending retransmissions either stall for the remainder of the wrap window, or all fire simultaneously at the rollover boundary. Long-running router/infrastructure nodes do hit this in practice. The replacement (int32_t)(p.nextTxMsec - now) <= 0 is the standard Arduino/embedded idiom for rollover-safe deadline checks and behaves identically to the original for any non-wrap timing. * Address Copilot review: use unsigned half-range for rollover-safe retransmit check Review feedback from @Copilot on PR #10227: casting a uint32_t subtraction to int32_t is implementation-defined in C++ when the unsigned value exceeds INT32_MAX (even though it works on typical two's-complement targets). Switch to the fully well-defined unsigned half-range form: nextTxMsec is in the past-or-equal iff (now - nextTxMsec) has not wrapped past 2^31 ms. Future offsets < 2^31 ms wrap into the top half and read as 'not yet'. Same semantics as the signed-cast version on every two's-complement platform we care about, but portable to any conforming C++ impl. * Use monotonic time for airtime windows * Document monotonic airtime windows * Fix test_packet_signing sentinel that #10227's rollover fix inverts test_C3_invalid_repeated_packet_cannot_ack_or_change_retry_state parked a pending packet at nextTxMsec = UINT32_MAX to mean "never retransmit", then asserted that a rejected repeated packet leaves the retry state untouched. NextHopRouter::doRetransmissions() now tests whether a retransmit is due with an unsigned half-range compare, (uint32_t)(now - nextTxMsec) < 0x80000000u, so that retransmission timing survives the ~49.7 day millis() wrap. Under it now - 0xFFFFFFFF == now + 1, a small positive delta, so UINT32_MAX reads as ~1ms in the past: the retransmit fires and rewrites nextTxMsec, and the test failed with "Expected 4294967295 Was 6247". Use a representable future time instead. Production is unaffected either way - nextTxMsec is only ever written as millis() + d, and UINT32_MAX came from the test harness alone - so the sentinel is what needs to go, not the comparison. Special-casing UINT32_MAX in the retransmit path would keep a value that reads as "expired" under any wrap-correct compare. The value is held in a local because millis() advances across runPipelineIngress(), so recomputing it at the assertion would compare against a different number. Reported upstream on meshtastic/firmware#10227, whose branch predates this test. * Make Throttle time-injectable and add hasElapsed() Throttle backs ~94 call sites, which makes it the highest-leverage place in the tree to put the clock seam: reading Time::getMillis() instead of millis() in its three call sites turns all of them into time-injectable code at once, without touching any of them. The 32-bit millis() wrap is not otherwise reachable from a native test. The read is behaviour-preserving - Time::getMillis() returns millis() unless a test injects a clock - and the full native suite passes with it live. Also add hasElapsed(), the complement of isWithinTimespanMs(), because 51 of the 94 call sites are spelled !isWithinTimespanMs and read poorly. Its boundary is inclusive (>=) since isWithinTimespanMs uses <; both are documented. It deliberately does not treat lastExecutionMs == 0 as "never run": call sites pair that test with the interval check themselves, and absorbing a sentinel into the one helper every module depends on is exactly the value-overloading hazard being removed elsewhere. Migrating the existing !isWithinTimespanMs sites is cosmetic and deliberately left out of this commit. test/test_throttle/ covers window semantics, both boundaries, the complement identity, execute()'s first-run and throttled paths, and - the point of the exercise - a window opened before the wrap closing correctly after it, including at the 24h interval that is the longest in the tree. * Stop disarmed deadline sentinels reaching the comparison Two deadline variables encoded "inactive" as a magic value that only reads as "never" because the comparison against it is a naive millis() compare. Under any rollover-correct comparison both invert to "expired ~49 days ago", so they have to be untangled before those comparisons can be fixed. Power::reboot() set rebootAtMsec = -1 on platforms with no reboot implementation, intending "never fire". Every reader already treats 0 as the disarm value - powerCommandsCheck() tests `if (rebootAtMsec && ...)`, and AdminModule writes 0 to cancel - so -1 was both wrong and unnecessary. Use 0. Left as UINT32_MAX it would reboot-loop the moment the comparison is corrected. ExternalNotificationModule's nag window compared against nagCycleCutoff, which holds UINT32_MAX once stopped and 1 at boot. isNagging is the real armed flag, so test it first and short-circuit: a disarmed cutoff can no longer reach the arithmetic, while an idle module still takes the same sleep path that the boot-time value of 1 was relying on. Note this fixes the sentinel only. The comparison itself is still a naive `nagCycleCutoff < millis()` and remains on the list to convert. * Fix millis() rollover in every deadline and interval comparison Roughly 20 sites compared against millis() directly - `millis() > deadline`, `deadline < millis()`, `last + interval < millis()`. All of them break for about 24 days after the 32-bit millis() wrap: depending on which side of the wrap each value sits, the action either stalls for weeks or fires immediately and repeatedly. The longest affected interval is the 12 hour NTP renewal, a ~50x margin against the wrap, so none of these needed the range - only the correct comparison. Add Throttle::deadlinePassed(deadlineMs) for sites that store an absolute deadline they cannot re-express as "interval since an event". It uses the same unsigned half-range test as NextHopRouter::doRetransmissions() rather than introducing a competing signed-cast idiom, and unlike the signed cast it is defined for every input. Sites that do store an event use the existing isWithinTimespanMs / hasElapsed. Nothing gained new state. Because both helpers read Time::getMillis(), every converted site is now reachable from a native test that drives the clock across the wrap; the comparison itself is covered directly in test/test_throttle/. Sentinel handling is the reason this could not be a mechanical rewrite. The disarm convention is not uniform: 0 means "inactive" for rebootAtMsec, shutdownAtMsec, alertBannerUntil, fixHoldEnds, suppressUntilMs and touchResumeBlockUntilMs; 0 means "due now" for ntp_renew, which is forced to 0 at link-up; UINT32_MAX means "inactive" for nagCycleCutoff; and alertBannerUntil == 0 in isOverlayBannerShowing() means "show indefinitely". Every inactive marker is arithmetically far in the past, so a correct comparison fires on it - each site tests its sentinel before the arithmetic, and keeps the meaning it had. Two sites carried a second bug found on the way: BME680Sensor tested (stateUpdateCounter * STATE_SAVE_PERIOD) < millis(). With a 6 hour period and a uint16_t counter that product overflows uint32_t after about 198 saves, independently of the millis() wrap. It now measures the interval since the last save. EInkDynamicDisplay had `if (previousRunMs > millis()) return;` as a millis() overflow guard, which skipped rate limiting entirely for the whole post-wrap period - the bug it meant to prevent. Every check below it already goes through Throttle, so the guard is removed rather than fixed. MotionSensor's calibration countdown is converted to a signed delta rather than deadlinePassed, because it needs the remaining magnitude and not a boolean; that matches the already-correct check in the same file. * Remove getMillis64() and use Throttle for the NodeInfo reply window getMillis64() had exactly one caller and no callers in tests. It also carried obligations that made it the wrong shape for this firmware: a wrap accumulator in mutable statics, which is not ISR-safe, and which must be polled at least once every ~49.7 days or it silently misses a wrap and returns a time ~49 days short. Its one caller only wanted to know whether a 12 hour suppression window had elapsed - which Throttle answers correctly across the wrap without any accumulator. NodeInfoModule now stores Time::getMillis() in lastNodeInfoSeen and tests the window with Throttle::isWithinTimespanMs, so the map holds milliseconds rather than seconds derived from a 64-bit read. USERPREFS_NODEINFO_REPLY_SUPPRESS_SECS is user-overridable and now feeds a multiply by 1000, so a static_assert rejects any value too large to express in milliseconds instead of letting it wrap. clockSourceChanged goes too. It existed solely to rebase getMillis64()'s accumulator when a test swapped clock sources, and it made the wrap untestable through the injection API: setTestMillis() set the flag, so a wrap crossed by two setTestMillis() calls was swallowed. With the accumulator gone the flag has nothing to rebase, and the injection API is a plain settable clock. The three getMillis64 tests are dropped as they no longer describe anything. One test replaces them, pinning that advanceTestMillis() wraps past 0xFFFFFFFF rather than saturating, since the Throttle wrap tests rely on it. Also fix eviction in pruneLastNodeInfoCache(): it picked the entry with the smallest stored stamp, which is the wrong victim once some stamps sit on the far side of the wrap. It now evicts the largest elapsed time. * Add CI guard and docs rule against naive millis() comparisons Fixing the existing sites does not stop the next one being added. The millis-deadline-check job rejects millis() placed directly next to a comparison operator, in either order, anywhere in src/. It lives in test_native.yml alongside suite-count-check, which sets the precedent for a repo-hygiene guard that CI enforces and bin/run-tests.sh does not. The correct idioms all subtract before comparing, so none of them match the pattern. Line comments are stripped first, so documentation is free to name the broken form - as the guard's own comment and the coding conventions both do. Writing the check before finishing the sweep turned out to be worth it: it found roughly 14 sites that a by-hand audit of deadline variables had missed, including two extra nagCycleCutoff compares, both boot-screen timeouts, and a 6 hour sensor save interval that was also overflowing a uint32_t multiply. .github/millis-deadline-allowlist.txt covers the cases that are genuinely not deadline tests. Both current entries are uptime thresholds - "has the device been up N ms" - with no stored deadline and no event to measure from: a 30s button holdoff against phantom shutdown from floating pins, and a 10s window for the OEM boot logo. Each re-crosses its threshold once per wrap, which is harmless for boot-holdoff logic and not worth new state to avoid. Entries are keyed on file plus exact source text, without line numbers, so an edit above an entry does not silently invalidate it. Locally the guard reports 19 matches before the sweep and 2 after, both allowlisted. The Throttle bullet in the coding conventions is rewritten from "prefer Throttle for rate limiting" to "never compare against millis() directly", lists all four helpers with when to use which, names the CI guard, and documents the sentinel hazard with the rebootAtMsec = -1 case that would have become a reboot loop. Mirrored into AGENTS.md; CLAUDE.md gets a pointer row. * Trim rollover comments to what the code needs The comments added with the millis() rollover fixes carried too much of the investigation that produced them: how many sites were found, which document recorded them, what the old code used to do. That belongs in the commit history, not in the source, and some of it was already stale - Power::reboot() still described the check it disarms as "a naive millis() > deadline" when that comparison had been fixed in the same series. What stays is the non-obvious part at each site: which sentinel value the variable overloads and what it means there, since that differs between call sites and is what a correct comparison gets wrong. 0 means "not scheduled" for rebootAtMsec, "renew now" for ntp_renew, and "show indefinitely" in isOverlayBannerShowing(). Exposition is kept where it earns its place: the Throttle helpers, the uptime clock's note on why there is no 64-bit variant, and the tests. The Throttle docs lose only the site count and the "longest interval in the firmware" statistic, both of which would age badly; the range trade-off between the two forms is what a caller actually needs. Comments only - no code changed, verified by diff. * possible fixes * Address review feedback on the rollover fixes - BME680Sensor: checkpoint lastStateSaveMs after a successful write instead of at the interval test. The first save (IAQ accuracy >= 2) left it at 0, timing the next save from boot, and stamping before the write deferred the retry a full period when the write failed. Reads Time::getMillis(), the same clock Throttle compares against. - Throttle: add deadlinePassedAt(now, deadline) for loops that snapshot the clock once and test many deadlines; deadlinePassed() now delegates to it. NextHopRouter::doRetransmissions() uses it, replacing the inline half-range compare adopted from #10227 (nightjoker7) - same arithmetic, credited at the call site - and takes its snapshot from Time::getMillis() so setNextTx() deadlines and the due test cannot diverge under an injected test clock. - test_native.yml: set -euo pipefail in the millis-deadline guard, matching the sibling suite-count job. Without -e a partially failed scan could report "no violations" from truncated output. - test_packet_signing: build the not-due deadline from Time::getMillis() rather than millis(), so the test and the router read one clock. - test_throttle: cover deadlinePassedAt(), and correct a wrapped-value comment (0xFFFFFF00 + 400 is 0x00000090, not 0x00000094). Two review comments were declined: the AirTime mutex (every airTime-> caller runs in the single cooperative loop, WebServerThread included) and the MotionSensor 0-sentinel countdown (the calibration frame is only installed while a window is open). clod helped out here * Correct the described failure window of a naive millis() compare The comments and agent docs said a bare `millis() > deadline` "breaks for ~24 days after the wrap". That figure belongs to the fix, not the bug: it is the half-range limit of deadlinePassed(), which reads deadlines more than 2^31 ms ahead as already passed, and the range over which a UINT32_MAX sentinel reads as passed. The naive compare's actual failure is an inversion lasting only while the deadline sits on the far side of the wrap, so it is bounded by the interval: the action fires immediately and loses its wait, or blocks for about the wait it should have performed - days for the nRF52 flash-corruption backoff, one skipped cycle for a seconds-long retransmit timer. Comments and docs only; the ~24.8 day statements that correctly describe deadlinePassed()'s own range are left as they were. clod helped out here * Restore a monotonic uptime clock and consolidate the wrap counters Time::getMillisMonotonic() is the getMillis64() shape - a 32-bit wrap counter carried across reads - promoted to the shared timebase, with Time::getUptimeSecs() as the derived whole-seconds view. This deliberately reverses the earlier removal of getMillis64(), and the distinction matters: removal was right for a lazily-read accumulator with one rare caller, where a 49.7-day gap between reads silently swallowed a wrap. Here every read is the poll and AirTime::runOnce() guarantees one per second; the missed-wrap contract is pinned by a test rather than left as a footnote. Three private wrap counters collapse into it: - AirTime::syncNow() takes its seconds from Time::getUptimeSecs() and drops its lastSyncMsec checkpoint; window rotation is unchanged. - DeviceTelemetryModule loses refreshUptime()/uptimeWrapCount/uptimeLastMs; uptime_seconds comes from Time::getUptimeSecs(), which also removes the 0.296s-per-wrap truncation of (0xFFFFFFFF / 1000) * wraps. Its two interval checks move to Throttle::hasElapsed(). - HostMetricsModule's copies of those members were never read (its uptime comes from /proc/uptime) - deleted. Not ISR-safe (unguarded mutable carry): ISRs keep using getMillis(), which stays a pure read. Audited: no interrupt-context file reads getTime(), getValidTime(), or the new accessors. test/native-suite-count 44 -> 45: the bump for test_uptime_clock was lost in a branch history rewrite, leaving every later value off by one - run-tests.sh reports AMBER and CI's suite-count-check fails on the current push until this correction. * Anchor the wall clock in monotonic milliseconds getTime() computed elapsed-since-time-set as a 32-bit millis() delta, so a node that took time once and stayed up past 49.7 days reported a wall clock one full cycle in the past - and last_heard, rx_time, message and position stamps all inherited it. The anchor is now the 64-bit monotonic count (timeStartMsec -> timeStartMs64) and the elapsed term is computed in 64-bit, so the wall clock is exact at any uptime. All six anchor writers follow: the five hardware-RTC read branches and perhapsSetRTC(), which keeps a truncated 32-bit copy of the same instant for its Throttle-checked rate-limit stamps. The test seams anchor the same way. Two native regression tests drive getTime() across the wrap through the Time seam - one anchored before the wrap and read after it, one anchored after a counted wrap - with the test epoch derived from BUILD_EPOCH so the plausibility window cannot rot as the build date advances. * Stamp the rx_time placeholder in monotonic uptime seconds computeRxTimeStamp() stamped Time::getMillis() when the clock was untrusted, and reconcilePendingRxTimes() back-calculated with a 32-bit millis() delta - correct within one wrap, but a placeholder older than 49.7 days aliased to a small elapsed value and reconciled to a plausible-but-wrong recent epoch: the exact failure has_rx_time exists to prevent, reachable by an ordinary unattended router whose phone connects two months in. The placeholder is now Time::getUptimeSecs(). Both stamps come off the monotonic counter, so the elapsed term is exact at any age and the aliasing window is gone outright rather than widened. If elapsed somehow exceeds the epoch itself, the packet stays un-dated (absent, never wrong) instead of clamping to a pre-1970 value. Defence in depth: a placeholder that leaks needs ~50 years of uptime to cross MIN_PLAUSIBLE_EPOCH, where milliseconds took 18.3 days. The stream-API reconciliation tests keep their scenarios with the placeholder unit switched, and ScopedTimeFixture resets the monotonic carry so uptime seconds are deterministic per case. * Date nodes heard before the clock arrives, without polluting last_heard A node first heard while the wall clock was untrusted got no last_heard at all, and nothing backfilled it once time arrived - the phone showed "Last heard: unknown" for a node it had just announced. The arrival instant now waits in a RAM-only sidecar (NodeNum -> uptime seconds, 32 slots, reuse-oldest - the RouteHealth shape) and is converted to a real epoch on the clock-becoming-trusted transition, beside the existing rx_time reconciliation. last_heard itself never holds anything but a real epoch or 0: it persists to flash and the warm tier, where an uptime-relative value would be meaningless after reboot. The sidecar's write sites are updateFrom()'s no-trusted-clock path (the rx_time placeholder already carries the arrival instant, so this is a store, not a second clock read) and addFromContact's anti-eviction stamps, which previously wrote a bare getTime() - boot-relative seconds on a clockless node, the exact value lastHeardIsWallClock() exists to catch. Eviction ranking honours the stamps: heard-this-boot outranks every stored epoch, ordered among themselves, so a stamped contact is not the first victim. PhoneAPI re-reads last_heard at nodeinfo send time: a record prefetched before the clock became trusted can carry 0 while the store has since been backfilled, and re-reading at the pop makes handshake ordering (time-set vs node-list download) irrelevant. Backfill never moves last_heard backwards and skips the pathological elapsed-exceeds-epoch case. A node evicted to the warm tier before time arrives is still absorbed with last_heard 0 - same as before, bounded to the untrusted window. * Update the agent docs for the monotonic timebase The conventions bullet asserted there is deliberately no 64-bit millis; the monotonic uptime clock restored for timestamps changes that contract. State the split explicitly: Throttle for deadlines and intervals (no carry state), Time::getMillisMonotonic()/getUptimeSecs() for timestamps, polled by construction and not ISR-safe. * Publish the monotonic wrap carry from a single writer getMillisMonotonic() was a read-modify-write on two unguarded statics, and it is reached off the main loop: the nRF52 Bluefruit task via onFromRadioAuthorize() -> PhoneAPI::getFromRadio -> getValidTime(), and the portduino civetweb workers via the same path. Two readers interleaving inside the wrap window could each increment the carry, putting every uptime and wall-clock reading 2^32 ms ahead for the rest of the boot - a permanent ~49.7 day jump in rx_time, last_heard and ClientNotification.time. Readers no longer write. serviceMonotonic() publishes a snapshot behind a seqlock and is the only writer; a reader adds its own unsigned elapsed time to that snapshot, which is exact across the wrap, so it never inspects the boundary and cannot miscount it. The main loop publishes every iteration, so the once-per-49.7-days obligation now has the whole window of margin instead of resting on an instruction-wide race. AirTime was the guaranteed poller and is now a pure reader, so the two airtime wrap tests step the clock the way loop() does. The test clock itself is atomic so a suite can drive it from one thread while others read. * Re-arm the GPS ephemeris hold when none is in force The rollover sweep guarded the hold re-arm with `fixHoldEnds != 0 &&`, which reads like the sentinel rule but inverts this site. The comparison it replaced, `(fixHoldEnds + GPS_THREAD_INTERVAL) < millis()`, was always true when nothing was armed - that was the point, since 0 means "not holding" and so is a reason to arm. With the guard, a publish that cleared the hold without sleeping (the `shouldPublish && !tooLong && !holdExpired` path, which does not call down()) left hasValidLocation set and prev_fixQual non-zero, so no disjunct held: nothing re-armed, nothing published, and the receiver stayed powered at the 200ms poll until searchedTooLong() fired. State the question positively instead. fixHoldInForce() is the only place the sentinel is interpreted, and both of runOnce()'s decisions derive from it - the asymmetry is now visible rather than implied, since arming does not require a prior hold but expiring does. Its `!= 0` test is not redundant with the arithmetic: deadlinePassed() is an unsigned half-range test, so past 2^31 ms of uptime the sentinel reads as a deadline ~24.9 days in the future. Kept beside its caller rather than in a header; the native test build compiles GPS.cpp, so the suite declares the prototypes. Also converts the getACK() wait to isWithinTimespanMs(start, interval): it has both the start instant and the interval in hand, which gives the full 49.7-day range instead of 24.8 days ahead, and takes its anchor from Time::getMillis() so the wait is injectable. * Date the NodeInfo reply window in uptime seconds The 12h reply-suppression stamp regressed from wrap-immune 64-bit seconds to raw 32-bit milliseconds, and pruneLastNodeInfoCache() evicts only by node count and DB membership - never by age. A stable mesh under the node cap therefore keeps every stamp indefinitely, and once uptime passes 49.7 days an old one aliases back into the window: `now - stamp` computes as ~0 and a legitimate NodeInfo request goes unanswered for up to 12h. It self-heals and repeats once per wrap cycle. Store Time::getUptimeSecs() instead, which does not wrap for 136 years, and drop the millisecond conversion the previous shape needed. Entries past the window are now evicted too: they can only ever decide "don't suppress". N8-N11 cover the window from both sides, and N10 pins the regression - it needs a full 2^32 ms of uptime to elapse, not merely a crossing of the boundary, because that is when a millisecond stamp reads as "answered this instant". tearDown() now restores the injected clock and C14's region and TX bucket. A failing assertion aborts the test body, so restoring at the end of it leaked that state into every later case. * Update the agent docs for the single-writer clock and sentinel direction Two rules the preceding three commits changed. The monotonic clock is no longer maintained by whoever happens to read it: serviceMonotonic() is the only writer, readers are pure, and calling it from anywhere but the main loop reintroduces the double-count. The sentinel guidance gained the half it was missing. It named UINT32_MAX as a sentinel while prescribing an idiom that only covers 0, and it assumed the sentinel always means "suppress" - at the GPS fix-hold site it meant "fire", which is how that regression passed review looking like the rule. * Name the fix-hold expiry predicate and arm it from the injected clock holdJustExpired() gives the second reading of the fixHoldEnds sentinel a name beside the first, so both are pinned by test/test_gps_fix_hold/ and neither can be respelled at the call site. The old inline form could not be tested: written as a literal, its guard folds at compile time and the assertion asserts nothing. The arm site used bare millis() while the evaluation reads the Throttle clock; same value in production, but it kept that write out of reach of Time::setTestMillis(). Remap a deadline that lands on 0, which would otherwise read as no hold at all. * Share the extend formula between the clock's reader and writer getMillisMonotonic() and serviceMonotonic() carried byte-identical wrap arithmetic. A one-sided edit to either would drift the published carry from what readers report, so keep one copy. * Trim the NodeInfo dedup comment to the house limit * todo note for potential future imrpovments * fix some simple deadlines * Trim the hold-expiry test comment to the house limit * Fix non-blocking uptime publication and pre-clock recency edges (#29) * fix(time): avoid blocking monotonic readers * test(time): make paused-publisher check deterministic * fix(time): address review portability gaps * Init the eviction sentinel to the newest possible recency EvictionRecency{} is {0, false}, which evictionRecencyOlder() ranks as older than every candidate: without the oldestIndex/oldestBoringIndex guards nothing would ever be selected and a full node DB would stop evicting entirely. Init to the genuine maximum instead, so the sentinel is correct on its own. The index guards stay: two independent reasons the scan is right beats one. * Keep the deadline-guard check name branch protection matches The guard was widened to cover Time::getMillis() and unqualified getMillis(), and renamed to suit. Upstream branch protection matches required checks by name, so a rename means the old name never reports and merges block on a check that will never arrive. Widen the guard, keep the name; the descriptive text carries the broader scope. * Correct native-suite-count to 47 after the develop merge Upstream #11293 added test_nmea_wpl and took develop's count to 43; this branch had independently reached 46. Merging develop resolved the counter textually, keeping 46, while the directory set became the union of both sides at 47. The suite-count CI gate fails on the mismatch, and it gates the native test jobs, so the tests themselves were being skipped. * test(uptime): make the wrap fall where the comment says it does The concurrent-reader case started at 0xFFFFF000, leaving 0x1000 to the wrap, so the 0x800 advance annotated "cross the wrap" fell short and the wrap actually happened during the following 60s advance. Start at 0xFFFFF800 instead, so the first advance lands exactly on the wrap while the readers are running and the second is the ordinary time after it - the shape both comments already described. Total elapsed is unchanged, so the closing assertion still holds. * Respond to human comments * Did I ever tell you about the time I went to Shelbyville? I wore an onion on my belt, which was the style at the time. * Convert the I2S nag deadline develop dragged in The HAS_I2S_SPEAKER_NRF52 RTTTL block arrived from develop with a raw nagCycleCutoff >= millis(), which the deadline guard rejects. Use the same Throttle::deadlinePassed() form as the two sibling paths in this function. * Arm the LittleFS format guard with a flag, not a zero timestamp preFSBegin() runs in the first millisecond of boot, so millis() can legitimately return 0 there. Both readers of last_format_ms treated 0 as "nothing formatted this boot", which would skip the repeat-corruption escalation and let a dead flash reformat-loop instead of reporting FLASH_CORRUPTION_UNRECOVERABLE. * Note the single-thread contract on AirTime * Note the AirTime locking TODO, and tighten the thread note The two constant getters are not constrained, and getSilentMinutes() reads the buckets without rotating them, so "the accessors mutate" was not accurate. * trunk: ignore trufflehog false positives on millis-wrap test constants test_throttle and test_uptime_clock pin dense clusters of hex boundary constants (0xFFFFFF00u and neighbors) to exercise 32-bit millis() rollover. trufflehog's Lob detector stitches nearby hex literals into one candidate string, and the result happens to match a Lob API key shape - not a secret, just test fixtures. Same pattern already used for the gitleaks/nodedb-fixture false positive in this file. --------- Co-authored-by: nightjoker7 Co-authored-by: Clive Blackledge Co-authored-by: Benjamin Faershtein <119711889+RCGV1@users.noreply.github.com> Co-authored-by: Thomas Göttgens Co-authored-by: Ben Meadors --- .github/copilot-instructions.md | 13 +- .github/millis-deadline-allowlist.txt | 22 ++ .github/workflows/test_native.yml | 66 ++++ .trunk/trunk.yaml | 9 + AGENTS.md | 13 +- CLAUDE.md | 13 +- src/Power.cpp | 12 +- src/PowerFSMThread.h | 7 +- src/UptimeClock.cpp | 99 ++++- src/UptimeClock.h | 63 +++- src/airtime.cpp | 164 ++++---- src/airtime.h | 10 + src/gps/GPS.cpp | 40 +- src/gps/RTC.cpp | 49 ++- src/graphics/EInkDynamicDisplay.cpp | 4 +- src/graphics/Screen.cpp | 6 +- src/graphics/draw/NotificationRenderer.cpp | 9 +- src/input/RotaryEncoderImpl.cpp | 3 +- src/main.cpp | 4 + src/mesh/MeshService.cpp | 18 +- src/mesh/MeshService.h | 4 +- src/mesh/NextHopRouter.cpp | 13 +- src/mesh/NodeDB.cpp | 116 +++++- src/mesh/NodeDB.h | 37 ++ src/mesh/PhoneAPI.cpp | 8 + src/mesh/Router.cpp | 2 +- src/mesh/Router.h | 3 +- src/mesh/Throttle.cpp | 15 +- src/mesh/Throttle.h | 44 +++ src/mesh/eth/ethClient.cpp | 5 +- src/modules/DropzoneModule.cpp | 3 +- src/modules/ExternalNotificationModule.cpp | 19 +- src/modules/NodeInfoModule.cpp | 30 +- src/modules/NodeInfoModule.h | 2 + src/modules/StatusLEDModule.cpp | 9 +- src/modules/Telemetry/DeviceTelemetry.cpp | 19 +- src/modules/Telemetry/DeviceTelemetry.h | 21 -- src/modules/Telemetry/HostMetrics.h | 4 - src/modules/Telemetry/Sensor/BME680Sensor.cpp | 7 +- src/modules/Telemetry/Sensor/BME680Sensor.h | 1 + src/motion/MotionSensor.cpp | 7 +- .../extra_variants/t5s3_epaper/variant.cpp | 28 +- src/platform/nrf52/NRF52Bluetooth.cpp | 2 +- src/platform/nrf52/main-nrf52.cpp | 19 +- test/test_airtime/test_main.cpp | 196 ++++++++++ test/test_gps_fix_hold/test_main.cpp | 218 +++++++++++ .../ports/test_timestamp.cpp | 2 +- .../test_meshpacket_serializer/test_helpers.h | 2 +- test/test_nodedb_blocked/test_main.cpp | 23 ++ test/test_packet_signing/test_main.cpp | 131 ++++++- test/test_stream_api/test_main.cpp | 73 +++- test/test_throttle/test_main.cpp | 237 ++++++++++++ test/test_uptime_clock/test_main.cpp | 356 ++++++++++++++++++ 53 files changed, 2006 insertions(+), 274 deletions(-) create mode 100644 .github/millis-deadline-allowlist.txt create mode 100644 test/test_airtime/test_main.cpp create mode 100644 test/test_gps_fix_hold/test_main.cpp create mode 100644 test/test_throttle/test_main.cpp create mode 100644 test/test_uptime_clock/test_main.cpp diff --git a/.github/copilot-instructions.md b/.github/copilot-instructions.md index 114afd1a2..d8c5fed32 100644 --- a/.github/copilot-instructions.md +++ b/.github/copilot-instructions.md @@ -338,7 +338,18 @@ firmware/ - Use `assert()` for invariants that should never fail - C++17 features are available (`std::optional`, structured bindings, `if constexpr`, etc.) - **Keep code comments minimal - one or two lines, max.** Comment only when the _why_ isn't obvious from the code; never restate what the next line does. No multi-paragraph block comments explaining straightforward changes. The diff and commit message carry the rationale; the code carries the behavior. -- **Use `Throttle` for time-based rate limiting, not raw `millis()` math.** `src/mesh/Throttle.h` provides `Throttle::isWithinTimespanMs(lastMs, intervalMs)` (returns true while inside the cooldown) and `Throttle::execute(&lastMs, intervalMs, func)` (function-pointer form that updates the timestamp on fire). Use these for any "did N ms pass since X" check - raw `millis() > lastMs + N` is rollover-unsafe (breaks after ~49.7 days) and inconsistent with the rest of the codebase. The helpers compute `now - lastMs` with unsigned subtraction, which wraps correctly. +- **Never compare against `millis()` directly. Use `Throttle`.** `src/mesh/Throttle.h` is the sanctioned way to ask about time, and CI enforces this (`millis-deadline-check` in `.github/workflows/test_native.yml` fails the PR on a new `millis() >` / `< millis()` comparison). + - `Throttle::isWithinTimespanMs(lastMs, intervalMs)` - true while still inside the cooldown. + - `Throttle::hasElapsed(lastMs, intervalMs)` - its complement, true once the interval has passed (inclusive `>=`). Prefer this to spelling `!isWithinTimespanMs(...)`. + - `Throttle::execute(&lastMs, intervalMs, func)` - function-pointer form that updates the timestamp on fire. + - `Throttle::deadlinePassed(deadlineMs)` - for a stored absolute deadline that cannot be re-expressed as "interval since an event". Uses an unsigned half-range compare; reads deadlines more than ~24.8 days out as already passed, which no interval in this firmware approaches (the longest is 24 h). + - `Throttle::deadlinePassedAt(nowMs, deadlineMs)` - the same test against a caller-supplied `now`, for a loop that snapshots the clock once and then tests many deadlines (`NextHopRouter::doRetransmissions()`). Take the snapshot from `Time::getMillis()`, not `millis()`. + + Raw `millis() > deadline` or `deadline < millis()` is rollover-unsafe: the comparison inverts while the deadline sits on the far side of the 32-bit wrap, so the action fires immediately (losing its whole wait) or blocks for roughly the interval it should have waited - days, for the nRF52 flash-corruption backoff. All five helpers subtract first, so unsigned wraparound cancels out. `Throttle` reads the clock through `Time::getMillis()` (`src/UptimeClock.h`), which means every one of its ~94 call sites is time-injectable - a native test can drive `Time::setTestMillis(0xFFFFFF00)` across the wrap. For _timestamps_ (not deadlines) there is `Time::getMillisMonotonic()` / `Time::getUptimeSecs()` - a 64-bit monotonic uptime read. Readers are pure: they add their own wrap-immune elapsed time to a snapshot published by `Time::serviceMonotonic()`, which the main loop calls every iteration and which is **the only writer**. Never call `serviceMonotonic()` from anywhere else - two writers can count one wrap twice, putting every uptime and wall-clock reading ~49.7 days into the future for the rest of the boot. Not ISR-safe (the snapshot is read under a seqlock); see the contract in `UptimeClock.h`. Deadline and interval checks should still use `Throttle`, which needs no carry state at all. + + **Sentinel hazard.** If a deadline variable also encodes "inactive" - `0` for `rebootAtMsec`, `shutdownAtMsec`, `alertBannerUntil`, `fixHoldEnds`; `UINT32_MAX` for `nagCycleCutoff` - test that sentinel _before_ the elapsed comparison, and match the test to the sentinel actually in use. `if (deadline && Throttle::deadlinePassed(deadline))` covers the `0` family only; `nagCycleCutoff` needs `deadline != UINT32_MAX`, or a separate armed flag as `ExternalNotificationModule` does with `isNagging`. Every sentinel value is arithmetically far in the past, so a correct comparison reads it as "expired" and fires immediately: `rebootAtMsec = -1` meaning "never" is what would have become a reboot loop. Never fold the sentinel into the helper. + + **And decide which way the sentinel should fall.** "Inactive" does not always mean "suppress". At the GPS fix-hold site `fixHoldEnds == 0` means _no hold is in force_, which is exactly when a new hold must be armed - the naive comparison it replaced was `(fixHoldEnds + GPS_THREAD_INTERVAL) < millis()`, always true when nothing was armed. Guarding it with `fixHoldEnds != 0 &&` looks like this rule and inverts the site: nothing re-arms, nothing publishes, and the receiver stays powered until the search timeout. Read the surrounding logic before adding the guard. `fixHoldInForce()` in `src/gps/GPS.cpp` is the worked example - state the predicate positively, so the sentinel has an honest answer, and derive both decisions from it - with `test/test_gps_fix_hold/` pinning both directions. ### Naming Conventions diff --git a/.github/millis-deadline-allowlist.txt b/.github/millis-deadline-allowlist.txt new file mode 100644 index 000000000..1363acec0 --- /dev/null +++ b/.github/millis-deadline-allowlist.txt @@ -0,0 +1,22 @@ +# Allowlist for the millis-deadline-check guard in .github/workflows/test_native.yml. +# +# That guard rejects comparisons made directly against millis(), because they invert while the +# deadline sits on the far side of the 32-bit wrap. Use Throttle::deadlinePassed(deadline) or +# Throttle::hasElapsed(lastEvent, intervalMs) instead - see .github/copilot-instructions.md. +# +# Only add a line here when the comparison genuinely is not a deadline test. The usual valid case is +# an *uptime threshold*: "has the device been up for at least N ms", where there is no stored +# deadline and no event to measure from. Those still misbehave briefly after a wrap - the threshold +# is simply re-crossed - which is harmless for boot-holdoff logic and not worth new state. +# +# Format: +# Line numbers are deliberately absent so edits above an entry do not invalidate it. A `#` comment +# on the code line is stripped before matching, so do not include one here. + +# Boot holdoff, not a deadline: suppresses a phantom shutdown from floating pins during the first +# 30s of uptime. Pairs with the buttonPressStartTime > 30000 test on the same line. +src/input/ButtonThread.cpp if (millis() > 30000 && buttonPressStartTime > 30000 && _longLongPress != INPUT_BROKER_NONE && + +# Boot-window check, not a deadline: draws the custom OEM logo only during the first 10s of uptime, +# so the ordinary Meshtastic logo is used at shutdown. +src/graphics/niche/InkHUD/Applets/System/Logo/LogoApplet.cpp if (millis() < 10 * 1000UL) { diff --git a/.github/workflows/test_native.yml b/.github/workflows/test_native.yml index 2e171e46a..04e6b3a23 100644 --- a/.github/workflows/test_native.yml +++ b/.github/workflows/test_native.yml @@ -79,6 +79,72 @@ jobs: done <<<"$removed" exit $fail + # Reject naive deadline comparisons against the 32-bit uptime clocks. `millis() > deadline` and + # `deadline < millis()` invert while the deadline sits on the far side of the 32-bit wrap: the + # action fires immediately, or blocks for about the interval it should have waited. The correct + # forms are + # Throttle::isWithinTimespanMs / hasElapsed (elapsed since a stored event) and + # Throttle::deadlinePassed (an absolute deadline). See .github/copilot-instructions.md. + millis-deadline-check: + # Name is load-bearing: upstream branch protection matches the check by name. Widen the guard, + # not this string. + name: Naive millis() Deadline Compare + runs-on: ubuntu-latest + permissions: + contents: read + steps: + - uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7 + with: + persist-credentials: false + + - name: Reject 32-bit uptime clocks used directly in a deadline comparison + shell: bash + run: | + set -euo pipefail + allowlist=".github/millis-deadline-allowlist.txt" + + # Flag millis() or its Time::getMillis() wrapper directly adjacent to a comparison + # operator, in either order. The correct idioms subtract first, so they are not matched. + # + # Line comments are stripped before matching, so prose may name the broken idiom (this + # guard's own documentation does). Block comments are not stripped; keep `millis() >` out + # of /* */ blocks. mawk-compatible - ubuntu-latest has no gawk. + find src -type f \( -name '*.cpp' -o -name '*.h' -o -name '*.hpp' -o -name '*.ino' \) \ + ! -path 'src/mesh/generated/*' -print0 | + xargs -0 awk ' + { + line = $0 + sub(/\/\/.*/, "", line) + if (line ~ /((millis|getMillis)\(\)[ \t]*[<>]=?)|([<>]=?[ \t]*(millis|getMillis)\(\))/) { + code = line + sub(/^[ \t]+/, "", code); sub(/[ \t]+$/, "", code) + printf "%s\t%s\t%s\n", FILENAME, FNR, code + } + }' > /tmp/millis-hits.tsv + + # Allowlisted entries are keyed on file + exact source text, deliberately without a line + # number, so unrelated edits above them do not invalidate the entry. + : > /tmp/millis-allowed.tsv + if [[ -f $allowlist ]]; then + grep -vE '^[[:space:]]*(#|$)' "$allowlist" > /tmp/millis-allowed.tsv || true + fi + + violations=0 + while IFS=$'\t' read -r file line code; do + [[ -n ${file:-} ]] || continue + if grep -qxF "$(printf '%s\t%s' "$file" "$code")" /tmp/millis-allowed.tsv; then + continue + fi + echo "$file:$line: $code" + violations=$((violations + 1)) + done < /tmp/millis-hits.tsv + + if [[ $violations -gt 0 ]]; then + echo "::error title=Naive uptime deadline compare::$violations line(s) compare a 32-bit uptime clock directly, which inverts while the deadline is on the far side of the 32-bit wrap - the action fires immediately, or blocks for about the interval it should have waited. Use Throttle::deadlinePassed(deadline) for a stored absolute deadline, or Throttle::hasElapsed(lastEvent, intervalMs) for an interval. If a match genuinely is not a deadline test (an uptime threshold, say), add it to $allowlist with a reason." + exit 1 + fi + echo "No naive 32-bit uptime deadline comparisons in src/ (allowlist: $(wc -l < /tmp/millis-allowed.tsv) entr(y/ies))." + simulator-tests: name: Native Simulator Tests runs-on: ubuntu-24.04-arm diff --git a/.trunk/trunk.yaml b/.trunk/trunk.yaml index 7b45c5f83..099a6a491 100644 --- a/.trunk/trunk.yaml +++ b/.trunk/trunk.yaml @@ -151,6 +151,15 @@ lint: - linters: [ascii-dash] paths: - src/graphics/fonts/** + # millis()-wraparound tests pin dense clusters of hex boundary constants + # (0xFFFFFF00u and neighbors). trufflehog's Lob detector stitches nearby + # hex literals into one candidate string and the result happens to match + # a Lob API key shape. Not secrets - deterministic test fixtures for the + # 32-bit rollover. + - linters: [trufflehog] + paths: + - test/test_throttle/test_main.cpp + - test/test_uptime_clock/test_main.cpp runtimes: enabled: - python@3.14.4 diff --git a/AGENTS.md b/AGENTS.md index f154b7824..5c67d124d 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -81,7 +81,18 @@ Key rotation to never trigger casually: only the **full** factory reset (`factor - **Never edit or commit files under `src/mesh/generated/`.** They are regenerated from the [`meshtastic/protobufs`](https://github.com/meshtastic/protobufs) repo by the `update_protobufs.yml` workflow (entry point: `bin/regen-protos.sh`). Local edits will be overwritten and create merge conflicts. If a `.proto` change is needed, open a PR against the protobufs repo first, then let the workflow re-sync this repo. - **`confirm=True` on destructive MCP tools is a real gate, not a formality.** Don't bypass it via auto-approve settings. - **Keep code comments minimal - one or two lines, max.** Comment only when the _why_ isn't obvious from the code; never restate what the next line does. No multi-paragraph block comments explaining straightforward changes. The diff and commit message carry the rationale; the code carries the behavior. -- **Use `Throttle` for time-based rate limiting, not raw `millis()` math.** `src/mesh/Throttle.h` provides `Throttle::isWithinTimespanMs(lastMs, intervalMs)` (returns true while inside the cooldown) and `Throttle::execute(&lastMs, intervalMs, func)` (function-pointer form that updates the timestamp on fire). Use these for any "did N ms pass since X" check - raw `millis() > lastMs + N` is rollover-unsafe (breaks after ~49.7 days) and inconsistent with the rest of the codebase. The helpers compute `now - lastMs` with unsigned subtraction, which wraps correctly. +- **Never compare against `millis()` directly. Use `Throttle`.** `src/mesh/Throttle.h` is the sanctioned way to ask about time, and CI enforces this (`millis-deadline-check` in `.github/workflows/test_native.yml` fails the PR on a new `millis() >` / `< millis()` comparison). + - `Throttle::isWithinTimespanMs(lastMs, intervalMs)` - true while still inside the cooldown. + - `Throttle::hasElapsed(lastMs, intervalMs)` - its complement, true once the interval has passed (inclusive `>=`). Prefer this to spelling `!isWithinTimespanMs(...)`. + - `Throttle::execute(&lastMs, intervalMs, func)` - function-pointer form that updates the timestamp on fire. + - `Throttle::deadlinePassed(deadlineMs)` - for a stored absolute deadline that cannot be re-expressed as "interval since an event". + - `Throttle::deadlinePassedAt(nowMs, deadlineMs)` - the same test against a caller-supplied `now`, for a loop that snapshots the clock once and tests many deadlines. Snapshot from `Time::getMillis()`. + + Raw `millis() > deadline` or `deadline < millis()` is rollover-unsafe: the comparison inverts while the deadline sits on the far side of the 32-bit wrap, so the action fires immediately or blocks for roughly the interval it should have waited. All five helpers subtract first, so unsigned wraparound cancels out. `Throttle` reads the clock through `Time::getMillis()` (`src/UptimeClock.h`), so all ~94 of its call sites are time-injectable and a native test can drive the wrap with `Time::setTestMillis()`. + + **Sentinel hazard.** If a deadline variable also encodes "inactive" (`0` for `rebootAtMsec`, `shutdownAtMsec`, `alertBannerUntil`, `fixHoldEnds`; `UINT32_MAX` for `nagCycleCutoff`), test that sentinel _before_ the elapsed comparison - every such value is arithmetically far in the past, so a correct comparison fires on it immediately. Match the test to the sentinel in use: `if (deadline && Throttle::deadlinePassed(deadline))` covers the `0` family, `nagCycleCutoff` needs `deadline != UINT32_MAX` or a separate armed flag (`isNagging`). + + Then decide which way the sentinel should fall - "inactive" does not always mean "suppress". At the GPS fix-hold site `fixHoldEnds == 0` means _no hold is in force_, which is exactly when one must be armed; guarding it with `fixHoldEnds != 0 &&` looks like this rule and inverts the site. See `fixHoldInForce()` in `src/gps/GPS.cpp` and `test/test_gps_fix_hold/`. ## Typical agent workflows diff --git a/CLAUDE.md b/CLAUDE.md index c7150cd2d..325fb7100 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -11,12 +11,13 @@ > > **Need this? It's here.** > -> | | | -> | ------------------------------------------- | ---------------------------------------------------------- | -> | General helpers (clamp, UTF-8, string fmt…) | `src/meshUtils.h` | -> | Logging macros (LOG_DEBUG / INFO / WARN…) | `src/DebugConfiguration.h` | -> | New module skeleton | inherit `ProtobufModule` in `src/mesh/ProtobufModule.h` | -> | Observer / event wiring | `src/Observer.h` | +> | | | +> | --------------------------------------------------------- | ---------------------------------------------------------- | +> | General helpers (clamp, UTF-8, string fmt…) | `src/meshUtils.h` | +> | Logging macros (LOG_DEBUG / INFO / WARN…) | `src/DebugConfiguration.h` | +> | Elapsed time / deadlines (never bare `millis()` compares) | `src/mesh/Throttle.h` | +> | New module skeleton | inherit `ProtobufModule` in `src/mesh/ProtobufModule.h` | +> | Observer / event wiring | `src/Observer.h` | **Read `.github/copilot-instructions.md` first.** That file is the canonical agent-facing document for this repo. It covers project layout, coding conventions, the build system, CI/CD, the native C++ test suite, and the MCP Server & Hardware Test Harness. Read it top-to-bottom before starting any non-trivial change. diff --git a/src/Power.cpp b/src/Power.cpp index d347e7f93..aa752cf63 100644 --- a/src/Power.cpp +++ b/src/Power.cpp @@ -837,12 +837,13 @@ bool Power::setup() void Power::powerCommandsCheck() { - if (rebootAtMsec && millis() > rebootAtMsec) { + // 0 means "not scheduled" for both, and reads as long expired - test it first. + if (rebootAtMsec && Throttle::deadlinePassed(rebootAtMsec)) { LOG_INFO("Rebooting"); reboot(); } - if (shutdownAtMsec && millis() > shutdownAtMsec) { + if (shutdownAtMsec && Throttle::deadlinePassed(shutdownAtMsec)) { shutdownAtMsec = 0; shutdown(); } @@ -884,9 +885,10 @@ void Power::reboot() #elif defined(ARCH_STM32) HAL_NVIC_SystemReset(); #else - rebootAtMsec = -1; - LOG_WARN("FIXME implement reboot for this platform; some settings " - "need restart to apply"); + // 0 disarms; UINT32_MAX would read as long expired and reboot-loop. + rebootAtMsec = 0; + LOG_WARN("FIXME implement reboot for this platform. Note that some settings " + "require a restart to be applied"); #endif } diff --git a/src/PowerFSMThread.h b/src/PowerFSMThread.h index 47c45c262..60a52e71d 100644 --- a/src/PowerFSMThread.h +++ b/src/PowerFSMThread.h @@ -5,6 +5,7 @@ #include "concurrency/OSThread.h" #include "configuration.h" #include "main.h" +#include "mesh/Throttle.h" namespace concurrency { @@ -29,9 +30,9 @@ class PowerFSMThread : public OSThread if (powerStatus->getHasUSB()) { timeLastPowered = millis(); } else if (config.power.on_battery_shutdown_after_secs > 0 && config.power.on_battery_shutdown_after_secs != UINT32_MAX && - millis() > (timeLastPowered + - Default::getConfiguredOrDefaultMs( - config.power.on_battery_shutdown_after_secs))) { // shutdown after 30 minutes unpowered + Throttle::hasElapsed( + timeLastPowered, + Default::getConfiguredOrDefaultMs(config.power.on_battery_shutdown_after_secs))) { // unpowered too long powerFSM.trigger(EVENT_SHUTDOWN); } diff --git a/src/UptimeClock.cpp b/src/UptimeClock.cpp index 5f85f50ff..45f9affad 100644 --- a/src/UptimeClock.cpp +++ b/src/UptimeClock.cpp @@ -1,33 +1,98 @@ // See UptimeClock.h for the full contract. #include "UptimeClock.h" #include +#include uint32_t Time::getMillis() { #ifdef PIO_UNIT_TESTING - if (Time::useTestClock) - return Time::testNowMs; + if (Time::useTestClock.load(std::memory_order_relaxed)) + return Time::testNowMs.load(std::memory_order_relaxed); #endif return millis(); } -uint64_t Time::getMillis64() +namespace { - static uint32_t lastLow = 0; // last 32-bit sample - static uint32_t highWord = 0; // number of observed wraps +struct PublishedSnapshot { + std::atomic high{0}; + std::atomic low{0}; +}; - uint32_t now = Time::getMillis(); +// The constexpr atomic initializers make both snapshots available before firmware startup. +PublishedSnapshot published[2]; +std::atomic publishedGeneration{0}; #ifdef PIO_UNIT_TESTING - // A test swapping clock sources (real <-> injected) can make `now` jump backward for - // reasons other than a genuine wrap - rebase rather than miscount it as one. - if (Time::clockSourceChanged) { - lastLow = now; - highWord = 0; - Time::clockSourceChanged = false; - } +std::atomic monotonicPublishHook{nullptr}; #endif - if (now < lastLow) - highWord++; // low word wrapped since last call - lastLow = now; - return (static_cast(highWord) << 32) | now; + +// Extend a published (high, low) snapshot to `now`; unsigned subtraction is exact across the wrap +// for any gap under 49.7 days. One copy, because reader and writer must agree on it exactly. +uint64_t extendPublished(uint32_t high, uint32_t low, uint32_t now) +{ + return ((((uint64_t)high << 32) | low) + (uint32_t)(now - low)); } + +// A generation change means the writer completed a publish while this copy was being read. A +// paused publish leaves the generation unchanged and writes only the inactive snapshot. +void readPublished(uint32_t &high, uint32_t &low) +{ + for (;;) { + const uint32_t before = publishedGeneration.load(std::memory_order_acquire); + PublishedSnapshot &snapshot = published[before & 1u]; + high = snapshot.high.load(std::memory_order_relaxed); + low = snapshot.low.load(std::memory_order_relaxed); + std::atomic_thread_fence(std::memory_order_acquire); + if (publishedGeneration.load(std::memory_order_relaxed) == before) + return; + } +} +} // namespace + +uint64_t Time::getMillisMonotonic() +{ + uint32_t high, low; + readPublished(high, low); + // The reader writes nothing back; it just extends the last published carry to now. + return extendPublished(high, low, getMillis()); +} + +uint32_t Time::getUptimeSecs() +{ + return (uint32_t)(getMillisMonotonic() / 1000); +} + +void Time::serviceMonotonic() +{ + const uint32_t generation = publishedGeneration.load(std::memory_order_relaxed); + PublishedSnapshot &active = published[generation & 1u]; + const uint32_t low = active.low.load(std::memory_order_relaxed); + const uint32_t high = active.high.load(std::memory_order_relaxed); + const uint64_t next = extendPublished(high, low, getMillis()); + + PublishedSnapshot &inactive = published[(generation + 1u) & 1u]; + inactive.high.store((uint32_t)(next >> 32), std::memory_order_relaxed); + inactive.low.store((uint32_t)next, std::memory_order_relaxed); +#ifdef PIO_UNIT_TESTING + if (const auto hook = monotonicPublishHook.load(std::memory_order_relaxed)) + hook(); +#endif + publishedGeneration.store(generation + 1u, std::memory_order_release); +} + +#ifdef PIO_UNIT_TESTING +void Time::resetMonotonicForTests() +{ + publishedGeneration.store(0, std::memory_order_relaxed); + for (auto &snapshot : published) { + snapshot.high.store(0, std::memory_order_relaxed); + snapshot.low.store(0, std::memory_order_relaxed); + } + monotonicPublishHook.store(nullptr, std::memory_order_relaxed); +} + +void Time::setMonotonicPublishHookForTests(MonotonicPublishHook hook) +{ + monotonicPublishHook.store(hook, std::memory_order_relaxed); +} +#endif diff --git a/src/UptimeClock.h b/src/UptimeClock.h index 9329a7bf6..efc04eb89 100644 --- a/src/UptimeClock.h +++ b/src/UptimeClock.h @@ -1,46 +1,69 @@ #pragma once #include +#ifdef PIO_UNIT_TESTING +#include +#endif // Monotonic uptime clock, injectable so tests can drive a virtual timebase instead of sleeping. // Uptime only; see gps/RTC.h for wall-clock. Not named Time.h: -Isrc would shadow C's . namespace Time { #ifdef PIO_UNIT_TESTING -// Test-only virtual clock; OFF by default so suites relying on real time are unaffected. -inline uint32_t testNowMs = 0; -inline bool useTestClock = false; -inline bool clockSourceChanged = true; // forces getMillis64() to rebase its wrap accumulator +// Test-only virtual clock; OFF by default so suites relying on real time are unaffected. Atomic so +// a suite can step the clock from one thread while others read it - the concurrent-reader cases in +// test_uptime_clock/ do exactly that. +inline std::atomic testNowMs{0}; +inline std::atomic useTestClock{false}; +using MonotonicPublishHook = void (*)(); inline void setTestMillis(uint32_t ms) { - testNowMs = ms; - useTestClock = true; - clockSourceChanged = true; + testNowMs.store(ms, std::memory_order_relaxed); + useTestClock.store(true, std::memory_order_relaxed); } inline void advanceTestMillis(uint32_t deltaMs) { - // Advancing from 0 after getMillis64() sampled the real clock steps backward, which would - // otherwise be miscounted as a wrap. - if (!useTestClock) - clockSourceChanged = true; - testNowMs += deltaMs; - useTestClock = true; + testNowMs.fetch_add(deltaMs, std::memory_order_relaxed); + useTestClock.store(true, std::memory_order_relaxed); } // Restore real-clock behaviour (call in test tearDown if a suite mixes real and fake time). inline void useRealClock() { - useTestClock = false; - testNowMs = 0; - clockSourceChanged = true; + useTestClock.store(false, std::memory_order_relaxed); + testNowMs.store(0, std::memory_order_relaxed); } +// Zero the published wrap carry. Suites that assert absolute uptime values call this in setUp(): +// a previous case that moved the test clock backwards left a counted wrap behind. +void resetMonotonicForTests(); +void setMonotonicPublishHookForTests(MonotonicPublishHook hook); #endif -/// Milliseconds since boot, 32-bit (wraps ~49.7 days). Drop-in for millis(). +/// Milliseconds since boot, 32-bit (wraps ~49.7 days). Drop-in for millis(). For "has this interval +/// elapsed / deadline arrived" use Throttle (isWithinTimespanMs / hasElapsed / deadlinePassed), +/// which is wrap-correct with no carry state at all. uint32_t getMillis(); -/// Milliseconds since boot, 64-bit, rollover-immune. Must be polled at least once per ~49.7-day -/// wrap window to catch every wrap, and keeps mutable static carry state, so it is NOT ISR-safe. -uint64_t getMillis64(); +/// Milliseconds since boot as a monotonic 64-bit count. +/// +/// A pure read: it derives its answer from a complete snapshot published by serviceMonotonic() +/// plus the unsigned elapsed time since that snapshot, which is exact across the wrap. A reader +/// that preempts publication uses the previous snapshot. If publication completes during a copy, +/// the reader retries; it never waits for a publish in progress. +/// +/// Not intended for ISR call sites because lock-free std::atomic operations are not guaranteed by +/// every supported toolchain. ISRs use getMillis(); the publication protocol itself never waits. +uint64_t getMillisMonotonic(); + +/// Whole seconds since boot, derived from getMillisMonotonic() (~136 years of range). This is +/// the unit to store when an instant must be dated before the wall clock is trustworthy. +uint32_t getUptimeSecs(); + +/// Advances the published wrap carry. THE ONLY WRITER - call it from the main loop and nowhere +/// else. Two concurrent callers could count one wrap twice, jumping every uptime and wall-clock +/// reading ~49.7 days forward for the rest of the boot. +/// +/// Must run at least once per ~49.7-day wrap window; the main loop calls it every iteration. +void serviceMonotonic(); } // namespace Time diff --git a/src/airtime.cpp b/src/airtime.cpp index 0e0d72e20..a9b4c7dc5 100644 --- a/src/airtime.cpp +++ b/src/airtime.cpp @@ -1,6 +1,8 @@ #include "airtime.h" #include "NodeDB.h" +#include "UptimeClock.h" #include "configuration.h" +#include AirTime *airTime = NULL; @@ -11,6 +13,9 @@ uint32_t air_period_rx[PERIODS_TO_LOG]; void AirTime::logAirtime(reportTypes reportType, uint32_t airtime_ms) { + // A packet may be logged immediately after waking from light sleep. Sync first so + // the packet is counted in the current wall-time bucket, not a stale awake-time bucket. + syncNow(); if (reportType == TX_LOG) { LOG_DEBUG("Packet TX: %ums", airtime_ms); @@ -33,47 +38,112 @@ void AirTime::logAirtime(reportTypes reportType, uint32_t airtime_ms) uint8_t AirTime::currentPeriodIndex() { - return ((getSecondsSinceBoot() / SECONDS_PER_PERIOD) % PERIODS_TO_LOG); + return ((secSinceBoot / SECONDS_PER_PERIOD) % PERIODS_TO_LOG); } uint8_t AirTime::getPeriodUtilMinute() { - return (getSecondsSinceBoot() / 10) % CHANNEL_UTILIZATION_PERIODS; + return (secSinceBoot / 10) % CHANNEL_UTILIZATION_PERIODS; } uint8_t AirTime::getPeriodUtilHour() { - return (getSecondsSinceBoot() / 60) % MINUTES_IN_HOUR; + return (secSinceBoot / 60) % MINUTES_IN_HOUR; } void AirTime::airtimeRotatePeriod() { + // Preserve the public helper while keeping all rotation logic in one monotonic-time path. + syncNow(); +} - if (this->airtimes.lastPeriodIndex != this->currentPeriodIndex()) { - LOG_DEBUG("Rotate airtimes to a new period = %u", this->currentPeriodIndex()); +void AirTime::syncNow() +{ + // Monotonic uptime, not RTC/network time: a user, GPS, or NTP clock change must not move + // airtime accounting. Pure read; the main loop publishes the wrap carry it derives from. + uint32_t nowSecs = Time::getUptimeSecs(); - for (int i = PERIODS_TO_LOG - 2; i >= 0; --i) { - this->airtimes.periodTX[i + 1] = this->airtimes.periodTX[i]; - this->airtimes.periodRX[i + 1] = this->airtimes.periodRX[i]; - this->airtimes.periodRX_ALL[i + 1] = this->airtimes.periodRX_ALL[i]; - - air_period_tx[i + 1] = this->airtimes.periodTX[i]; - air_period_rx[i + 1] = this->airtimes.periodRX[i]; - } - - this->airtimes.periodTX[0] = 0; - this->airtimes.periodRX[0] = 0; - this->airtimes.periodRX_ALL[0] = 0; - - air_period_tx[0] = 0; - air_period_rx[0] = 0; + if (firstTime) { + memset(this->utilizationTX, 0, sizeof(this->utilizationTX)); + memset(this->channelUtilization, 0, sizeof(this->channelUtilization)); + memset(this->airtimes.periodTX, 0, sizeof(this->airtimes.periodTX)); + memset(this->airtimes.periodRX, 0, sizeof(this->airtimes.periodRX)); + memset(this->airtimes.periodRX_ALL, 0, sizeof(this->airtimes.periodRX_ALL)); + memset(air_period_tx, 0, sizeof(air_period_tx)); + memset(air_period_rx, 0, sizeof(air_period_rx)); + this->secSinceBoot = nowSecs; + this->lastUtilPeriod = this->getPeriodUtilMinute(); + this->lastUtilPeriodTX = this->getPeriodUtilHour(); this->airtimes.lastPeriodIndex = this->currentPeriodIndex(); + firstTime = false; + return; } + + if (nowSecs == this->secSinceBoot) { + return; + } + + uint32_t oldSecSinceBoot = this->secSinceBoot; + this->secSinceBoot = nowSecs; + + // Historical airtime reports use 1-hour buckets. If multiple hours elapsed while + // asleep, rotate each crossed bucket or clear the whole report window. + uint32_t elapsedAirtimePeriods = (this->secSinceBoot / SECONDS_PER_PERIOD) - (oldSecSinceBoot / SECONDS_PER_PERIOD); + if (elapsedAirtimePeriods >= PERIODS_TO_LOG) { + memset(this->airtimes.periodTX, 0, sizeof(this->airtimes.periodTX)); + memset(this->airtimes.periodRX, 0, sizeof(this->airtimes.periodRX)); + memset(this->airtimes.periodRX_ALL, 0, sizeof(this->airtimes.periodRX_ALL)); + memset(air_period_tx, 0, sizeof(air_period_tx)); + memset(air_period_rx, 0, sizeof(air_period_rx)); + } else { + while (elapsedAirtimePeriods-- > 0) { + LOG_DEBUG("Rotate airtimes to a new period = %u", this->currentPeriodIndex()); + for (int i = PERIODS_TO_LOG - 2; i >= 0; --i) { + this->airtimes.periodTX[i + 1] = this->airtimes.periodTX[i]; + this->airtimes.periodRX[i + 1] = this->airtimes.periodRX[i]; + this->airtimes.periodRX_ALL[i + 1] = this->airtimes.periodRX_ALL[i]; + air_period_tx[i + 1] = this->airtimes.periodTX[i]; + air_period_rx[i + 1] = this->airtimes.periodRX[i]; + } + + this->airtimes.periodTX[0] = 0; + this->airtimes.periodRX[0] = 0; + this->airtimes.periodRX_ALL[0] = 0; + air_period_tx[0] = 0; + air_period_rx[0] = 0; + } + } + this->airtimes.lastPeriodIndex = this->currentPeriodIndex(); + + // Channel utilization is a rolling 60-second view split into six 10-second buckets. + // Clear every bucket crossed while asleep so old airtime decays by real elapsed time. + uint32_t elapsedUtilPeriods = (this->secSinceBoot / 10) - (oldSecSinceBoot / 10); + if (elapsedUtilPeriods >= CHANNEL_UTILIZATION_PERIODS) { + memset(this->channelUtilization, 0, sizeof(this->channelUtilization)); + } else { + for (uint32_t i = 1; i <= elapsedUtilPeriods; i++) { + this->channelUtilization[((oldSecSinceBoot / 10) + i) % CHANNEL_UTILIZATION_PERIODS] = 0; + } + } + this->lastUtilPeriod = this->getPeriodUtilMinute(); + + // TX utilization is a rolling 60-minute view used by duty-cycle checks. + uint32_t elapsedUtilTXPeriods = (this->secSinceBoot / 60) - (oldSecSinceBoot / 60); + if (elapsedUtilTXPeriods >= MINUTES_IN_HOUR) { + memset(this->utilizationTX, 0, sizeof(this->utilizationTX)); + } else { + for (uint32_t i = 1; i <= elapsedUtilTXPeriods; i++) { + this->utilizationTX[((oldSecSinceBoot / 60) + i) % MINUTES_IN_HOUR] = 0; + } + } + this->lastUtilPeriodTX = this->getPeriodUtilHour(); } uint32_t *AirTime::airtimeReport(reportTypes reportType) { + // Reports may be requested before runOnce() executes after wake. + syncNow(); if (reportType == TX_LOG) { return this->airtimes.periodTX; @@ -97,11 +167,16 @@ uint32_t AirTime::getSecondsPerPeriod() uint32_t AirTime::getSecondsSinceBoot() { + // Keep HTTP/debug reporting aligned with the same monotonic clock used by the buckets. + syncNow(); return this->secSinceBoot; } float AirTime::channelUtilizationPercent() { + // Gate decisions should see buckets that have decayed across light-sleep time. + syncNow(); + uint32_t sum = 0; for (uint32_t i = 0; i < CHANNEL_UTILIZATION_PERIODS; i++) { sum += this->channelUtilization[i]; @@ -112,6 +187,9 @@ float AirTime::channelUtilizationPercent() float AirTime::utilizationTXPercent() { + // Duty-cycle checks use this value, so keep it current even outside the periodic thread. + syncNow(); + uint32_t sum = 0; for (uint32_t i = 0; i < MINUTES_IN_HOUR; i++) { sum += this->utilizationTX[i]; @@ -162,50 +240,6 @@ AirTime::AirTime() : concurrency::OSThread("AirTime"), airtimes({}) {} int32_t AirTime::runOnce() { - secSinceBoot++; - - uint8_t utilPeriod = this->getPeriodUtilMinute(); - uint8_t utilPeriodTX = this->getPeriodUtilHour(); - - if (firstTime) { - - // Init utilizationTX window to all 0 - for (uint32_t i = 0; i < MINUTES_IN_HOUR; i++) { - this->utilizationTX[i] = 0; - } - - // Init channelUtilization window to all 0 - for (uint32_t i = 0; i < CHANNEL_UTILIZATION_PERIODS; i++) { - this->channelUtilization[i] = 0; - } - - // Init airtime windows to all 0 - for (int i = 0; i < PERIODS_TO_LOG; i++) { - this->airtimes.periodTX[i] = 0; - this->airtimes.periodRX[i] = 0; - this->airtimes.periodRX_ALL[i] = 0; - - // air_period_tx[i] = 0; - // air_period_rx[i] = 0; - } - - firstTime = false; - lastUtilPeriod = utilPeriod; - } else { - this->airtimeRotatePeriod(); - - // Reset the channelUtilization window when we roll over - if (lastUtilPeriod != utilPeriod) { - lastUtilPeriod = utilPeriod; - - this->channelUtilization[utilPeriod] = 0; - } - - if (lastUtilPeriodTX != utilPeriodTX) { - lastUtilPeriodTX = utilPeriodTX; - - this->utilizationTX[utilPeriodTX] = 0; - } - } + syncNow(); return (1000 * 1); } diff --git a/src/airtime.h b/src/airtime.h index 8e3e6c557..39c1d3e03 100644 --- a/src/airtime.h +++ b/src/airtime.h @@ -39,6 +39,12 @@ void logAirtime(reportTypes reportType, uint32_t airtime_ms); uint32_t *airtimeReport(reportTypes reportType); +// Not thread-safe: everything but getPeriodsToLog()/getSecondsPerPeriod() either rotates the +// windows via syncNow() or reads the buckets. Current callers are all on the OSThread scheduler - +// RadioLibInterface/SimRadio, RadioInterface, Router, DeviceTelemetry, ContentHandler, and the +// screen renderers. New callers must be on that thread too, or this needs a lock. +// TODO: airtime lock-guarding - serialise the above behind a lock so the contract is enforced +// rather than documented. Kept out of this PR: it is a separate concern from millis() rollover. class AirTime : private concurrency::OSThread { @@ -66,6 +72,8 @@ class AirTime : private concurrency::OSThread bool firstTime = true; uint8_t lastUtilPeriod = 0; uint8_t lastUtilPeriodTX = 0; + // Time::getUptimeSecs() as of the last syncNow(); the gap since is what the windows rotate by, + // so they stay correct even if the scheduler was paused by light sleep. uint32_t secSinceBoot = 0; uint8_t max_channel_util_percent = 40; uint8_t polite_channel_util_percent = 25; @@ -81,6 +89,8 @@ class AirTime : private concurrency::OSThread uint8_t getPeriodUtilMinute(); uint8_t getPeriodUtilHour(); uint8_t currentPeriodIndex(); + // Advance rolling airtime windows from monotonic uptime, not from runOnce() calls. + void syncNow(); protected: virtual int32_t runOnce() override; diff --git a/src/gps/GPS.cpp b/src/gps/GPS.cpp index 2ca1d86d1..69000f2fe 100644 --- a/src/gps/GPS.cpp +++ b/src/gps/GPS.cpp @@ -10,6 +10,7 @@ #include "NodeDB.h" #include "PowerMon.h" #include "Throttle.h" +#include "UptimeClock.h" #include "buzz.h" #include "concurrency/Periodic.h" #include "gps/RTC.h" @@ -350,11 +351,13 @@ GPS_RESPONSE GPS::getACK(const char *message, uint32_t waitMillis) uint8_t buffer[768] = {0}; uint8_t b; int bytesRead = 0; - uint32_t startTimeout = millis() + waitMillis; + // Start stamp + interval rather than a stored deadline: same wrap-safety, but the full 49.7-day + // range instead of 24.8 days ahead, and Time::getMillis() makes the wait injectable. + const uint32_t waitStartMs = Time::getMillis(); #if GPS_DEBUG std::string debugmsg = ""; #endif - while (millis() < startTimeout) { + while (Throttle::isWithinTimespanMs(waitStartMs, waitMillis)) { if (_serial_gps->available()) { b = _serial_gps->read(); @@ -1422,6 +1425,29 @@ void GPS::publishUpdate() } } +/// Is a post-lock ephemeris hold currently in force? The `!= 0` is the "never armed" sentinel, which +/// deadlinePassed() reads as passed for the first half of each wrap cycle and as ~24.8 days in the +/// future for the second. No header: test_gps_fix_hold declares the prototypes itself. +bool fixHoldInForce(uint32_t fixHoldEnds, uint32_t threadIntervalMs) +{ + return fixHoldEnds != 0 && !Throttle::deadlinePassed(fixHoldEnds + threadIntervalMs); +} + +/// Did an armed hold just expire? `!= 0` guards against negating fixHoldInForce() alone, which would +/// call an unarmed hold "expired" every cycle. No grace interval: the deadline itself is go-down time. +bool holdJustExpired(uint32_t fixHoldEnds) +{ + return fixHoldEnds != 0 && !fixHoldInForce(fixHoldEnds, 0); +} + +/// Should a post-lock ephemeris hold be (re-)armed this cycle? "No hold in force" fires often, since +/// every publish clears the hold, including ones that don't put the receiver back to sleep. +bool shouldArmFixHold(bool hasValidLocation, uint8_t prevFixQual, uint32_t fixHoldEnds, uint32_t threadIntervalMs) +{ + // First lock of a cycle, first lock after the receiver was off, or nothing holding right now. + return !hasValidLocation || prevFixQual == 0 || !fixHoldInForce(fixHoldEnds, threadIntervalMs); +} + int32_t GPS::runOnce() { #if defined(SENSECAP_INDICATOR) @@ -1522,13 +1548,15 @@ int32_t GPS::runOnce() if (updateInterval <= GPS_UPDATE_ALWAYS_ON_THRESHOLD_MS) { hasValidLocation = true; shouldPublish = true; - } else if (!hasValidLocation || prev_fixQual == 0 || (fixHoldEnds + GPS_THREAD_INTERVAL) < millis()) { + } else if (shouldArmFixHold(hasValidLocation, prev_fixQual, fixHoldEnds, GPS_THREAD_INTERVAL)) { hasValidLocation = true; // Hold for up to 20secs after getting a lock to download ephemeris etc uint32_t holdTime = updateInterval - GPS_UPDATE_ALWAYS_ON_THRESHOLD_MS; if (holdTime > GPS_FIX_HOLD_MAX_MS) holdTime = GPS_FIX_HOLD_MAX_MS; - fixHoldEnds = millis() + holdTime; + // Same clock the Throttle evaluation reads, and never the "no hold" sentinel. + const uint32_t holdEnds = Time::getMillis() + holdTime; + fixHoldEnds = holdEnds == 0 ? 1 : holdEnds; LOG_DEBUG_GPS("Holding for %ums after lock", holdTime); } } @@ -1546,7 +1574,7 @@ int32_t GPS::runOnce() } // Hold has expired , Search time has expired, we got a time only, or we never needed to hold. - bool holdExpired = (fixHoldEnds != 0 && millis() > fixHoldEnds); + bool holdExpired = holdJustExpired(fixHoldEnds); if (shouldPublish || tooLong || holdExpired) { if (gotTime && hasValidLocation) { shouldPublish = true; @@ -1563,7 +1591,7 @@ int32_t GPS::runOnce() #if GPS_DEBUG } else if (fixHoldEnds != 0) { - LOG_DEBUG("Holding for GPS data download: %d ms (numSats=%d)", fixHoldEnds - millis(), p.sats_in_view); + LOG_DEBUG("Holding for GPS data download: %d ms (numSats=%d)", fixHoldEnds - Time::getMillis(), p.sats_in_view); #endif } } diff --git a/src/gps/RTC.cpp b/src/gps/RTC.cpp index 99153e764..5c18cca62 100644 --- a/src/gps/RTC.cpp +++ b/src/gps/RTC.cpp @@ -1,10 +1,12 @@ #include "gps/RTC.h" +#include "UptimeClock.h" #include "configuration.h" #include "detect/ScanI2C.h" #include "detect/ScanI2CTwoWire.h" #include "gps/GPSLog.h" #include "main.h" #include "mesh/MeshService.h" +#include "mesh/NodeDB.h" #include "modules/NodeInfoModule.h" #include #include @@ -26,9 +28,12 @@ static void onTimeSourceQualityChanged(RTCQuality oldQuality, RTCQuality newQual LOG_DEBUG("Time source acquired (%s -> %s), recheck NodeInfo", RtcName(oldQuality), RtcName(newQuality)); nodeInfoModule->triggerImmediateNodeInfoCheck(); } - if (oldQuality < RTCQualityFromNet && newQuality >= RTCQualityFromNet && service) { + if (oldQuality < RTCQualityFromNet && newQuality >= RTCQualityFromNet) { LOG_DEBUG("RTC net quality reached (%s -> %s), reconciling rx_time", RtcName(oldQuality), RtcName(newQuality)); - service->reconcilePendingRxTimes(); + if (service) + service->reconcilePendingRxTimes(); + if (nodeDB) + nodeDB->backfillHeardAt(); } } @@ -38,8 +43,9 @@ RTCQuality getRTCQuality() } // stuff that really should be in in the instance instead... -static uint32_t - timeStartMsec; // Once we have a GPS lock, this is where we hold the initial msec clock that corresponds to that time +// The Time::getMillisMonotonic() instant corresponding to zeroOffsetSecs. 64-bit so getTime()'s +// elapsed term cannot wrap: a 32-bit anchor walks the wall clock back 49.7 days per millis() cycle. +static uint64_t timeStartMs64; static uint64_t zeroOffsetSecs; // GPS based time in secs since 1970 - only updated once on initial lock #ifdef PIO_UNIT_TESTING @@ -71,11 +77,11 @@ static struct timeval mockSystemTime = {}; { struct timeval tv; if (readSystemTime(&tv)) { - uint32_t now = millis(); + const uint64_t now = Time::getMillisMonotonic(); uint32_t printableEpoch = tv.tv_sec; // Print lib only supports 32 bit but time_t can be 64 bit on some platforms if (currentQuality == RTCQualityNone) { LOG_DEBUG("Seed time from system clock: %lu", (unsigned long)printableEpoch); - timeStartMsec = now; + timeStartMs64 = now; zeroOffsetSecs = tv.tv_sec; } else { LOG_DEBUG("Ignore system clock fallback (%lu); RTC quality is %s", (unsigned long)printableEpoch, @@ -101,7 +107,7 @@ RTCSetResult readFromRTC() [[maybe_unused]] struct timeval tv; /* btw settimeofday() is helpful here too*/ #ifdef RV3028_RTC if (rtc_found.address == RV3028_RTC) { - uint32_t now = millis(); + const uint64_t now = Time::getMillisMonotonic(); Melopero_RV3028 rtc; #if WIRE_INTERFACES_COUNT == 2 rtc.initI2C(*ScanI2CTwoWire::fetchI2CBus(rtc_found)); @@ -132,7 +138,7 @@ RTCSetResult readFromRTC() t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec, printableEpoch); if (currentQuality == RTCQualityNone) { RTCQuality oldQuality = currentQuality; - timeStartMsec = now; + timeStartMs64 = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; onTimeSourceQualityChanged(oldQuality, currentQuality); @@ -150,7 +156,7 @@ RTCSetResult readFromRTC() SensorPCF85063 rtc; #endif - uint32_t now = millis(); + const uint64_t now = Time::getMillisMonotonic(); #if WIRE_INTERFACES_COUNT == 2 rtc.begin(*ScanI2CTwoWire::fetchI2CBus(rtc_found)); @@ -178,7 +184,7 @@ RTCSetResult readFromRTC() t.tm_mon + 1, t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec, printableEpoch); if (currentQuality == RTCQualityNone) { RTCQuality oldQuality = currentQuality; - timeStartMsec = now; + timeStartMs64 = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; onTimeSourceQualityChanged(oldQuality, currentQuality); @@ -189,7 +195,7 @@ RTCSetResult readFromRTC() } #elif defined(RX8130CE_RTC) if (rtc_found.address == RX8130CE_RTC) { - uint32_t now = millis(); + const uint64_t now = Time::getMillisMonotonic(); #ifdef MUZI_BASE ArtronShop_RX8130CE rtc(&Wire1); #else @@ -214,7 +220,7 @@ RTCSetResult readFromRTC() #endif if (currentQuality == RTCQualityNone) { RTCQuality oldQuality = currentQuality; - timeStartMsec = now; + timeStartMs64 = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; onTimeSourceQualityChanged(oldQuality, currentQuality); @@ -224,7 +230,7 @@ RTCSetResult readFromRTC() } #elif HAS_LSE if (stm32wlRtcAvailable()) { - uint32_t now = millis(); + const uint64_t now = Time::getMillisMonotonic(); tv.tv_sec = STM32RTC::getInstance().getEpoch(); tv.tv_usec = 0; uint32_t printableEpoch = tv.tv_sec; // Print lib only supports 32 bit but time_t can be 64 bit on some platforms @@ -239,7 +245,7 @@ RTCSetResult readFromRTC() #endif if (currentQuality == RTCQualityNone) { RTCQuality oldQuality = currentQuality; - timeStartMsec = now; + timeStartMs64 = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; onTimeSourceQualityChanged(oldQuality, currentQuality); @@ -264,7 +270,8 @@ RTCSetResult readFromRTC() RTCSetResult perhapsSetRTC(RTCQuality q, const struct timeval *tv, bool forceUpdate) { static uint32_t lastSetMsec = 0; - uint32_t now = millis(); + const uint64_t now64 = Time::getMillisMonotonic(); + const uint32_t now = (uint32_t)now64; // low word == getMillis(); fine for the Throttle-checked stamps below uint32_t printableEpoch = tv->tv_sec; // Print lib only supports 32 bit but time_t can be 64 bit on some platforms #ifdef BUILD_EPOCH if (tv->tv_sec < BUILD_EPOCH) { @@ -314,7 +321,7 @@ RTCSetResult perhapsSetRTC(RTCQuality q, const struct timeval *tv, bool forceUpd } // This delta value works on all platforms - timeStartMsec = now; + timeStartMs64 = now64; zeroOffsetSecs = tv->tv_sec; // If this platform has a settable RTC, set it #ifdef RV3028_RTC @@ -486,10 +493,12 @@ int32_t getTZOffset() */ uint32_t getTime(bool local) { + // Both terms are 64-bit monotonic, so the elapsed time cannot wrap - see timeStartMs64. + const uint64_t elapsedSecs = (Time::getMillisMonotonic() - timeStartMs64) / 1000; if (local) { - return (((uint32_t)millis() - timeStartMsec) / 1000) + zeroOffsetSecs + getTZOffset(); + return elapsedSecs + zeroOffsetSecs + getTZOffset(); } else { - return (((uint32_t)millis() - timeStartMsec) / 1000) + zeroOffsetSecs; + return elapsedSecs + zeroOffsetSecs; } } @@ -509,7 +518,7 @@ void setBootRelativeTimeForUnitTest(uint32_t secondsSinceBoot) { currentQuality = RTCQualityNone; zeroOffsetSecs = 0; - timeStartMsec = millis() - (secondsSinceBoot * 1000); + timeStartMs64 = Time::getMillisMonotonic() - ((uint64_t)secondsSinceBoot * 1000); lastSetFromPhoneNtpOrGps = 0; lastTimeValidationWarning = 0; } @@ -538,7 +547,7 @@ void setReadFromRTCUseSystemTimeForTests(bool enabled) void resetRTCStateForTests() { currentQuality = RTCQualityNone; - timeStartMsec = 0; + timeStartMs64 = 0; zeroOffsetSecs = 0; lastSetFromPhoneNtpOrGps = 0; lastTimeValidationWarning = 0; diff --git a/src/graphics/EInkDynamicDisplay.cpp b/src/graphics/EInkDynamicDisplay.cpp index be05cd0c3..c51f0a5bb 100644 --- a/src/graphics/EInkDynamicDisplay.cpp +++ b/src/graphics/EInkDynamicDisplay.cpp @@ -232,9 +232,7 @@ void EInkDynamicDisplay::checkForPromotion() // Is it too soon for another frame of this type? void EInkDynamicDisplay::checkRateLimiting() { - // Sanity check: millis() overflow - just let the update run.. - if (previousRunMs > millis()) - return; + // No millis()-overflow guard needed: the Throttle checks below are wrap-correct already. // Skip update: too soon for BACKGROUND if (frameFlags == BACKGROUND) { diff --git a/src/graphics/Screen.cpp b/src/graphics/Screen.cpp index 55c565c3c..c8271ddf1 100644 --- a/src/graphics/Screen.cpp +++ b/src/graphics/Screen.cpp @@ -1112,7 +1112,7 @@ int32_t Screen::runOnce() // Show boot screen for first logo_timeout seconds, then switch to normal operation. // serialSinceMsec adjusts for additional serial wait time during nRF52 bootup static bool showingBootScreen = true; - if (showingBootScreen && (millis() > (logo_timeout + serialSinceMsec))) { + if (showingBootScreen && Throttle::hasElapsed(serialSinceMsec, logo_timeout)) { LOG_INFO("Done with boot screen"); stopBootScreen(); showingBootScreen = false; @@ -1120,8 +1120,8 @@ int32_t Screen::runOnce() #ifdef USERPREFS_OEM_TEXT static bool showingOEMBootScreen = true; - if (showingOEMBootScreen && (millis() > ((logo_timeout / 2) + serialSinceMsec))) { - LOG_INFO("Switch to OEM screen"); + if (showingOEMBootScreen && Throttle::hasElapsed(serialSinceMsec, logo_timeout / 2)) { + LOG_INFO("Switch to OEM screen..."); // Change frames. static FrameCallback bootOEMFrames[] = {graphics::UIRenderer::drawOEMBootScreen}; static const int bootOEMFrameCount = sizeof(bootOEMFrames) / sizeof(bootOEMFrames[0]); diff --git a/src/graphics/draw/NotificationRenderer.cpp b/src/graphics/draw/NotificationRenderer.cpp index d71ca6d08..7abfd210d 100644 --- a/src/graphics/draw/NotificationRenderer.cpp +++ b/src/graphics/draw/NotificationRenderer.cpp @@ -12,6 +12,7 @@ #include "graphics/images.h" #include "input/RotaryEncoderInterruptImpl1.h" #include "input/UpDownInterruptImpl1.h" +#include "mesh/Throttle.h" #if HAS_BUTTON #include "input/ButtonThread.h" #endif @@ -253,7 +254,7 @@ void NotificationRenderer::drawBannercallback(OLEDDisplay *display, OLEDDisplayU // Handle text_input notifications first - they have their own timeout/banner logic if (current_notification_type == notificationTypeEnum::text_input) { // Check for timeout and reset if needed for text input - if (millis() > alertBannerUntil && alertBannerUntil > 0) { + if (alertBannerUntil > 0 && Throttle::deadlinePassed(alertBannerUntil)) { resetBanner(); return; } @@ -261,7 +262,8 @@ void NotificationRenderer::drawBannercallback(OLEDDisplay *display, OLEDDisplayU return; } - if (millis() > alertBannerUntil && alertBannerUntil > 0) { + // 0 means "no deadline set", and reads as long expired - test it first. + if (alertBannerUntil > 0 && Throttle::deadlinePassed(alertBannerUntil)) { resetBanner(); } @@ -1226,7 +1228,8 @@ void NotificationRenderer::drawTextInput(OLEDDisplay *display, OLEDDisplayUiStat bool NotificationRenderer::isOverlayBannerShowing() { - return strlen(alertBannerMessage) > 0 && (alertBannerUntil == 0 || millis() <= alertBannerUntil); + // Here 0 means "show indefinitely", so it must short-circuit the comparison. + return strlen(alertBannerMessage) > 0 && (alertBannerUntil == 0 || !Throttle::deadlinePassed(alertBannerUntil)); } bool NotificationRenderer::isMenuShowing() diff --git a/src/input/RotaryEncoderImpl.cpp b/src/input/RotaryEncoderImpl.cpp index dcdbf0d36..88075c2f1 100644 --- a/src/input/RotaryEncoderImpl.cpp +++ b/src/input/RotaryEncoderImpl.cpp @@ -3,6 +3,7 @@ #include "RotaryEncoderImpl.h" #include "InputBroker.h" #include "RotaryEncoder.h" +#include "mesh/Throttle.h" #ifdef ARCH_ESP32 #include "sleep.h" #endif @@ -66,7 +67,7 @@ void RotaryEncoderImpl::pollOnce() static uint32_t lastPressed = millis(); if (rotary->readButton() == RotaryEncoder::ButtonState::BUTTON_PRESSED) { - if (lastPressed + 200 < millis()) { + if (Throttle::hasElapsed(lastPressed, 200)) { LOG_DEBUG("Rotary event Press"); lastPressed = millis(); e.inputEvent = this->eventPressed; diff --git a/src/main.cpp b/src/main.cpp index e51dee109..3a4eb5f5f 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -16,6 +16,7 @@ #include "RadioLibInterface.h" #include "ReliableRouter.h" #include "TransmitHistory.h" +#include "UptimeClock.h" #include "airtime.h" #include "buzz.h" #include "power/PowerHAL.h" @@ -1360,6 +1361,9 @@ void loop() { runASAP = false; + // The single writer of the monotonic wrap carry; every other caller only reads it. + Time::serviceMonotonic(); + #if defined(MESHTASTIC_ENCRYPTED_STORAGE) && defined(MESHTASTIC_PHONEAPI_ACCESS_CONTROL) if (lockdownDisablePending) { lockdownDisablePending = false; diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index 77540660b..162d15353 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -182,14 +182,14 @@ NodeNum MeshService::getNodenumFromRequestId(uint32_t request_id) return nodenum; } -// Back-calculate the real epoch for any queued packet still carrying a millis() rx_time +// Back-calculate the real epoch for any queued packet still carrying an uptime-seconds rx_time // placeholder, now that the clock is trustworthy. void MeshService::reconcilePendingRxTimes() { const uint32_t nowEpoch = getValidTime(RTCQualityFromNet); if (nowEpoch == 0) // called before the clock was actually valid - nothing to reconcile against return; - const uint32_t nowMillis = Time::getMillis(); + const uint32_t nowUptimeSecs = Time::getUptimeSecs(); // Rotate the queue once. TypedQueue is strictly FIFO on both backends, so dequeueing and // re-enqueueing every element in turn leaves the delivery order unchanged. @@ -198,11 +198,13 @@ void MeshService::reconcilePendingRxTimes() if (!p) // drained from under us - nothing left to rotate break; if (!p->has_rx_time) { - // Unsigned subtraction is wraparound-safe; rx_time is a 32-bit wire field, so the - // placeholder was never wider than 32 bits to begin with. - const uint32_t elapsedMs = nowMillis - p->rx_time; - p->rx_time = nowEpoch - (elapsedMs / 1000); - p->has_rx_time = true; + // Both stamps are monotonic uptime seconds, so the elapsed term is exact at any age. + // If it somehow exceeds the epoch, leave the packet un-dated rather than pre-1970. + const uint32_t elapsedSecs = nowUptimeSecs - p->rx_time; + if (elapsedSecs < nowEpoch) { + p->rx_time = nowEpoch - elapsedSecs; + p->has_rx_time = true; + } } if (!toPhoneQueue.enqueue(p, 0)) { // mirrors sendToPhone()'s degrade-on-failure path LOG_CRIT("Requeue to toPhoneQueue failed"); @@ -627,7 +629,7 @@ bool MeshService::isToPhoneQueueEmpty() uint32_t MeshService::GetTimeSinceMeshPacket(const meshtastic_MeshPacket *mp) { - // rx_time may be a millis() placeholder while has_rx_time is false - don't age it as + // rx_time may be an uptime-seconds placeholder while has_rx_time is false - don't age it as // wall-clock, and don't pass it off as "just now" either. if (!mp->has_rx_time) return SINCE_UNKNOWN; diff --git a/src/mesh/MeshService.h b/src/mesh/MeshService.h index bae955969..8ddc6e434 100644 --- a/src/mesh/MeshService.h +++ b/src/mesh/MeshService.h @@ -137,8 +137,8 @@ class MeshService // search the queue for a request id and return the matching nodenum NodeNum getNodenumFromRequestId(uint32_t request_id); - // Rewrite any queued-for-phone packet still carrying a millis() rx_time placeholder into a - // real epoch, now that the wall clock is trustworthy. + // Rewrite any queued-for-phone packet still carrying an uptime-seconds rx_time placeholder + // into a real epoch, now that the wall clock is trustworthy. void reconcilePendingRxTimes(); // Release QueueStatus packet to pool diff --git a/src/mesh/NextHopRouter.cpp b/src/mesh/NextHopRouter.cpp index d7d396f60..3be7a1ba6 100644 --- a/src/mesh/NextHopRouter.cpp +++ b/src/mesh/NextHopRouter.cpp @@ -1,6 +1,8 @@ #include "NextHopRouter.h" #include "Default.h" #include "MeshTypes.h" +#include "Throttle.h" +#include "UptimeClock.h" #include "meshUtils.h" #if !MESHTASTIC_EXCLUDE_TRACEROUTE #include "modules/TraceRouteModule.h" @@ -403,7 +405,9 @@ PendingPacket *NextHopRouter::startRetransmission(meshtastic_MeshPacket *p, uint */ int32_t NextHopRouter::doRetransmissions() { - uint32_t now = millis(); + // Same clock Throttle reads, so setNextTx() deadlines and this test can't diverge under an + // injected test clock. + uint32_t now = Time::getMillis(); int32_t d = INT32_MAX; // FIXME, we should use a better datastructure rather than walking through this map. @@ -414,8 +418,9 @@ int32_t NextHopRouter::doRetransmissions() bool stillValid = true; // assume we'll keep this record around - // FIXME, handle 51 day rolloever here!!! - if (p.nextTxMsec <= now) { + // Judged against the snapshot above, so one pass sees one instant and the 49.7 day wrap + // can't stall retransmission. + if (Throttle::deadlinePassedAt(now, p.nextTxMsec)) { if (p.numRetransmissions == 0) { if (isFromUs(p.packet)) { LOG_DEBUG("Reliable send failed, return nak fr=0x%08x,to=0x%08x,id=0x%08x", p.packet->from, p.packet->to, @@ -511,7 +516,7 @@ void NextHopRouter::setNextTx(PendingPacket *pending) { assert(iface); auto d = iface->getRetransmissionMsec(pending->packet); - pending->nextTxMsec = millis() + d; + pending->nextTxMsec = Time::getMillis() + d; LOG_TRACE("Next retransmission in %u msecs", d); printPacket("", pending->packet); setReceivedMessage(); // Run ASAP, so we can figure out our correct sleep time diff --git a/src/mesh/NodeDB.cpp b/src/mesh/NodeDB.cpp index e31df4faa..699d2fab5 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -19,6 +19,7 @@ #include "SafeFile.h" #include "TransmitHistory.h" #include "TypeConversions.h" +#include "UptimeClock.h" #include "error.h" #include "gps/RTC.h" #include "main.h" @@ -3269,7 +3270,7 @@ uint32_t sinceLastSeen(const meshtastic_NodeInfoLite *n) uint32_t sinceReceived(const meshtastic_MeshPacket *p) { - // rx_time may be a millis() placeholder while has_rx_time is false - don't age it as + // rx_time may be an uptime-seconds placeholder while has_rx_time is false - don't age it as // wall-clock, and don't pass it off as "just now" either. if (!p->has_rx_time) return SINCE_UNKNOWN; @@ -3516,16 +3517,16 @@ void NodeDB::addFromContact(meshtastic_SharedContact contact) if (config.device.role == meshtastic_Config_DeviceConfig_Role_CLIENT_BASE) { // Special case for CLIENT_BASE: is_favorite has special meaning, and we don't want to automatically set it // without the user doing so deliberately. We don't normally expect users to use a CLIENT_BASE to send DMs or to add - // contacts, but we should make sure it doesn't auto-favorite in case they do. Instead, as a workaround, we'll set - // last_heard to now, so that the add_contact node doesn't immediately get evicted. - info->last_heard = getTime(); + // contacts, but we should make sure it doesn't auto-favorite in case they do. Instead, as a workaround, we'll + // stamp the contact as heard now, so that the add_contact node doesn't immediately get evicted. + stampContactHeardNow(info); } else { // Normal case: set is_favorite to prevent expiration. // last_heard will remain as-is (or remain 0 if this entry wasn't in the nodeDB). - // If the protected cap refuses the favorite, fall back to stamping last_heard so the + // If the protected cap refuses the favorite, fall back to a heard-now stamp so the // contact still isn't the first eviction victim. if (!setProtectedFlag(info, NODEINFO_BITFIELD_IS_FAVORITE_MASK, true)) - info->last_heard = getTime(); + stampContactHeardNow(info); } // As the clients will begin sending the contact with DMs, we want to strictly check if the node is manually verified @@ -3678,9 +3679,13 @@ void NodeDB::updateFrom(const meshtastic_MeshPacket &mp) return; } - // Gate on has_rx_time, not truthiness - rx_time may hold a millis() placeholder. + // Gate on has_rx_time, not truthiness - rx_time may hold an uptime-seconds placeholder. if (mp.has_rx_time) info->last_heard = mp.rx_time; + else + // rx_time is the arrival instant in uptime seconds. It goes to the RAM sidecar, not + // last_heard, which only ever holds a real epoch or 0. + recordHeardWhileClockUntrusted(getFrom(&mp), mp.rx_time); // Gate on the packet actually having been received over our own radio, not on rx_snr being // truthy, because 0 dB is valid. TRANSPORT_LORA is set only on the real over-the-air RX path @@ -4096,6 +4101,84 @@ meshtastic_Config_DeviceConfig_Role NodeDB::getNodeRole(NodeNum n) return meshtastic_Config_DeviceConfig_Role_CLIENT; } +void NodeDB::recordHeardWhileClockUntrusted(NodeNum num, uint32_t heardAtUptime) +{ + // Update in place if the node already has a stamp. + for (auto &h : heardAt) { + if (h.num == num) { + h.heardAtUptimeSecs = heardAtUptime; + return; + } + } + // Otherwise take an empty slot, or reuse the oldest stamp. + NodeHeardAt *victim = &heardAt[0]; + for (auto &h : heardAt) { + if (h.num == 0) { + victim = &h; + break; + } + if (h.heardAtUptimeSecs < victim->heardAtUptimeSecs) + victim = &h; + } + victim->num = num; + victim->heardAtUptimeSecs = heardAtUptime; +} + +bool NodeDB::getHeardAtUptimeSecs(NodeNum num, uint32_t &stamp) const +{ + for (const auto &h : heardAt) { + if (h.num == num) { + stamp = h.heardAtUptimeSecs; + return true; + } + } + return false; +} + +NodeDB::EvictionRecency NodeDB::evictionRecency(const meshtastic_NodeInfoLite *n) const +{ + uint32_t stamp = 0; + const bool heardThisBoot = getHeardAtUptimeSecs(n->num, stamp); + return {heardThisBoot ? stamp : n->last_heard, heardThisBoot}; +} + +bool NodeDB::evictionRecencyOlder(EvictionRecency candidate, EvictionRecency incumbent) +{ + if (candidate.heardThisBoot != incumbent.heardThisBoot) + return !candidate.heardThisBoot; + return candidate.value < incumbent.value; +} + +void NodeDB::stampContactHeardNow(meshtastic_NodeInfoLite *info) +{ + const uint32_t nowEpoch = getValidTime(RTCQualityFromNet); + if (nowEpoch) + info->last_heard = nowEpoch; + else + recordHeardWhileClockUntrusted(info->num, Time::getUptimeSecs()); +} + +void NodeDB::backfillHeardAt() +{ + const uint32_t nowEpoch = getValidTime(RTCQualityFromNet); + if (nowEpoch == 0) // called before the clock was actually valid - nothing to date against + return; + const uint32_t nowUptimeSecs = Time::getUptimeSecs(); + for (auto &h : heardAt) { + if (h.num == 0) + continue; + meshtastic_NodeInfoLite *info = getMeshNode(h.num); + if (info) { + // Both stamps are monotonic uptime seconds, so the elapsed term is exact at any age. + // Never move last_heard backwards: the node may since have been re-heard on a good clock. + const uint32_t elapsedSecs = nowUptimeSecs - h.heardAtUptimeSecs; + if (elapsedSecs < nowEpoch && nowEpoch - elapsedSecs > info->last_heard) + info->last_heard = nowEpoch - elapsedSecs; + } + h = {}; // evicted or converted either way, the stamp's job is done + } +} + /// Find a node in our DB, create an empty NodeInfo if missing meshtastic_NodeInfoLite *NodeDB::getOrCreateMeshNode(NodeNum n) { @@ -4105,8 +4188,10 @@ meshtastic_NodeInfoLite *NodeDB::getOrCreateMeshNode(NodeNum n) if (isFull()) { LOG_INFO("Node database full: %i nodes, %u bytes free. Erase oldest", numMeshNodes, memGet.getFreeHeap()); // look for oldest node and erase it - uint32_t oldest = UINT32_MAX; - uint32_t oldestBoring = UINT32_MAX; + // Newest-possible sentinel: a zeroed init ranks older than every candidate, so nothing + // would ever be selected. Keep it maximal even though the index guards below also cover it. + EvictionRecency oldest = {UINT32_MAX, true}; + EvictionRecency oldestBoring = {UINT32_MAX, true}; int oldestIndex = -1; int oldestBoringIndex = -1; for (int i = 1; i < numMeshNodes; i++) { @@ -4114,14 +4199,19 @@ meshtastic_NodeInfoLite *NodeDB::getOrCreateMeshNode(NodeNum n) const bool isFavoriteNode = nodeInfoLiteIsFavorite(cand); const bool isIgnored = nodeInfoLiteIsIgnored(cand); const bool isVerified = nodeInfoLiteIsKeyManuallyVerified(cand); + // last_heard, except that nodes heard this boot before the clock became trusted + // rank by their RAM arrival stamp instead of the 0 in the stored field. + const EvictionRecency candRecency = evictionRecency(cand); // Simply the oldest non-favorite, non-ignored, non-verified node - if (!isFavoriteNode && !isIgnored && !isVerified && cand->last_heard < oldest) { - oldest = cand->last_heard; + if (!isFavoriteNode && !isIgnored && !isVerified && + (oldestIndex == -1 || evictionRecencyOlder(candRecency, oldest))) { + oldest = candRecency; oldestIndex = i; } // The oldest "boring" node - if (!isFavoriteNode && !isIgnored && cand->public_key.size == 0 && cand->last_heard < oldestBoring) { - oldestBoring = cand->last_heard; + if (!isFavoriteNode && !isIgnored && cand->public_key.size == 0 && + (oldestBoringIndex == -1 || evictionRecencyOlder(candRecency, oldestBoring))) { + oldestBoring = candRecency; oldestBoringIndex = i; } } diff --git a/src/mesh/NodeDB.h b/src/mesh/NodeDB.h index 0d45d1e1e..e5b5a67ac 100644 --- a/src/mesh/NodeDB.h +++ b/src/mesh/NodeDB.h @@ -248,6 +248,14 @@ enum LoadFileResult { enum UserLicenseStatus { NotKnown, NotLicensed, Licensed }; +// RAM-only arrival stamp (monotonic uptime secs) for nodes heard before the wall clock was trusted, +// backfilled into last_heard as an epoch once it is. last_heard persists, so it cannot hold this. +// Bounded, linear-scan, reuse-oldest, never persisted - dies with the boot, as does its timebase. +struct NodeHeardAt { + NodeNum num = 0; ///< node this stamp describes; 0 == empty slot + uint32_t heardAtUptimeSecs = 0; ///< Time::getUptimeSecs() when last heard +}; + class NodeDB { // NodeNum provisionalNodeNum; // if we are trying to find a node num this is our current attempt @@ -308,6 +316,10 @@ class NodeDB void addFromContact(const meshtastic_SharedContact); + /// On the clock-becoming-trusted transition (see RTC.cpp): convert every RAM arrival stamp into + /// a real last_heard epoch, never backwards, then empty the table. updateFrom() takes over. + void backfillHeardAt(); + /** Update position info for this node based on received position data */ void updatePosition(uint32_t nodeId, const meshtastic_Position &p, RxSource src = RX_SRC_RADIO); @@ -638,6 +650,31 @@ class NodeDB uint32_t lastBackupAttempt = 0; // when we last tried a backup automatically or manually uint32_t lastSort = 0; // When last sorted the nodeDB + /// See NodeHeardAt. Caps how many distinct nodes can be dated once the clock arrives; a node + /// pushed out by reuse-oldest just stays "last heard: unknown", the same as before this table. + static constexpr size_t kMaxHeardAt = 32; + NodeHeardAt heardAt[kMaxHeardAt] = {}; + + /// Stamp (or re-stamp) a node's RAM arrival record; used instead of writing a non-epoch into + /// last_heard whenever the wall clock is untrusted. + void recordHeardWhileClockUntrusted(NodeNum num, uint32_t heardAtUptimeSecs); + + /// addFromContact's anti-eviction stamp: a real epoch when the clock is trusted, otherwise a + /// RAM arrival stamp that evictionRecency() honours - never a boot-relative last_heard. + void stampContactHeardNow(meshtastic_NodeInfoLite *info); + + /// Read the node's RAM arrival stamp. The boolean carries presence because uptime second 0 is valid. + bool getHeardAtUptimeSecs(NodeNum num, uint32_t &stamp) const; + + struct EvictionRecency { + uint32_t value; + bool heardThisBoot; + }; + + /// Eviction ranking with current-boot stamps newer than every persisted epoch. + EvictionRecency evictionRecency(const meshtastic_NodeInfoLite *n) const; + static bool evictionRecencyOlder(EvictionRecency candidate, EvictionRecency incumbent); + /* * Internal boolean to track sorting paused */ diff --git a/src/mesh/PhoneAPI.cpp b/src/mesh/PhoneAPI.cpp index e093d5be0..45f9b2477 100644 --- a/src/mesh/PhoneAPI.cpp +++ b/src/mesh/PhoneAPI.cpp @@ -972,6 +972,14 @@ size_t PhoneAPI::getFromRadio(uint8_t *buf) } if (infoToSend.num != 0) { + // A record prefetched before the clock became trusted carries last_heard == 0 even + // once the store is backfilled, so re-read it at send time: handshake ordering + // (time-set vs node-list download) must not decide what the phone sees. + if (infoToSend.last_heard == 0 && infoToSend.num != nodeDB->getNodeNum()) { + const meshtastic_NodeInfoLite *fresh = nodeDB->getMeshNode(infoToSend.num); + if (fresh) + infoToSend.last_heard = fresh->last_heard; + } // Just in case we stored a different user.id in the past, but should never happen going forward sprintf(infoToSend.user.id, "!%08x", infoToSend.num); diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index 3a938e03c..2aa6a6c63 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -318,7 +318,7 @@ PacketId generatePacketId() RxTimeStamp computeRxTimeStamp() { const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - return {haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(), haveTime}; + return {haveTime ? getValidTime(RTCQualityFromNet) : Time::getUptimeSecs(), haveTime}; } void stampRxTime(meshtastic_MeshPacket *p) diff --git a/src/mesh/Router.h b/src/mesh/Router.h index 003aebc57..d5ea73cfe 100644 --- a/src/mesh/Router.h +++ b/src/mesh/Router.h @@ -21,7 +21,8 @@ bool isBlockedEventCoordinatePacket(const meshtastic_MeshPacket *p); bool willUsePki(const meshtastic_MeshPacket *p); /// rx_time/has_rx_time for "now": a real epoch when the clock is trustworthy, else a -/// Time::getMillis() placeholder with valid=false. +/// Time::getUptimeSecs() placeholder with valid=false. Uptime seconds are monotonic, so +/// reconciliation against a later epoch is exact at any age. struct RxTimeStamp { uint32_t time; bool valid; diff --git a/src/mesh/Throttle.cpp b/src/mesh/Throttle.cpp index a4f8347b2..606ba737e 100644 --- a/src/mesh/Throttle.cpp +++ b/src/mesh/Throttle.cpp @@ -1,4 +1,5 @@ #include "Throttle.h" +#include "UptimeClock.h" #include /// @brief Execute a function throttled to a minimum interval @@ -10,11 +11,11 @@ bool Throttle::execute(uint32_t *lastExecutionMs, uint32_t minumumIntervalMs, void (*throttleFunc)(void), void (*onDefer)(void)) { if (*lastExecutionMs == 0) { - *lastExecutionMs = millis(); + *lastExecutionMs = Time::getMillis(); throttleFunc(); return true; } - uint32_t now = millis(); + uint32_t now = Time::getMillis(); if ((now - *lastExecutionMs) >= minumumIntervalMs) { throttleFunc(); @@ -31,6 +32,14 @@ bool Throttle::execute(uint32_t *lastExecutionMs, uint32_t minumumIntervalMs, vo /// @param timeSpanMs The interval in milliseconds of the timespan bool Throttle::isWithinTimespanMs(uint32_t lastExecutionMs, uint32_t timeSpanMs) { - uint32_t now = millis(); + uint32_t now = Time::getMillis(); return (now - lastExecutionMs) < timeSpanMs; +} + +/// @brief Check whether an absolute deadline has arrived, correctly across the millis() wrap +/// @param deadlineMs The deadline, as a millis() value +/// See the header for the range limit and the sentinel requirement. +bool Throttle::deadlinePassed(uint32_t deadlineMs) +{ + return deadlinePassedAt(Time::getMillis(), deadlineMs); } \ No newline at end of file diff --git a/src/mesh/Throttle.h b/src/mesh/Throttle.h index 8b4bb5d30..f9d68a414 100644 --- a/src/mesh/Throttle.h +++ b/src/mesh/Throttle.h @@ -7,4 +7,48 @@ class Throttle public: static bool execute(uint32_t *lastExecutionMs, uint32_t minumumIntervalMs, void (*func)(void), void (*onDefer)(void) = NULL); static bool isWithinTimespanMs(uint32_t lastExecutionMs, uint32_t intervalMs); + + /// Complement of isWithinTimespanMs(): true once intervalMs has passed since lastExecutionMs. + /// Boundary is inclusive (>=), mirroring isWithinTimespanMs()'s exclusive <. + /// Deliberately does not treat lastExecutionMs == 0 as "never run" - callers that use 0 as a + /// sentinel must test for it separately, so the sentinel never reaches the arithmetic. + static bool hasElapsed(uint32_t lastExecutionMs, uint32_t intervalMs) + { + return !isWithinTimespanMs(lastExecutionMs, intervalMs); + } + + /// True once an absolute deadline has arrived. Use this rather than comparing against millis() + /// directly: that inverts while the deadline sits on the far side of the 32-bit wrap, so the + /// action either fires immediately or blocks for about the interval it should have waited. + /// + /// Use this when the site stores a deadline; use hasElapsed() when it stores the time of the + /// last event, which allows the full ~49.7 day range instead of ~24.8 days ahead. + /// + /// Callers that overload the deadline with an "inactive" sentinel (0, or UINT32_MAX) MUST test + /// for that separately, first: every such value is arithmetically far in the past, so it reads + /// as passed. + /// + /// TODO(deadline-type): mistake-proof that MUST by giving a deadline its own one-field type - + /// Deadline::in(ms) / .armed() / .passed() / .disarm(). A hand-built `now + interval` could then + /// no longer land on the sentinel by accident, and "armed" would stay a question separate from + /// "passed" - the split that has to survive, because which way "inactive" falls is the caller's + /// to decide. Same size and cost as the bare uint32_t. The conversion sites, grouped by the four + /// meanings they give the sentinel today: + /// 0 = unarmed - Power.cpp rebootAtMsec/shutdownAtMsec (the cheapest pair to convert), and + /// GPS.cpp fixHoldEnds, whose arm site remaps a 0 result to 1 by hand. + /// 0 = forever - NotificationRenderer.cpp alertBannerUntil. Every read spells its own `> 0` + /// guard, so this third state wants naming rather than repeating. + /// 0 = due now - ethClient.cpp ntp_renew, forced at link-up. + /// UINT32_MAX - ExternalNotificationModule.cpp nagCycleCutoff, whose armed() also lives in a + /// second variable (isNagging) and whose arm site can land on the sentinel. + static bool deadlinePassed(uint32_t deadlineMs); + + /// deadlinePassed() against a caller-supplied "now", for a loop that snapshots the time once and + /// tests many deadlines against it. Same range limit and sentinel rules as above. + static bool deadlinePassedAt(uint32_t nowMs, uint32_t deadlineMs) + { + // Passed iff now - deadline has not wrapped past 2^31 ms; further-ahead deadlines land in + // the top half. Not an int32_t cast, which is implementation-defined beyond INT32_MAX. + return (uint32_t)(nowMs - deadlineMs) < 0x80000000u; + } }; \ No newline at end of file diff --git a/src/mesh/eth/ethClient.cpp b/src/mesh/eth/ethClient.cpp index bf6be0b9c..bf85eef92 100644 --- a/src/mesh/eth/ethClient.cpp +++ b/src/mesh/eth/ethClient.cpp @@ -4,6 +4,7 @@ #include "configuration.h" #include "gps/RTC.h" #include "main.h" +#include "mesh/Throttle.h" #include "mesh/api/ethServerAPI.h" #include "target_specific.h" #if HAS_ETHERNET && defined(HAS_ETHERNET_OTA) @@ -196,7 +197,9 @@ static int32_t reconnectETH() } #ifndef DISABLE_NTP - if (isEthernetAvailable() && (ntp_renew < millis())) { + // 0 here means "renew now" (forced at link-up). deadlinePassed(0) only reads as passed for the + // first half of each wrap cycle, so treat 0 as always-due rather than relying on that. + if (isEthernetAvailable() && (ntp_renew == 0 || Throttle::deadlinePassed(ntp_renew))) { LOG_INFO("Update NTP time from %s", config.network.ntp_server); if (timeClient.update()) { diff --git a/src/modules/DropzoneModule.cpp b/src/modules/DropzoneModule.cpp index 16bd83849..100b87662 100644 --- a/src/modules/DropzoneModule.cpp +++ b/src/modules/DropzoneModule.cpp @@ -12,6 +12,7 @@ #include "modules/Telemetry/Sensor/DFRobotLarkSensor.h" #include "modules/Telemetry/UnitConversions.h" +#include "mesh/Throttle.h" #include DropzoneModule *dropzoneModule; @@ -19,7 +20,7 @@ DropzoneModule *dropzoneModule; int32_t DropzoneModule::runOnce() { // Send on a 5 second delay from receiving the matching request - if (startSendConditions != 0 && (startSendConditions + 5000U) < millis()) { + if (startSendConditions != 0 && Throttle::hasElapsed(startSendConditions, 5000U)) { service->sendToMesh(sendConditions(), RX_SRC_LOCAL); startSendConditions = 0; } diff --git a/src/modules/ExternalNotificationModule.cpp b/src/modules/ExternalNotificationModule.cpp index 091a95d41..420697689 100644 --- a/src/modules/ExternalNotificationModule.cpp +++ b/src/modules/ExternalNotificationModule.cpp @@ -21,6 +21,7 @@ #include "configuration.h" #include "gps/RTC.h" #include "main.h" +#include "mesh/Throttle.h" #include "mesh/generated/meshtastic/rtttl.pb.h" #include @@ -85,7 +86,10 @@ int32_t ExternalNotificationModule::runOnce() #if defined(HAS_I2S_SPEAKER_NRF52) isRtttlPlaying = isRtttlPlaying || nrf52RtttlPlayer.isPlaying(); #endif - if ((nagCycleCutoff < millis()) && !isRtttlPlaying) { + // isNagging is the armed flag; nagCycleCutoff holds a real deadline only while it is set + // (UINT32_MAX once stopped, 1 at boot), so short-circuit before the comparison. + const bool nagWindowExpired = !isNagging || Throttle::deadlinePassed(nagCycleCutoff); + if (nagWindowExpired && !isRtttlPlaying) { // Turn off external notification immediately when timeout is reached, regardless of song state nagCycleCutoff = UINT32_MAX; ExternalNotificationModule::stopNow(); @@ -97,14 +101,15 @@ int32_t ExternalNotificationModule::runOnce() if (isNagging) { delay = (moduleConfig.external_notification.output_ms ? moduleConfig.external_notification.output_ms : EXT_NOTIFICATION_MODULE_OUTPUT_MS); - if (externalTurnedOn[0] + delay < millis()) { + // externalTurnedOn[] is when each output was last toggled, so these are intervals. + if (Throttle::hasElapsed(externalTurnedOn[0], delay)) { setExternalState(0, !getExternal(0)); } - if (externalTurnedOn[1] + delay < millis()) { + if (Throttle::hasElapsed(externalTurnedOn[1], delay)) { setExternalState(1, !getExternal(1)); } // Only toggle buzzer output if not using PWM mode (to avoid conflict with RTTTL) - if (!moduleConfig.external_notification.use_pwm && externalTurnedOn[2] + delay < millis()) { + if (!moduleConfig.external_notification.use_pwm && Throttle::hasElapsed(externalTurnedOn[2], delay)) { LOG_DEBUG("EXTERNAL 2 %d compared to %d", externalTurnedOn[2] + moduleConfig.external_notification.output_ms, millis()); setExternalState(2, !getExternal(2)); @@ -146,7 +151,7 @@ int32_t ExternalNotificationModule::runOnce() if (moduleConfig.external_notification.use_i2s_as_buzzer) { if (audioThread->isPlaying()) { // Continue playing - } else if (isNagging && (nagCycleCutoff >= millis())) { + } else if (isNagging && !Throttle::deadlinePassed(nagCycleCutoff)) { audioThread->beginRttl(rtttlConfig.ringtone, strlen_P(rtttlConfig.ringtone)); } // we need fast updates to play the RTTTL @@ -158,7 +163,7 @@ int32_t ExternalNotificationModule::runOnce() if (canBuzz() && buzzerShouldAlert) { if (nrf52RtttlPlayer.isPlaying()) { nrf52RtttlPlayer.play(); - } else if (isNagging && (nagCycleCutoff >= millis())) { + } else if (isNagging && !Throttle::deadlinePassed(nagCycleCutoff)) { nrf52RtttlPlayer.begin(rtttlConfig.ringtone); } delay = EXT_NOTIFICATION_FAST_THREAD_MS; @@ -168,7 +173,7 @@ int32_t ExternalNotificationModule::runOnce() if (moduleConfig.external_notification.use_pwm && config.device.buzzer_gpio && canBuzz() && buzzerShouldAlert) { if (rtttl::isPlaying()) { rtttl::play(); - } else if (isNagging && (nagCycleCutoff >= millis())) { + } else if (isNagging && !Throttle::deadlinePassed(nagCycleCutoff)) { // start the song again if we have time left rtttl::begin(config.device.buzzer_gpio, rtttlConfig.ringtone); } diff --git a/src/modules/NodeInfoModule.cpp b/src/modules/NodeInfoModule.cpp index f738d2aed..7c4096959 100644 --- a/src/modules/NodeInfoModule.cpp +++ b/src/modules/NodeInfoModule.cpp @@ -34,17 +34,14 @@ bool NodeInfoModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, mes // Suppress replies to senders we've replied to recently (12H window) if (mp.decoded.want_response && !isFromUs(&mp)) { const NodeNum sender = getFrom(&mp); - // A local dedup window, not a wall-clock reading - uptime avoids RTC-quality jumps and - // replayed packets' stale rx_time perturbing it. - const uint32_t now = (uint32_t)(Time::getMillis64() / 1000); + // A local dedup window, not a wall-clock reading - uptime avoids RTC jumps and replayed + // packets' stale rx_time perturbing it. Seconds, not millis - this is a wide window. + const uint32_t nowSecs = Time::getUptimeSecs(); auto it = lastNodeInfoSeen.find(sender); - if (it != lastNodeInfoSeen.end()) { - uint32_t sinceLast = now >= it->second ? now - it->second : 0; - if (sinceLast < NodeInfoReplySuppressSeconds) { - suppressReplyForCurrentRequest = true; - } + if (it != lastNodeInfoSeen.end() && (uint32_t)(nowSecs - it->second) < NodeInfoReplySuppressSeconds) { + suppressReplyForCurrentRequest = true; } - lastNodeInfoSeen[sender] = now; + lastNodeInfoSeen[sender] = nowSecs; pruneLastNodeInfoCache(); } @@ -193,19 +190,26 @@ void NodeInfoModule::pruneLastNodeInfoCache() return; const size_t maxEntries = nodeDB->meshNodes->size(); + const uint32_t nowSecs = Time::getUptimeSecs(); + // Drop entries for nodes we no longer know, and any stamp already past the suppression window: + // it can only decide "don't suppress", so keeping it buys nothing. for (auto it = lastNodeInfoSeen.begin(); it != lastNodeInfoSeen.end();) { - if (!nodeDB->getMeshNode(it->first)) { + if (!nodeDB->getMeshNode(it->first) || (uint32_t)(nowSecs - it->second) >= NodeInfoReplySuppressSeconds) { it = lastNodeInfoSeen.erase(it); } else { ++it; } } + // Evict by largest elapsed time rather than smallest stamp, so the victim is still the oldest + // entry if the uptime counter ever wraps underneath us. while (!lastNodeInfoSeen.empty() && lastNodeInfoSeen.size() > maxEntries) { - auto oldestIt = std::min_element(lastNodeInfoSeen.begin(), lastNodeInfoSeen.end(), - [](const std::pair &lhs, - const std::pair &rhs) { return lhs.second < rhs.second; }); + auto oldestIt = std::max_element( + lastNodeInfoSeen.begin(), lastNodeInfoSeen.end(), + [nowSecs](const std::pair &lhs, const std::pair &rhs) { + return (uint32_t)(nowSecs - lhs.second) < (uint32_t)(nowSecs - rhs.second); + }); lastNodeInfoSeen.erase(oldestIt); } } diff --git a/src/modules/NodeInfoModule.h b/src/modules/NodeInfoModule.h index 9b3b66cae..8653c71eb 100644 --- a/src/modules/NodeInfoModule.h +++ b/src/modules/NodeInfoModule.h @@ -50,6 +50,8 @@ class NodeInfoModule : public ProtobufModule, private concurren private: bool shorterTimeout = false; bool suppressReplyForCurrentRequest = false; + /// Sender -> uptime seconds (Time::getUptimeSecs()) at our last reply. Seconds, not millis: + /// the suppression window is hours wide. See handleReceivedProtobuf(). std::map lastNodeInfoSeen; void pruneLastNodeInfoCache(); diff --git a/src/modules/StatusLEDModule.cpp b/src/modules/StatusLEDModule.cpp index 5c6f84942..3a09fb862 100644 --- a/src/modules/StatusLEDModule.cpp +++ b/src/modules/StatusLEDModule.cpp @@ -2,6 +2,7 @@ #include "MeshService.h" #include "configuration.h" #include "mesh/RadioInterface.h" +#include "mesh/Throttle.h" #include /* @@ -118,7 +119,7 @@ int32_t StatusLEDModule::runOnce() } else if (power_state == charged) { CHARGE_LED_state = LED_STATE_ON; } else if (power_state == critical) { - if (POWER_LED_starttime + 30000 < millis() && !doing_fast_blink) { + if (Throttle::hasElapsed(POWER_LED_starttime, 30000) && !doing_fast_blink) { doing_fast_blink = true; POWER_LED_starttime = millis(); } @@ -126,7 +127,7 @@ int32_t StatusLEDModule::runOnce() PAIRING_LED_state = LED_STATE_OFF; CHARGE_LED_state = !CHARGE_LED_state; my_interval = 250; - if (POWER_LED_starttime + 2000 < millis()) { + if (Throttle::hasElapsed(POWER_LED_starttime, 2000)) { doing_fast_blink = false; CHARGE_LED_state = LED_STATE_OFF; } @@ -165,7 +166,7 @@ int32_t StatusLEDModule::runOnce() } #endif #ifdef LED_PAIRING - if (!config.bluetooth.enabled || PAIRING_LED_starttime + 30 * 1000 < millis() || doing_fast_blink) { + if (!config.bluetooth.enabled || Throttle::hasElapsed(PAIRING_LED_starttime, 30 * 1000) || doing_fast_blink) { PAIRING_LED_state = LED_STATE_OFF; } else if (ble_state == unpaired) { if (slowTrack) { @@ -190,7 +191,7 @@ int32_t StatusLEDModule::runOnce() bool chargeIndicatorLED2 = LED_STATE_OFF; bool chargeIndicatorLED3 = LED_STATE_OFF; bool chargeIndicatorLED4 = LED_STATE_OFF; - if (lastUserbuttonTime + 10 * 1000 > millis() || CHARGE_LED_state == LED_STATE_ON) { + if (Throttle::isWithinTimespanMs(lastUserbuttonTime, 10 * 1000) || CHARGE_LED_state == LED_STATE_ON) { // should this be off at very low percentages? chargeIndicatorLED1 = LED_STATE_ON; if (powerStatus && powerStatus->getBatteryChargePercent() >= 25) diff --git a/src/modules/Telemetry/DeviceTelemetry.cpp b/src/modules/Telemetry/DeviceTelemetry.cpp index 9772463d7..e3ef3f095 100644 --- a/src/modules/Telemetry/DeviceTelemetry.cpp +++ b/src/modules/Telemetry/DeviceTelemetry.cpp @@ -6,7 +6,9 @@ #include "PowerFSM.h" #include "RadioLibInterface.h" #include "Router.h" +#include "Throttle.h" #include "TransmitHistory.h" +#include "UptimeClock.h" #include "configuration.h" #include "gps/RTC.h" #include "main.h" @@ -21,13 +23,12 @@ static constexpr uint16_t TX_HISTORY_KEY_DEVICE_TELEMETRY = 0x8001; int32_t DeviceTelemetryModule::runOnce() { - refreshUptime(); uint32_t lastTelemetry = transmitHistory ? transmitHistory->getLastSentToMeshMillis(TX_HISTORY_KEY_DEVICE_TELEMETRY) : 0; bool isImpoliteRole = isSensorOrRouterRole(); - if (((lastTelemetry == 0) || - ((uptimeLastMs - lastTelemetry) >= Default::getConfiguredOrDefaultMsScaled(moduleConfig.telemetry.device_update_interval, - default_telemetry_broadcast_interval_secs, - numOnlineNodes, TrafficType::TELEMETRY))) && + if (((lastTelemetry == 0) || Throttle::hasElapsed(lastTelemetry, Default::getConfiguredOrDefaultMsScaled( + moduleConfig.telemetry.device_update_interval, + default_telemetry_broadcast_interval_secs, + numOnlineNodes, TrafficType::TELEMETRY))) && airTime->isTxAllowedChannelUtil(!isImpoliteRole) && airTime->isTxAllowedAirUtil() && config.device.role != meshtastic_Config_DeviceConfig_Role_CLIENT_HIDDEN && moduleConfig.telemetry.device_telemetry_enabled) { @@ -38,9 +39,9 @@ int32_t DeviceTelemetryModule::runOnce() // Just send to phone when it's not our time to send to mesh yet // Only send while queue is empty (phone assumed connected) sendTelemetry(NODENUM_BROADCAST, true); - if (lastSentStatsToPhone == 0 || (uptimeLastMs - lastSentStatsToPhone) >= sendStatsToPhoneIntervalMs) { + if (lastSentStatsToPhone == 0 || Throttle::hasElapsed(lastSentStatsToPhone, sendStatsToPhoneIntervalMs)) { sendLocalStatsToPhone(); - lastSentStatsToPhone = uptimeLastMs; + lastSentStatsToPhone = Time::getMillis(); } } return sendToPhoneIntervalMs; @@ -114,7 +115,7 @@ meshtastic_Telemetry DeviceTelemetryModule::getDeviceTelemetry() t.variant.device_metrics.has_voltage = true; t.variant.device_metrics.voltage = batteryMv / 1000.0f; } - t.variant.device_metrics.uptime_seconds = getUptimeSeconds(); + t.variant.device_metrics.uptime_seconds = Time::getUptimeSecs(); return t; } @@ -124,7 +125,7 @@ meshtastic_Telemetry DeviceTelemetryModule::getLocalStatsTelemetry() telemetry.which_variant = meshtastic_Telemetry_local_stats_tag; telemetry.variant.local_stats = meshtastic_LocalStats_init_zero; telemetry.time = getTime(); - telemetry.variant.local_stats.uptime_seconds = getUptimeSeconds(); + telemetry.variant.local_stats.uptime_seconds = Time::getUptimeSecs(); telemetry.variant.local_stats.channel_utilization = airTime->channelUtilizationPercent(); telemetry.variant.local_stats.air_util_tx = airTime->utilizationTXPercent(); telemetry.variant.local_stats.num_online_nodes = numOnlineNodes; diff --git a/src/modules/Telemetry/DeviceTelemetry.h b/src/modules/Telemetry/DeviceTelemetry.h index f37afee70..c2d2762f3 100644 --- a/src/modules/Telemetry/DeviceTelemetry.h +++ b/src/modules/Telemetry/DeviceTelemetry.h @@ -18,8 +18,6 @@ class DeviceTelemetryModule : private concurrency::OSThread, : concurrency::OSThread("DeviceTelemetry"), ProtobufModule("DeviceTelemetry", meshtastic_PortNum_TELEMETRY_APP, &meshtastic_Telemetry_msg) { - uptimeWrapCount = 0; - uptimeLastMs = millis(); nodeStatusObserver.observe(&nodeStatus->onNewStatus); setIntervalFromNow(setStartDelay()); // Wait until NodeInfo is sent } @@ -37,12 +35,6 @@ class DeviceTelemetryModule : private concurrency::OSThread, */ bool sendTelemetry(NodeNum dest = NODENUM_BROADCAST, bool phoneOnly = false); - /** - * Get the uptime in seconds - * Loses some accuracy after 49 days, but that's fine - */ - uint32_t getUptimeSeconds() { return (0xFFFFFFFF / 1000) * uptimeWrapCount + (uptimeLastMs / 1000); } - private: meshtastic_Telemetry getDeviceTelemetry(); meshtastic_Telemetry getLocalStatsTelemetry(); @@ -51,17 +43,4 @@ class DeviceTelemetryModule : private concurrency::OSThread, uint32_t sendToPhoneIntervalMs = SECONDS_IN_MINUTE * 1000; // Send to phone every minute uint32_t sendStatsToPhoneIntervalMs = 15 * SECONDS_IN_MINUTE * 1000; // Send stats to phone every 15 minutes uint32_t lastSentStatsToPhone = 0; - - void refreshUptime() - { - auto now = millis(); - // If we wrapped around (~49 days), increment the wrap count - if (now < uptimeLastMs) - uptimeWrapCount++; - - uptimeLastMs = now; - } - - uint32_t uptimeWrapCount; - uint32_t uptimeLastMs; }; \ No newline at end of file diff --git a/src/modules/Telemetry/HostMetrics.h b/src/modules/Telemetry/HostMetrics.h index 99ee631c1..a352a5afa 100644 --- a/src/modules/Telemetry/HostMetrics.h +++ b/src/modules/Telemetry/HostMetrics.h @@ -12,8 +12,6 @@ class HostMetricsModule : private concurrency::OSThread, public ProtobufModuleonNewStatus); setIntervalFromNow(setStartDelay()); // Wait until NodeInfo is sent } @@ -35,6 +33,4 @@ class HostMetricsModule : private concurrency::OSThread, public ProtobufModule) #include @@ -163,7 +165,8 @@ void BME680Sensor::updateState() } } else { /* Update every STATE_SAVE_PERIOD minutes */ - if ((stateUpdateCounter * STATE_SAVE_PERIOD) < millis()) { + // Interval since the last save; counter * period overflows uint32 past ~198 saves. + if (Throttle::hasElapsed(lastStateSaveMs, STATE_SAVE_PERIOD)) { LOG_DEBUG("%s state update every %d minutes", sensorName, STATE_SAVE_PERIOD / 60000); update = true; stateUpdateCounter++; @@ -181,6 +184,8 @@ void BME680Sensor::updateState() file.write((uint8_t *)&bsecState, BSEC_MAX_STATE_BLOB_SIZE); file.flush(); file.close(); + // Checkpoint on success only, so a failed write is retried at the next interval. + lastStateSaveMs = Time::getMillis(); } else { LOG_INFO("Can't write %s state (File: %s)", sensorName, bsecConfigFileName); } diff --git a/src/modules/Telemetry/Sensor/BME680Sensor.h b/src/modules/Telemetry/Sensor/BME680Sensor.h index 1134f04d9..b8c0bd810 100644 --- a/src/modules/Telemetry/Sensor/BME680Sensor.h +++ b/src/modules/Telemetry/Sensor/BME680Sensor.h @@ -39,6 +39,7 @@ class BME680Sensor : public TelemetrySensor uint8_t bsecState[BSEC_MAX_STATE_BLOB_SIZE] = {0}; uint8_t accuracy = 0; uint16_t stateUpdateCounter = 0; + uint32_t lastStateSaveMs = 0; // when the state blob was last written, for the save interval bsecSensor sensorList[9] = {BSEC_OUTPUT_IAQ, BSEC_OUTPUT_RAW_TEMPERATURE, BSEC_OUTPUT_RAW_PRESSURE, diff --git a/src/motion/MotionSensor.cpp b/src/motion/MotionSensor.cpp index b1744ad92..6cbe8e21d 100755 --- a/src/motion/MotionSensor.cpp +++ b/src/motion/MotionSensor.cpp @@ -259,8 +259,11 @@ void MotionSensor::drawFrameCalibration(OLEDDisplay *display, OLEDDisplayUiState const uint32_t now = millis(); const uint32_t endCalibrationAt = screen->getEndCalibration(); uint32_t timeRemaining = 0; - if (endCalibrationAt > now) { - timeRemaining = (endCalibrationAt - now + 999) / 1000; + // Signed delta, as in finishCalibrationIfExpired(): this needs the remaining magnitude, not + // just whether the deadline passed, so it cannot use Throttle::deadlinePassed(). + const int32_t remainingMs = (int32_t)(endCalibrationAt - now); + if (remainingMs > 0) { + timeRemaining = ((uint32_t)remainingMs + 999) / 1000; } int16_t compassX = 0, compassY = 0; diff --git a/src/platform/extra_variants/t5s3_epaper/variant.cpp b/src/platform/extra_variants/t5s3_epaper/variant.cpp index 2ef2d2e23..a83b04b0f 100644 --- a/src/platform/extra_variants/t5s3_epaper/variant.cpp +++ b/src/platform/extra_variants/t5s3_epaper/variant.cpp @@ -10,6 +10,7 @@ #include "input/InputBroker.h" #include "input/TouchScreenImpl1.h" #include "main.h" +#include "mesh/Throttle.h" #include "sleep.h" #include @@ -100,7 +101,10 @@ volatile bool touchControllerReady = false; volatile bool touchLightSleepActive = false; volatile bool touchNeedsWake = false; volatile bool touchIndicatorRefreshPending = false; -volatile uint32_t touchResumeBlockUntilMs = 0; +// When the light-sleep resume happened, not when the block expires: an interval bounds a missed +// 0-check by the settle time, where a stored deadline would block for up to half a wrap cycle. +constexpr uint32_t TOUCH_RESUME_BLOCK_MS = 150; +volatile uint32_t touchResumeAtMs = 0; volatile uint32_t touchStateEpoch = 1; volatile bool homeCapButtonEventsEnabled = false; #if HAS_SCREEN @@ -184,7 +188,8 @@ class SideKeyInterruptThread : public concurrency::OSThread { const uint32_t now = millis(); - if (now < touchResumeBlockUntilMs) { + // 0 means the device has never light-slept, so no block is armed - test it first. + if (touchResumeAtMs != 0 && Throttle::isWithinTimespanMs(touchResumeAtMs, TOUCH_RESUME_BLOCK_MS)) { resetStateAndStop(); return OSThread::disable(); } @@ -279,8 +284,8 @@ class SideKeyInterruptThread : public concurrency::OSThread if (touchLightSleepActive) { return; } - const uint32_t now = millis(); - if (now < touchResumeBlockUntilMs) { + // See the runOnce() guard above for why 0 must be tested separately. + if (touchResumeAtMs != 0 && Throttle::isWithinTimespanMs(touchResumeAtMs, TOUCH_RESUME_BLOCK_MS)) { return; } if (state != State::REST) { @@ -550,7 +555,7 @@ struct TouchLightSleepEndObserver { } touchStateEpoch++; - touchResumeBlockUntilMs = millis() + 150; + touchResumeAtMs = millis(); touchIndicatorRefreshPending = !isTouchInputEnabled(); #ifdef MESHTASTIC_INCLUDE_NICHE_GRAPHICS // Clear sleep-time touch overlay after wake. @@ -569,17 +574,18 @@ struct TouchLightSleepEndObserver { bool readTouch(int16_t *x, int16_t *y) { #ifdef MESHTASTIC_INCLUDE_NICHE_GRAPHICS - static uint32_t suppressUntilMs = 0; + constexpr uint32_t TOUCH_WAKE_SUPPRESS_MS = 60; + static uint32_t suppressFromMs = 0; // 0 = not suppressing, same reading as touchResumeAtMs static uint32_t seenTouchStateEpoch = 0; // Reset transient gesture helpers whenever touch mode changes. if (seenTouchStateEpoch != touchStateEpoch) { seenTouchStateEpoch = touchStateEpoch; - suppressUntilMs = 0; + suppressFromMs = 0; } - // Let buses and peripherals settle briefly after light-sleep wake. - if (millis() < touchResumeBlockUntilMs) { + // Let buses and peripherals settle briefly after light-sleep wake. 0 means no wake yet. + if (touchResumeAtMs != 0 && Throttle::isWithinTimespanMs(touchResumeAtMs, TOUCH_RESUME_BLOCK_MS)) { return false; } @@ -596,12 +602,12 @@ bool readTouch(int16_t *x, int16_t *y) LOG_DEBUG("touchscreen1: wakeup() on deferred resume"); touch.wakeup(); touchNeedsWake = false; - suppressUntilMs = millis() + 60; + suppressFromMs = millis(); return false; } // After a recovery pulse, emit a brief "released" window so gesture state can reset. - if (suppressUntilMs != 0 && millis() < suppressUntilMs) { + if (suppressFromMs != 0 && Throttle::isWithinTimespanMs(suppressFromMs, TOUCH_WAKE_SUPPRESS_MS)) { return false; } #endif diff --git a/src/platform/nrf52/NRF52Bluetooth.cpp b/src/platform/nrf52/NRF52Bluetooth.cpp index 8c17435cc..85a29e05a 100644 --- a/src/platform/nrf52/NRF52Bluetooth.cpp +++ b/src/platform/nrf52/NRF52Bluetooth.cpp @@ -446,7 +446,7 @@ bool NRF52Bluetooth::onPairingPasskey(uint16_t conn_handle, uint8_t const passke if (match_request) { uint32_t start_time = millis(); - while (millis() < start_time + 30000) { + while (Throttle::isWithinTimespanMs(start_time, 30000)) { if (!Bluefruit.connected(conn_handle)) break; } diff --git a/src/platform/nrf52/main-nrf52.cpp b/src/platform/nrf52/main-nrf52.cpp index 14138767e..eb2084403 100644 --- a/src/platform/nrf52/main-nrf52.cpp +++ b/src/platform/nrf52/main-nrf52.cpp @@ -1,4 +1,5 @@ #include "configuration.h" +#include "mesh/Throttle.h" #include #include #include @@ -270,12 +271,17 @@ namespace { constexpr uint8_t NRF52_MAGIC_LFS_IS_CORRUPT = 0xF5; constexpr uint32_t MULTIPLE_CORRUPTION_DELAY_MILLIS = 20 * 60 * 1000; -static unsigned long millis_until_formatting_again = 0; +// When the last format happened, not when the next one is due: measuring forward from the event +// bounds the pause below by the constant, where a stored deadline could hand delay() any value. +// Armed separately because preFSBegin() runs in the first millisecond of boot, so a zero timestamp +// is a legitimate value here, not an "unset" marker. +static uint32_t last_format_ms = 0; +static bool formatted_this_boot = false; // Report the critical error from loop(), giving a chance for the screen to be initialized first. inline void reportLittleFSCorruptionOnce() { - static bool report_corruption = !!millis_until_formatting_again; + static bool report_corruption = formatted_this_boot; if (report_corruption) { report_corruption = false; RECORD_CRITICALERROR(meshtastic_CriticalErrorCode_FLASH_CORRUPTION_UNRECOVERABLE); @@ -290,7 +296,8 @@ void preFSBegin() if (!(NRF_POWER->RESETREAS == 0 && NRF_POWER->GPREGRET == NRF52_MAGIC_LFS_IS_CORRUPT)) return; NRF_POWER->GPREGRET = 0; - millis_until_formatting_again = millis() + MULTIPLE_CORRUPTION_DELAY_MILLIS; + last_format_ms = millis(); + formatted_this_boot = true; InternalFS.format(); LOG_INFO("LittleFS format complete; restoring default settings"); } @@ -298,9 +305,11 @@ void preFSBegin() extern "C" void lfs_assert(const char *reason) { LOG_ERROR("LittleFS corruption detected: %s", reason); - if (millis_until_formatting_again > millis()) { + // Test the armed flag first, since elapsed-since-0 is inside the backoff for the first 20 + // minutes after each wrap. + if (formatted_this_boot && Throttle::isWithinTimespanMs(last_format_ms, MULTIPLE_CORRUPTION_DELAY_MILLIS)) { RECORD_CRITICALERROR(meshtastic_CriticalErrorCode_FLASH_CORRUPTION_UNRECOVERABLE); - const long millis_remain = millis_until_formatting_again - millis(); + const long millis_remain = MULTIPLE_CORRUPTION_DELAY_MILLIS - (millis() - last_format_ms); LOG_WARN("Pausing %d seconds to avoid wear on flash storage", millis_remain / 1000); delay(millis_remain); } diff --git a/test/test_airtime/test_main.cpp b/test/test_airtime/test_main.cpp new file mode 100644 index 000000000..97adeac0c --- /dev/null +++ b/test/test_airtime/test_main.cpp @@ -0,0 +1,196 @@ +// Unit tests for src/airtime.{h,cpp} - AirTime::syncNow() and its rolling windows. +// +// syncNow() replaced a per-second runOnce() tick with monotonic-uptime bucket rotation so windows +// stay correct across light sleep. It now takes its seconds from Time::getUptimeSecs(), which is a +// pure read of a carry the main loop publishes via Time::serviceMonotonic(); these tests exercise +// the rotation/decay math on top of that, including across the 32-bit millis() wrap. The wrap cases +// therefore step the clock the way the main loop does - advance, then publish. +#include "Arduino.h" +#include "TestUtil.h" +#include "UptimeClock.h" +#include "airtime.h" +#include +#include + +void setUp(void) +{ + // Absolute uptime assertions (e.g. getSecondsSinceBoot()) must not inherit wraps counted by + // an earlier case that moved the test clock backwards via setTestMillis(). + Time::resetMonotonicForTests(); +} +void tearDown(void) +{ + Time::useRealClock(); // don't leak the fake clock into other suites +} + +// --- first sync / immediate writes --- + +void test_logAirtime_writes_into_current_bucket_immediately() +{ + Time::setTestMillis(0); + AirTime a; + + a.logAirtime(TX_LOG, 100); + + TEST_ASSERT_EQUAL_UINT32(100, a.airtimeReport(TX_LOG)[0]); +} + +void test_getSecondsSinceBoot_tracks_elapsed_time() +{ + Time::setTestMillis(0); + AirTime a; + + TEST_ASSERT_EQUAL_UINT32(0, a.getSecondsSinceBoot()); + Time::advanceTestMillis(5000); + TEST_ASSERT_EQUAL_UINT32(5, a.getSecondsSinceBoot()); +} + +// --- hourly period rotation --- + +void test_period_rotates_after_one_hour() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(TX_LOG, 500); + + Time::advanceTestMillis(3600u * 1000u); // exactly one SECONDS_PER_PERIOD + + uint32_t *report = a.airtimeReport(TX_LOG); + TEST_ASSERT_EQUAL_UINT32(0, report[0]); // new period starts empty + TEST_ASSERT_EQUAL_UINT32(500, report[1]); // old period shifted back one slot +} + +// The property runOnce() alone could never exercise: several hours pass in a single sync (e.g. the +// device was light-sleeping), so the rotation has to walk forward more than one period at once. +void test_period_rotates_once_per_hour_crossed_while_asleep() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(TX_LOG, 200); + + Time::advanceTestMillis(3u * 3600u * 1000u); // 3 hours in one jump + + uint32_t *report = a.airtimeReport(TX_LOG); + TEST_ASSERT_EQUAL_UINT32(200, report[3]); + TEST_ASSERT_EQUAL_UINT32(0, report[0]); + TEST_ASSERT_EQUAL_UINT32(0, report[1]); + TEST_ASSERT_EQUAL_UINT32(0, report[2]); +} + +// More periods elapse than there are slots to rotate through: the whole history is stale, not just +// the oldest slot, so it must be wiped rather than rotated PERIODS_TO_LOG times. +void test_period_history_clears_when_asleep_longer_than_the_whole_log() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(TX_LOG, 999); + + Time::advanceTestMillis(9u * 3600u * 1000u); // 9 hours > PERIODS_TO_LOG (8) + + uint32_t *report = a.airtimeReport(TX_LOG); + for (uint8_t i = 0; i < a.getPeriodsToLog(); i++) { + TEST_ASSERT_EQUAL_UINT32_MESSAGE(0, report[i], "stale history must be cleared, not rotated in"); + } +} + +// --- channel utilization: rolling 60s window --- + +void test_channel_utilization_reflects_recent_airtime() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(RX_LOG, 6000); // 6s of airtime inside the 60s window + + TEST_ASSERT_FLOAT_WITHIN(0.01f, 10.0f, a.channelUtilizationPercent()); +} + +void test_channel_utilization_decays_once_the_60s_window_passes() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(RX_LOG, 6000); + + Time::advanceTestMillis(70u * 1000u); // longer than the 60s rolling window + + TEST_ASSERT_FLOAT_WITHIN(0.01f, 0.0f, a.channelUtilizationPercent()); +} + +void test_isTxAllowedChannelUtil_blocks_once_over_threshold() +{ + Time::setTestMillis(0); + AirTime a; + + TEST_ASSERT_TRUE(a.isTxAllowedChannelUtil()); // nothing logged yet + + a.logAirtime(RX_LOG, 25000); // 25s / 60s = 41.7%, over the 40% default max + TEST_ASSERT_FALSE(a.isTxAllowedChannelUtil()); +} + +// --- TX utilization: rolling 60-minute window --- + +void test_tx_utilization_decays_once_the_60_minute_window_passes() +{ + Time::setTestMillis(0); + AirTime a; + a.logAirtime(TX_LOG, 60000); // 1 minute of TX airtime + + TEST_ASSERT_TRUE(a.utilizationTXPercent() > 0.0f); + + Time::advanceTestMillis(61u * 60u * 1000u); // longer than the 60-minute rolling window + + TEST_ASSERT_FLOAT_WITHIN(0.01f, 0.0f, a.utilizationTXPercent()); +} + +// --- the headline property: syncNow() must survive the 32-bit millis() wrap --- + +void test_syncNow_survives_millis_wrap() +{ + const uint32_t beforeWrap = 4294967000u; // 296ms before the wrap, on a whole-second boundary + Time::setTestMillis(beforeWrap); + Time::serviceMonotonic(); // the main loop's publish, which is what carries the wrap + AirTime a; + + TEST_ASSERT_EQUAL_UINT32(4294967u, a.getSecondsSinceBoot()); + + Time::advanceTestMillis(1000); // crosses the wrap + Time::serviceMonotonic(); + TEST_ASSERT_EQUAL_UINT32(4294968u, a.getSecondsSinceBoot()); +} + +// A bucket logged just before the wrap must still be the one that rotates out after it - pinning +// the same property test_period_rotates_after_one_hour checks, but across the wrap boundary. +void test_period_rotation_survives_millis_wrap() +{ + const uint32_t beforeWrap = 0xFFFFFFFFu - (3600u * 1000u) + 1; // one hour minus 1ms before the wrap + Time::setTestMillis(beforeWrap); + Time::serviceMonotonic(); + AirTime a; + a.logAirtime(TX_LOG, 777); + + Time::advanceTestMillis(3600u * 1000u); // wraps partway through + Time::serviceMonotonic(); + + uint32_t *report = a.airtimeReport(TX_LOG); + TEST_ASSERT_EQUAL_UINT32(0, report[0]); + TEST_ASSERT_EQUAL_UINT32(777, report[1]); +} + +void setup() +{ + initializeTestEnvironment(); + UNITY_BEGIN(); + RUN_TEST(test_logAirtime_writes_into_current_bucket_immediately); + RUN_TEST(test_getSecondsSinceBoot_tracks_elapsed_time); + RUN_TEST(test_period_rotates_after_one_hour); + RUN_TEST(test_period_rotates_once_per_hour_crossed_while_asleep); + RUN_TEST(test_period_history_clears_when_asleep_longer_than_the_whole_log); + RUN_TEST(test_channel_utilization_reflects_recent_airtime); + RUN_TEST(test_channel_utilization_decays_once_the_60s_window_passes); + RUN_TEST(test_isTxAllowedChannelUtil_blocks_once_over_threshold); + RUN_TEST(test_tx_utilization_decays_once_the_60_minute_window_passes); + RUN_TEST(test_syncNow_survives_millis_wrap); + RUN_TEST(test_period_rotation_survives_millis_wrap); + exit(UNITY_END()); +} + +void loop() {} diff --git a/test/test_gps_fix_hold/test_main.cpp b/test/test_gps_fix_hold/test_main.cpp new file mode 100644 index 000000000..c6a4aec5e --- /dev/null +++ b/test/test_gps_fix_hold/test_main.cpp @@ -0,0 +1,218 @@ +// Unit tests for shouldArmFixHold() / fixHoldInForce() in src/gps/GPS.cpp - the post-lock +// ephemeris hold. +// +// In power-saving mode (gps_update_interval above GPS_UPDATE_ALWAYS_ON_THRESHOLD_MS) the GPS holds +// for up to 20s after a lock to download ephemeris, then publishes and sleeps. The predicate below +// decides, once per GPS thread cycle that has a location, whether a hold should be armed. +// +// The case that matters is a hold that was consumed by a publish which did not sleep: GPS::runOnce() +// clears fixHoldEnds whenever it publishes, but only calls down() when the search timed out or a +// hold expired. If the predicate treats "not holding" as a reason to skip, nothing re-arms, nothing +// publishes, and the receiver stays powered until searchedTooLong() fires. +#include "Arduino.h" +#include "TestUtil.h" +#include "Throttle.h" +#include "UptimeClock.h" +#include +#include + +// The predicates live beside their only caller in src/gps/GPS.cpp rather than in a header of their +// own; the native test build compiles that file, so declaring the prototypes here is enough. A +// signature change breaks the link rather than silently diverging from the definition. +bool fixHoldInForce(uint32_t fixHoldEnds, uint32_t threadIntervalMs); +bool holdJustExpired(uint32_t fixHoldEnds); +bool shouldArmFixHold(bool hasValidLocation, uint8_t prevFixQual, uint32_t fixHoldEnds, uint32_t threadIntervalMs); + +// GPS_THREAD_INTERVAL, spelled out so the suite does not pull in GPS.h and its hardware deps. +static constexpr uint32_t kThreadInterval = 200; + +// The two hold durations the firmware uses: GPS_FIX_HOLD_MAX_MS, and a short one. +static constexpr uint32_t kHoldMs = 20 * 1000; + +void setUp(void) +{ + Time::setTestMillis(0); +} +void tearDown(void) +{ + Time::useRealClock(); +} + +// Arms a hold at the current test time and returns the resulting fixHoldEnds. +static uint32_t armHoldNow(uint32_t holdMs = kHoldMs) +{ + return Time::getMillis() + holdMs; +} + +// --- the reasons to arm --- + +// First lock of a cycle: hasValidLocation is still false on the rising edge. +void test_arms_on_the_first_lock_of_a_cycle(void) +{ + Time::setTestMillis(50 * 1000); + TEST_ASSERT_TRUE(shouldArmFixHold(false, 3, 0, kThreadInterval)); +} + +// Lock after the receiver was off: down() zeroes fixQual, so prev_fixQual is 0 on the way back up. +void test_arms_on_the_first_lock_after_the_gps_was_off(void) +{ + Time::setTestMillis(50 * 1000); + TEST_ASSERT_TRUE(shouldArmFixHold(true, 0, 0, kThreadInterval)); +} + +// The regression. A publish that did not sleep leaves hasValidLocation set, prev_fixQual non-zero +// and fixHoldEnds cleared to 0. Nothing else in runOnce() re-arms, so if this returns false the +// GPS never holds, never publishes again and never calls down() until the search times out. +void test_arms_after_a_publish_cleared_the_hold_without_sleeping(void) +{ + Time::setTestMillis(50 * 1000); + TEST_ASSERT_TRUE_MESSAGE(shouldArmFixHold(true, 3, 0, kThreadInterval), + "fixHoldEnds == 0 means 'not holding', which is a reason to arm"); +} + +void test_arms_once_the_hold_has_expired(void) +{ + Time::setTestMillis(50 * 1000); + const uint32_t fixHoldEnds = armHoldNow(); + + Time::advanceTestMillis(kHoldMs + kThreadInterval); + TEST_ASSERT_TRUE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); +} + +// --- the reason not to arm --- + +void test_does_not_arm_while_a_hold_is_in_force(void) +{ + Time::setTestMillis(50 * 1000); + const uint32_t fixHoldEnds = armHoldNow(); + + Time::advanceTestMillis(kHoldMs / 2); + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); +} + +// The GPS_THREAD_INTERVAL grace period: at the exact deadline the hold has not yet expired, because +// the next cycle is one interval away. +void test_does_not_arm_in_the_thread_interval_grace_after_the_deadline(void) +{ + Time::setTestMillis(50 * 1000); + const uint32_t fixHoldEnds = armHoldNow(); + + Time::advanceTestMillis(kHoldMs); // exactly at the deadline + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); + + Time::advanceTestMillis(kThreadInterval - 1); + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); + + Time::advanceTestMillis(1); // deadline + GPS_THREAD_INTERVAL, inclusive boundary + TEST_ASSERT_TRUE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); +} + +// --- across the 32-bit wrap --- + +// A hold armed just before the wrap must still be held through it. The naive form this replaced +// (`(fixHoldEnds + GPS_THREAD_INTERVAL) < millis()`) read as expired for the whole pre-wrap window, +// re-arming the hold on every single cycle. +void test_does_not_arm_while_a_hold_straddling_the_wrap_is_in_force(void) +{ + Time::setTestMillis(0xFFFFFF00u); // 256ms short of the wrap + const uint32_t fixHoldEnds = armHoldNow(); + + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); + + Time::advanceTestMillis(0x200u); // now past the wrap, still inside the hold + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); + + Time::advanceTestMillis(kHoldMs); // well past the deadline, still past the wrap + TEST_ASSERT_TRUE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); +} + +// The deadline itself wrapping (fixHoldEnds numerically below millis()) must not read as expired. +void test_holds_when_the_deadline_wraps_but_now_has_not(void) +{ + Time::setTestMillis(0xFFFFFF00u); + const uint32_t fixHoldEnds = armHoldNow(); // wraps to ~0x4CFF + + TEST_ASSERT_TRUE_MESSAGE(fixHoldEnds < Time::getMillis(), "test setup: the deadline must have wrapped"); + TEST_ASSERT_FALSE(shouldArmFixHold(true, 3, fixHoldEnds, kThreadInterval)); +} + +// --- the two readings of the same sentinel --- + +// runOnce() asks two questions of fixHoldEnds and they take opposite answers when nothing is armed: +// "should I arm one?" (yes) and "did one just expire, so publish and sleep?" (no). Both are derived +// from fixHoldInForce(), which is the only place the sentinel is interpreted. +void test_no_hold_means_arm_but_does_not_mean_expired(void) +{ + Time::setTestMillis(50 * 1000); + + TEST_ASSERT_FALSE_MESSAGE(fixHoldInForce(0, kThreadInterval), "a hold that was never armed is not in force"); + TEST_ASSERT_TRUE_MESSAGE(shouldArmFixHold(true, 3, 0, kThreadInterval), "...so it is a reason to arm one"); + TEST_ASSERT_FALSE_MESSAGE(holdJustExpired(0), "...but not a reason to publish and sleep"); +} + +// holdJustExpired()'s sentinel guard is load-bearing on every cycle, not just past the half-range: +// fixHoldInForce() calls an unarmed hold "not in force", so negating it alone reads as expired. +void test_only_an_armed_hold_can_expire(void) +{ + Time::setTestMillis(50 * 1000); + const uint32_t fixHoldEnds = armHoldNow(); + + TEST_ASSERT_FALSE_MESSAGE(holdJustExpired(fixHoldEnds), "still inside the hold"); + + Time::advanceTestMillis(kHoldMs); // the deadline itself, no grace interval at this site + TEST_ASSERT_TRUE_MESSAGE(holdJustExpired(fixHoldEnds), "the deadline is the moment to publish and sleep"); + + TEST_ASSERT_TRUE_MESSAGE(!fixHoldInForce(0, 0), "test premise: the negation alone calls an unarmed hold expired"); + TEST_ASSERT_FALSE_MESSAGE(holdJustExpired(0), "so the sentinel test is what keeps it from expiring"); +} + +// The `fixHoldEnds != 0` term inside fixHoldInForce() looks redundant, and for the first half of +// each wrap cycle it is: deadlinePassed(0 + interval) is true once uptime exceeds one interval, so +// "not in force" would fall out of the arithmetic on its own. Past 2^31 ms of uptime it flips. +// deadlinePassed() is an unsigned half-range test, so `now - interval` lands in the top half and +// the sentinel reads as a deadline ~24.8 days in the FUTURE - an unarmed hold would look like one +// in force for the whole second half of every cycle, and nothing would ever re-arm. +void test_the_sentinel_guard_is_load_bearing_past_the_half_range(void) +{ + Time::setTestMillis(0x90000000u); // ~27.8 days of uptime, past the ~24.8-day half-range point + + // The arithmetic alone now says "not yet" for the sentinel... + TEST_ASSERT_FALSE_MESSAGE(Throttle::deadlinePassed(0 + kThreadInterval), + "test premise: past half-range the sentinel reads as a future deadline"); + + // ...so the explicit sentinel test is the only thing keeping the answer right. + TEST_ASSERT_FALSE_MESSAGE(fixHoldInForce(0, kThreadInterval), "an unarmed hold is never in force"); + TEST_ASSERT_TRUE_MESSAGE(shouldArmFixHold(true, 3, 0, kThreadInterval), "...so a hold must still be armed"); +} + +void test_hold_in_force_tracks_the_deadline(void) +{ + Time::setTestMillis(50 * 1000); + const uint32_t fixHoldEnds = armHoldNow(); + + TEST_ASSERT_TRUE(fixHoldInForce(fixHoldEnds, kThreadInterval)); + + Time::advanceTestMillis(kHoldMs + kThreadInterval); + TEST_ASSERT_FALSE(fixHoldInForce(fixHoldEnds, kThreadInterval)); +} + +void setup() +{ + initializeTestEnvironment(); + UNITY_BEGIN(); + RUN_TEST(test_no_hold_means_arm_but_does_not_mean_expired); + RUN_TEST(test_only_an_armed_hold_can_expire); + RUN_TEST(test_the_sentinel_guard_is_load_bearing_past_the_half_range); + RUN_TEST(test_hold_in_force_tracks_the_deadline); + RUN_TEST(test_arms_on_the_first_lock_of_a_cycle); + RUN_TEST(test_arms_on_the_first_lock_after_the_gps_was_off); + RUN_TEST(test_arms_after_a_publish_cleared_the_hold_without_sleeping); + RUN_TEST(test_arms_once_the_hold_has_expired); + RUN_TEST(test_does_not_arm_while_a_hold_is_in_force); + RUN_TEST(test_does_not_arm_in_the_thread_interval_grace_after_the_deadline); + RUN_TEST(test_does_not_arm_while_a_hold_straddling_the_wrap_is_in_force); + RUN_TEST(test_holds_when_the_deadline_wraps_but_now_has_not); + exit(UNITY_END()); +} + +void loop() {} diff --git a/test/test_meshpacket_serializer/ports/test_timestamp.cpp b/test/test_meshpacket_serializer/ports/test_timestamp.cpp index 333945f80..d6e38bcf1 100644 --- a/test/test_meshpacket_serializer/ports/test_timestamp.cpp +++ b/test/test_meshpacket_serializer/ports/test_timestamp.cpp @@ -21,7 +21,7 @@ void test_timestamp_zeroed_when_rx_time_absent() std::string json = MeshPacketSerializer::JsonSerialize(&packet, false); Json::Value root = parse_json(json); TEST_ASSERT_TRUE(root.isMember("timestamp")); - TEST_ASSERT_EQUAL_UINT32(0u, root["timestamp"].asUInt()); // must not leak the millis() placeholder + TEST_ASSERT_EQUAL_UINT32(0u, root["timestamp"].asUInt()); // must not leak the uptime placeholder } void test_encrypted_timestamp_zeroed_when_rx_time_absent() diff --git a/test/test_meshpacket_serializer/test_helpers.h b/test/test_meshpacket_serializer/test_helpers.h index 2dc06cec7..63447d509 100644 --- a/test/test_meshpacket_serializer/test_helpers.h +++ b/test/test_meshpacket_serializer/test_helpers.h @@ -70,7 +70,7 @@ static meshtastic_MeshPacket create_test_packet_no_rx_time(meshtastic_PortNum po int payload_variant = meshtastic_MeshPacket_decoded_tag) { meshtastic_MeshPacket packet = create_test_packet(port, payload, payload_size, payload_variant); - packet.rx_time = 123456; // a plausible millis() placeholder, not a real epoch + packet.rx_time = 123456; // a plausible uptime-seconds placeholder, not a real epoch packet.has_rx_time = false; return packet; } diff --git a/test/test_nodedb_blocked/test_main.cpp b/test/test_nodedb_blocked/test_main.cpp index 88d7f0259..8b35d6534 100644 --- a/test/test_nodedb_blocked/test_main.cpp +++ b/test/test_nodedb_blocked/test_main.cpp @@ -25,6 +25,7 @@ class NodeDBTestShim : public NodeDB public: void runDemote() { demoteOldestHotNodesToWarm(); } void runCleanup() { cleanupMeshDB(); } + void stampUntrusted(NodeNum num, uint32_t uptimeSecs) { recordHeardWhileClockUntrusted(num, uptimeSecs); } // Read back the role + protected category the warm tier cached for a node. bool warmMeta(NodeNum n, uint8_t &role, uint8_t &prot) { return warmStore.lookupMeta(n, role, prot); } @@ -178,6 +179,27 @@ static void test_eviction_preservesFavorite(void) TEST_ASSERT_NOT_NULL(db->getMeshNode(0x99990000)); } +// A node heard during this boot is newer than every persisted epoch, including valid epochs after +// 2038. Ranking both domains in one uint32_t incorrectly evicts the current-boot node first. +static void test_eviction_prefers_current_boot_stamp_over_post2038_epoch(void) +{ + constexpr NodeNum futureDated = 0x70000001; + constexpr NodeNum heardThisBoot = 0x70000002; + + db->seedSelf(); + db->push(futureDated, 0xB5000000u, false, false, /*withUser=*/true, /*withKey=*/true); + db->push(heardThisBoot, 0, false, false, /*withUser=*/true, /*withKey=*/true); + db->stampUntrusted(heardThisBoot, 10); + for (int i = 3; i < MAX_NUM_NODES; i++) + db->push(0x70000000u + i, UINT32_MAX, false, false, /*withUser=*/true, /*withKey=*/true); + + TEST_ASSERT_EQUAL_INT(MAX_NUM_NODES, (int)db->getNumMeshNodes()); + TEST_ASSERT_NOT_NULL(db->getOrCreateMeshNode(0x79999999)); + + TEST_ASSERT_NULL(db->getMeshNode(futureDated)); + TEST_ASSERT_NOT_NULL(db->getMeshNode(heardThisBoot)); +} + // Ignored handling: an ignored node survives eviction (like a favourite), and is // never purged by cleanupMeshDB even with no user info (a block set by bare ID). static void test_ignored_survivesEvictionAndCleanup(void) @@ -269,6 +291,7 @@ NDB_TEST_ENTRY void setup() RUN_TEST(test_migration_carriesRoleAndProtectedIntoWarm); RUN_TEST(test_migration_carriesSignerBitThroughWarm); RUN_TEST(test_eviction_preservesFavorite); + RUN_TEST(test_eviction_prefers_current_boot_stamp_over_post2038_epoch); RUN_TEST(test_ignored_survivesEvictionAndCleanup); RUN_TEST(test_protectedCap_refusesBeyondLimit); RUN_TEST(test_removeNodeByNum_absentNodeOnFullDb); diff --git a/test/test_packet_signing/test_main.cpp b/test/test_packet_signing/test_main.cpp index c3abb7bc9..d8234290a 100644 --- a/test/test_packet_signing/test_main.cpp +++ b/test/test_packet_signing/test_main.cpp @@ -22,6 +22,7 @@ // compiled out unless both PKI and XEdDSA are enabled (e.g. stm32 sets MESHTASTIC_EXCLUDE_XEDDSA). #if !(MESHTASTIC_EXCLUDE_PKI) && !(MESHTASTIC_EXCLUDE_XEDDSA) +#include "UptimeClock.h" #include "mesh/Channels.h" #include "mesh/CryptoEngine.h" #include "mesh/MeshRadio.h" @@ -421,6 +422,16 @@ void tearDown(void) delete mockNodeDB; mockNodeDB = nullptr; nodeDB = nullptr; + + // Restore globals here, not at the end of a test body: an assertion aborts the body, and these + // would otherwise leak into every later case. The injected clock is the one the N8-N11 + // suppression-window cases drive; the region and TX bucket are C14's duty-cycle setup. + Time::useRealClock(); + Time::resetMonotonicForTests(); + if (airTime) + airTime->utilizationTX[0] = 0; + config.lora.region = meshtastic_Config_LoRaConfig_RegionCode_US; + initRegion(); } // =========================================================================== @@ -1073,6 +1084,7 @@ void test_B13_licensed_port_and_destination_signing_matrix(void) class NodeInfoTestShim : public NodeInfoModule { public: + using MeshModule::currentRequest; // allocReply() only suppresses while a request is in flight using NodeInfoModule::allocReply; using NodeInfoModule::handleReceivedProtobuf; }; @@ -1221,14 +1233,18 @@ void test_C3_invalid_repeated_packet_cannot_ack_or_change_retry_state(void) prior.hop_start = 2; prior.transport_mechanism = meshtastic_MeshPacket_TransportMechanism_TRANSPORT_LORA; pipelineRouter->remember(&prior); - pipelineRouter->addPending(prior, UINT32_MAX); + // "Far future, so no retransmission is due." Must be a representable future time, not + // UINT32_MAX: doRetransmissions() compares with an unsigned half-range test, under which + // UINT32_MAX is ~1ms in the *past* and would fire a retransmit and rewrite nextTxMsec. + const uint32_t notDueTxMsec = Time::getMillis() + 3600000UL; + pipelineRouter->addPending(prior, notDueTxMsec); const uint32_t lastHeard = mockNodeDB->getMeshNode(LOCAL_NODE)->last_heard; meshtastic_MeshPacket invalid = makeSignedWirePacket(LOCAL_NODE, NODENUM_BROADCAST, id, 2, 2, 0, 0x34, false); runPipelineIngress(invalid); assertNoRejectedPipelineEffects(LOCAL_NODE, lastHeard); TEST_ASSERT_EQUAL(1, pipelineRouter->pendingCount()); - TEST_ASSERT_EQUAL_UINT32(UINT32_MAX, pipelineRouter->pendingNextTx(LOCAL_NODE, id)); + TEST_ASSERT_EQUAL_UINT32(notDueTxMsec, pipelineRouter->pendingNextTx(LOCAL_NODE, id)); } void test_C4_invalid_fallback_packet_cannot_relay(void) @@ -1569,6 +1585,113 @@ void test_N7_unsigned_unicast_nodeinfo_from_nonsigner_changes_name(void) "non-signer identity learning must be unaffected"); } +// --------------------------------------------------------------------------- +// N8-N11: the 12h reply-suppression window. +// +// The stamp is uptime SECONDS, not milliseconds: entries live for as long as the node stays in the +// DB, so a 32-bit millisecond stamp aliased back into the window once uptime passed 49.7 days and +// suppressed a legitimate reply for up to 12h. Driven through Time::setTestMillis() rather than by +// waiting. +// --------------------------------------------------------------------------- + +static constexpr uint32_t kSuppressSecs = 12 * 60 * 60; + +// Deliver a NodeInfo request from `sender` and report whether we would reply to it. +static bool wouldReplyToNodeInfoRequest(NodeInfoTestShim &shim, NodeNum sender) +{ + meshtastic_MeshPacket mp = makeDecoded(sender, NODENUM_BROADCAST, meshtastic_PortNum_NODEINFO_APP, SMALL_PAYLOAD); + mp.decoded.want_response = true; + meshtastic_User user = meshtastic_User_init_zero; + user.is_licensed = owner.is_licensed; + + shim.handleReceivedProtobuf(mp, &user); + + NodeInfoTestShim::currentRequest = ∓ + meshtastic_MeshPacket *reply = shim.allocReply(); + NodeInfoTestShim::currentRequest = nullptr; + + if (reply) { + packetPool.release(reply); + return true; + } + return false; +} + +// Step the injected clock the way the main loop does - advance, then publish the wrap carry. +static void advanceUptime(uint32_t deltaMs) +{ + Time::advanceTestMillis(deltaMs); + Time::serviceMonotonic(); +} + +void test_N8_second_request_inside_the_window_is_suppressed(void) +{ + mockNodeDB->addNode(REMOTE_NODE); + Time::setTestMillis(60 * 1000); + Time::serviceMonotonic(); + + NodeInfoTestShim shim; + TEST_ASSERT_TRUE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), "first request must be answered"); + + advanceUptime(60 * 60 * 1000); // 1h later, well inside the 12h window + TEST_ASSERT_FALSE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), "repeat request inside 12h must be suppressed"); +} + +void test_N9_request_after_the_window_is_answered(void) +{ + mockNodeDB->addNode(REMOTE_NODE); + Time::setTestMillis(60 * 1000); + Time::serviceMonotonic(); + + NodeInfoTestShim shim; + TEST_ASSERT_TRUE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE)); + + advanceUptime((kSuppressSecs + 60) * 1000); // 12h + a minute + TEST_ASSERT_TRUE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), "request after 12h must be answered"); +} + +// The regression. A stamp is only aliased by a counter that wraps underneath it, so the failure +// needs a *full* 2^32 ms of uptime to elapse, not merely a crossing of the boundary: with 32-bit +// millisecond stamps `now - stamp` then computes as 0 and the sender looks like it was answered +// this instant. Uptime seconds do not wrap for 136 years, so the entry reads as ~49.7 days old. +void test_N10_stale_stamp_does_not_alias_after_a_full_wrap(void) +{ + mockNodeDB->addNode(REMOTE_NODE); + Time::setTestMillis(0x80000000u); // ~24.8 days of uptime + Time::serviceMonotonic(); + + NodeInfoTestShim shim; + TEST_ASSERT_TRUE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE)); + + // A whole millis() cycle, in two serviced halves - one publish per window is the contract. + advanceUptime(0x80000000u); + advanceUptime(0x80000000u); + + TEST_ASSERT_TRUE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), + "a stamp one full wrap old must read as ~49.7 days, not as this instant"); +} + +// Suppression must still behave normally either side of the boundary: still suppressing inside the +// window, and answering again once 12h have passed, with the stamp and the reading on opposite +// sides of the wrap. +void test_N11_window_still_applies_across_the_wrap(void) +{ + mockNodeDB->addNode(REMOTE_NODE); + Time::setTestMillis(0xFFFF0000u); // just short of the wrap + Time::serviceMonotonic(); + + NodeInfoTestShim shim; + TEST_ASSERT_TRUE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE)); + + advanceUptime(0x20000u); // ~131s later, and now past the wrap + TEST_ASSERT_FALSE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), + "the window must still bite when the stamp sits the other side of the wrap"); + + advanceUptime((kSuppressSecs + 60) * 1000); + TEST_ASSERT_TRUE_MESSAGE(wouldReplyToNodeInfoRequest(shim, REMOTE_NODE), + "and must still release once 12h have passed across the wrap"); +} + void test_L1_licensed_nodeinfo_publishes_public_key(void) { owner.is_licensed = true; @@ -1984,6 +2107,10 @@ void setup() RUN_TEST(test_N5_unsigned_unicast_nodeinfo_from_signer_does_not_change_name); RUN_TEST(test_N6_signed_unicast_nodeinfo_from_signer_changes_name); RUN_TEST(test_N7_unsigned_unicast_nodeinfo_from_nonsigner_changes_name); + RUN_TEST(test_N8_second_request_inside_the_window_is_suppressed); + RUN_TEST(test_N9_request_after_the_window_is_answered); + RUN_TEST(test_N10_stale_stamp_does_not_alias_after_a_full_wrap); + RUN_TEST(test_N11_window_still_applies_across_the_wrap); printf("\n=== Group L: licensed identity and plaintext signing ===\n"); RUN_TEST(test_L1_licensed_nodeinfo_publishes_public_key); diff --git a/test/test_stream_api/test_main.cpp b/test/test_stream_api/test_main.cpp index 5075fe461..994e82c3d 100644 --- a/test/test_stream_api/test_main.cpp +++ b/test/test_stream_api/test_main.cpp @@ -526,14 +526,14 @@ static void test_want_config_includes_status_message_module_config(void) } /// Queue a packet as Router::dispatchReceived would have, before any time source existed. -static void queuePendingTimePlaceholderPacket(NodeNum from, uint32_t placeholderMillis) +static void queuePendingTimePlaceholderPacket(NodeNum from, uint32_t placeholderUptimeSecs) { meshtastic_MeshPacket pending = meshtastic_MeshPacket_init_zero; pending.which_payload_variant = meshtastic_MeshPacket_decoded_tag; pending.decoded.portnum = meshtastic_PortNum_TEXT_MESSAGE_APP; pending.from = from; pending.to = NODENUM_BROADCAST; - pending.rx_time = placeholderMillis; + pending.rx_time = placeholderUptimeSecs; // computeRxTimeStamp() stamps Time::getUptimeSecs() pending.has_rx_time = false; service->sendToPhone(packetPool.allocCopy(pending)); } @@ -574,6 +574,7 @@ class ScopedTimeFixture ScopedTimeFixture(uint32_t startMillis) : previous(nodeDB) { resetRTCStateForTests(); + Time::resetMonotonicForTests(); // uptime-seconds placeholders assume no carried wrap nodeDB = &instance; Time::setTestMillis(startMillis); } @@ -597,7 +598,7 @@ static void test_time_given_at_handshake_start_reconciles_queued_packet(void) ScopedTimeFixture timeFixture(5000); const NodeNum sender = 0x12345678; - queuePendingTimePlaceholderPacket(sender, 2000); // "received" 3s before the test's current millis() + queuePendingTimePlaceholderPacket(sender, 2); // "received" at uptime 2s, 3s before the fixture's 5000ms now PhoneAPITestShim api; startHandshake(api); @@ -624,7 +625,7 @@ static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packe ScopedTimeFixture timeFixture(5000); const NodeNum sender = 0x12345678; - queuePendingTimePlaceholderPacket(sender, 2000); + queuePendingTimePlaceholderPacket(sender, 2); PhoneAPITestShim api; startHandshake(api); @@ -650,6 +651,68 @@ static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packe api.close(); } +// The NodeDB half of the same transition: a node heard while the clock was untrusted gets no +// last_heard at all (the arrival instant waits in the RAM sidecar as uptime seconds), and the +// clock-valid hook backfills it to the real epoch of the sighting - so the phone reads +// "last heard: unknown" only until time arrives, never a boot-relative value. +static void test_node_heard_before_time_gets_last_heard_backfilled(void) +{ + ScopedMeshService scopedService; + ScopedTimeFixture timeFixture(5000); + + const NodeNum sender = 0x22334455; + meshtastic_MeshPacket heard = meshtastic_MeshPacket_init_zero; + heard.which_payload_variant = meshtastic_MeshPacket_decoded_tag; + heard.decoded.portnum = meshtastic_PortNum_TEXT_MESSAGE_APP; + heard.from = sender; + heard.to = NODENUM_BROADCAST; + heard.rx_time = 2; // uptime-seconds placeholder: "arrived at uptime 2s" + heard.has_rx_time = false; + nodeDB->updateFrom(heard); + + const meshtastic_NodeInfoLite *info = nodeDB->getMeshNode(sender); + TEST_ASSERT_NOT_NULL(info); + TEST_ASSERT_EQUAL_UINT32(0u, info->last_heard); // absent, never a boot-relative stamp + + struct timeval networkTime; + networkTime.tv_sec = time(NULL) + SEC_PER_DAY; + networkTime.tv_usec = 0; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &networkTime)); + + // Heard at uptime 2s, clock arrived at uptime 5s: the sighting dates to nowEpoch - 3. + TEST_ASSERT_UINT32_WITHIN(2, (uint32_t)networkTime.tv_sec - 3, info->last_heard); +} + +// Uptime zero is a valid arrival instant during the first second of boot. It must not be confused +// with an absent sidecar record when network time arrives. +static void test_node_heard_during_first_uptime_second_gets_last_heard_backfilled(void) +{ + ScopedMeshService scopedService; + ScopedTimeFixture timeFixture(500); + + const NodeNum sender = 0x33445566; + TEST_ASSERT_NOT_NULL(nodeDB->getOrCreateMeshNode(sender)); + meshtastic_MeshPacket heard = meshtastic_MeshPacket_init_zero; + heard.which_payload_variant = meshtastic_MeshPacket_decoded_tag; + heard.decoded.portnum = meshtastic_PortNum_TEXT_MESSAGE_APP; + heard.from = sender; + heard.to = NODENUM_BROADCAST; + heard.rx_time = 0; // received during uptime second zero + heard.has_rx_time = false; + nodeDB->updateFrom(heard); + + const meshtastic_NodeInfoLite *info = nodeDB->getMeshNode(sender); + TEST_ASSERT_NOT_NULL(info); + TEST_ASSERT_EQUAL_UINT32(0u, info->last_heard); + + struct timeval networkTime; + networkTime.tv_sec = time(NULL) + SEC_PER_DAY; + networkTime.tv_usec = 0; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &networkTime)); + + TEST_ASSERT_UINT32_WITHIN(1, (uint32_t)networkTime.tv_sec, info->last_heard); +} + /// Unity per-test setup; fixtures are local to each test. void setUp(void) {} /// Unity per-test teardown; fixtures clean themselves up. @@ -674,6 +737,8 @@ void setup() RUN_TEST(test_want_config_includes_status_message_module_config); RUN_TEST(test_time_given_at_handshake_start_reconciles_queued_packet); RUN_TEST(test_time_given_at_handshake_end_does_not_rewrite_already_sent_packet); + RUN_TEST(test_node_heard_before_time_gets_last_heard_backfilled); + RUN_TEST(test_node_heard_during_first_uptime_second_gets_last_heard_backfilled); // usingProtobufs intentionally has no reset path, so this must run last. RUN_TEST(test_serial_console_suppresses_raw_output_in_protobuf_mode); exit(UNITY_END()); diff --git a/test/test_throttle/test_main.cpp b/test/test_throttle/test_main.cpp new file mode 100644 index 000000000..e2630ba3d --- /dev/null +++ b/test/test_throttle/test_main.cpp @@ -0,0 +1,237 @@ +// Unit tests for src/mesh/Throttle.{h,cpp} - the firmware's elapsed-time and deadline helpers. +// +// These drive the injected clock across the 32-bit millis() wrap, which is not otherwise reachable +// in a test, and which every caller of these helpers depends on being handled correctly. +#include "Arduino.h" +#include "TestUtil.h" +#include "UptimeClock.h" +#include "mesh/Throttle.h" +#include +#include + +void setUp(void) {} +void tearDown(void) +{ + Time::useRealClock(); // don't leak the fake clock into other suites +} + +// --- basic window semantics --- + +void test_isWithinTimespan_true_inside_window() +{ + Time::setTestMillis(10000); + TEST_ASSERT_TRUE(Throttle::isWithinTimespanMs(9500, 1000)); // 500ms elapsed of a 1000ms window +} + +void test_isWithinTimespan_false_outside_window() +{ + Time::setTestMillis(10000); + TEST_ASSERT_FALSE(Throttle::isWithinTimespanMs(8000, 1000)); // 2000ms elapsed +} + +// The boundary is exclusive: elapsed == interval is NOT "within". +void test_isWithinTimespan_boundary_is_exclusive() +{ + Time::setTestMillis(10000); + TEST_ASSERT_FALSE(Throttle::isWithinTimespanMs(9000, 1000)); // exactly 1000ms elapsed + TEST_ASSERT_TRUE(Throttle::isWithinTimespanMs(9001, 1000)); // 999ms elapsed +} + +// --- hasElapsed is the exact complement --- + +void test_hasElapsed_is_complement_of_isWithinTimespan() +{ + Time::setTestMillis(10000); + const uint32_t cases[][2] = {{9500, 1000}, {8000, 1000}, {9000, 1000}, {10000, 1}, {0, 5000}}; + for (auto &c : cases) { + TEST_ASSERT_EQUAL(!Throttle::isWithinTimespanMs(c[0], c[1]), Throttle::hasElapsed(c[0], c[1])); + } +} + +void test_hasElapsed_boundary_is_inclusive() +{ + Time::setTestMillis(10000); + TEST_ASSERT_TRUE(Throttle::hasElapsed(9000, 1000)); // exactly 1000ms elapsed + TEST_ASSERT_FALSE(Throttle::hasElapsed(9001, 1000)); // 999ms elapsed +} + +// --- rollover: the headline property --- + +// A window opened just before the 32-bit wrap must still close correctly after it. +void test_isWithinTimespan_survives_millis_wrap() +{ + const uint32_t lastRun = 0xFFFFFF00u; // 256ms before the wrap + Time::setTestMillis(lastRun); + + Time::advanceTestMillis(100); // 0xFFFFFF64 - still before the wrap + TEST_ASSERT_TRUE(Throttle::isWithinTimespanMs(lastRun, 1000)); + + Time::advanceTestMillis(200); // wraps to 0x0000002C - 300ms elapsed in total + TEST_ASSERT_TRUE(Throttle::isWithinTimespanMs(lastRun, 1000)); + TEST_ASSERT_FALSE(Throttle::hasElapsed(lastRun, 1000)); + + Time::advanceTestMillis(800); // 1100ms elapsed in total, well past the wrap + TEST_ASSERT_FALSE(Throttle::isWithinTimespanMs(lastRun, 1000)); + TEST_ASSERT_TRUE(Throttle::hasElapsed(lastRun, 1000)); +} + +// The long-interval end of the range: a 24h window (the longest in the tree) across the wrap. +void test_long_interval_survives_wrap() +{ + const uint32_t dayMs = 24u * 60u * 60u * 1000u; // 86,400,000 + const uint32_t lastRun = 0xFFFFFF00u; + Time::setTestMillis(lastRun); + + Time::advanceTestMillis(dayMs - 1); + TEST_ASSERT_TRUE(Throttle::isWithinTimespanMs(lastRun, dayMs)); + + Time::advanceTestMillis(1); // exactly one day elapsed + TEST_ASSERT_TRUE(Throttle::hasElapsed(lastRun, dayMs)); +} + +// --- deadlinePassed() --- + +void test_deadlinePassed_basic() +{ + Time::setTestMillis(10000); + TEST_ASSERT_FALSE(Throttle::deadlinePassed(10001)); // 1ms in the future + TEST_ASSERT_TRUE(Throttle::deadlinePassed(10000)); // exactly now counts as passed + TEST_ASSERT_TRUE(Throttle::deadlinePassed(9999)); // 1ms in the past +} + +// The property the naive `millis() > deadline` compare fails: a deadline set before the wrap must +// fire once, and only once, after the wrap. +void test_deadlinePassed_survives_millis_wrap() +{ + Time::setTestMillis(0xFFFFFF00u); // 256ms before the wrap + const uint32_t deadline = 0xFFFFFF00u + 500; + + TEST_ASSERT_FALSE(Throttle::deadlinePassed(deadline)); // not yet + Time::advanceTestMillis(400); // 0x00000090 - wrapped, still not due + TEST_ASSERT_FALSE(Throttle::deadlinePassed(deadline)); + Time::advanceTestMillis(100); // exactly due, past the wrap + TEST_ASSERT_TRUE(Throttle::deadlinePassed(deadline)); + Time::advanceTestMillis(60000); // stays passed + TEST_ASSERT_TRUE(Throttle::deadlinePassed(deadline)); +} + +// The naive compare's actual failure mode, pinned so a regression is unmistakable: before the wrap +// the deadline is numerically smaller than now, so `millis() > deadline` would fire it early. +void test_deadlinePassed_does_not_fire_early_when_deadline_wraps() +{ + Time::setTestMillis(0xFFFFFF00u); + const uint32_t deadline = 0xFFFFFF00u + 1000; // wraps to 0x000002E8 + + TEST_ASSERT_TRUE(deadline < Time::getMillis()); // the naive compare would fire here + TEST_ASSERT_FALSE(Throttle::deadlinePassed(deadline)); +} + +// deadlinePassedAt() judges against a caller-supplied now, so a loop that snapshots the clock once +// gets one instant for every entry - including across the wrap, where the clock has moved on. +void test_deadlinePassedAt_uses_the_supplied_now() +{ + Time::setTestMillis(0xFFFFFF00u); + const uint32_t now = Time::getMillis(); + const uint32_t deadline = 0xFFFFFF00u + 500; // wraps to 0x000000F4 + + TEST_ASSERT_FALSE(Throttle::deadlinePassedAt(now, deadline)); + TEST_ASSERT_TRUE(Throttle::deadlinePassedAt(deadline, deadline)); // inclusive boundary + TEST_ASSERT_TRUE(Throttle::deadlinePassedAt(deadline + 1, deadline)); // past the wrap + Time::advanceTestMillis(60000); // clock moved, snapshot did not + TEST_ASSERT_FALSE(Throttle::deadlinePassedAt(now, deadline)); + TEST_ASSERT_TRUE(Throttle::deadlinePassed(deadline)); +} + +// deadlinePassed() cannot know about sentinels, so it reports them as passed. This pins that +// contract, since callers relying on it must test armed-ness first. +void test_deadlinePassed_reads_disarmed_sentinels_as_passed() +{ + Time::setTestMillis(6247); + + TEST_ASSERT_TRUE(Throttle::deadlinePassed(0)); // "inactive" for rebootAtMsec et al + TEST_ASSERT_TRUE(Throttle::deadlinePassed(UINT32_MAX)); // "inactive" for nagCycleCutoff + + // The guarded form every caller must use. + const uint32_t disarmed = 0; + TEST_ASSERT_FALSE(disarmed && Throttle::deadlinePassed(disarmed)); + + // And it still holds after a wrap. + Time::setTestMillis(0xFFFFFF00u); + Time::advanceTestMillis(1000); + TEST_ASSERT_FALSE(disarmed && Throttle::deadlinePassed(disarmed)); +} + +// --- execute() --- + +static int executeCount = 0; +static int deferCount = 0; +static void countExecute() +{ + executeCount++; +} +static void countDefer() +{ + deferCount++; +} + +void test_execute_runs_first_time_then_throttles() +{ + executeCount = 0; + deferCount = 0; + Time::setTestMillis(5000); + + uint32_t last = 0; // 0 means "never run" to execute() + TEST_ASSERT_TRUE(Throttle::execute(&last, 1000, countExecute, countDefer)); + TEST_ASSERT_EQUAL(1, executeCount); + + // Immediately again: deferred. + TEST_ASSERT_FALSE(Throttle::execute(&last, 1000, countExecute, countDefer)); + TEST_ASSERT_EQUAL(1, executeCount); + TEST_ASSERT_EQUAL(1, deferCount); + + // After the interval: runs again. + Time::advanceTestMillis(1000); + TEST_ASSERT_TRUE(Throttle::execute(&last, 1000, countExecute, countDefer)); + TEST_ASSERT_EQUAL(2, executeCount); +} + +void test_execute_survives_millis_wrap() +{ + executeCount = 0; + Time::setTestMillis(0xFFFFFF00u); + + uint32_t last = 0; + TEST_ASSERT_TRUE(Throttle::execute(&last, 1000, countExecute)); // arms at 0xFFFFFF00 + TEST_ASSERT_EQUAL(1, executeCount); + + Time::advanceTestMillis(500); // wraps past 0 + TEST_ASSERT_FALSE(Throttle::execute(&last, 1000, countExecute)); // not due yet + TEST_ASSERT_EQUAL(1, executeCount); + + Time::advanceTestMillis(600); // 1100ms total + TEST_ASSERT_TRUE(Throttle::execute(&last, 1000, countExecute)); + TEST_ASSERT_EQUAL(2, executeCount); +} + +void setup() +{ + initializeTestEnvironment(); + UNITY_BEGIN(); + RUN_TEST(test_isWithinTimespan_true_inside_window); + RUN_TEST(test_isWithinTimespan_false_outside_window); + RUN_TEST(test_isWithinTimespan_boundary_is_exclusive); + RUN_TEST(test_hasElapsed_is_complement_of_isWithinTimespan); + RUN_TEST(test_hasElapsed_boundary_is_inclusive); + RUN_TEST(test_isWithinTimespan_survives_millis_wrap); + RUN_TEST(test_long_interval_survives_wrap); + RUN_TEST(test_deadlinePassed_basic); + RUN_TEST(test_deadlinePassed_survives_millis_wrap); + RUN_TEST(test_deadlinePassed_does_not_fire_early_when_deadline_wraps); + RUN_TEST(test_deadlinePassedAt_uses_the_supplied_now); + RUN_TEST(test_deadlinePassed_reads_disarmed_sentinels_as_passed); + RUN_TEST(test_execute_runs_first_time_then_throttles); + RUN_TEST(test_execute_survives_millis_wrap); + exit(UNITY_END()); +} + +void loop() {} diff --git a/test/test_uptime_clock/test_main.cpp b/test/test_uptime_clock/test_main.cpp new file mode 100644 index 000000000..f950102c2 --- /dev/null +++ b/test/test_uptime_clock/test_main.cpp @@ -0,0 +1,356 @@ +// Unit tests for src/UptimeClock.{h,cpp} - the monotonic uptime seam. +// Covers: test-clock injection, stepping the injected clock, the real-clock fallback, and the +// single-writer wrap carry (readers derive, serviceMonotonic() publishes). getMillis() itself is a +// plain 32-bit read with no wrap handling of its own - its consumers' wrap arithmetic is tested in +// test_throttle/. +#include "Arduino.h" +#include "TestUtil.h" +#include "UptimeClock.h" +#include "gps/RTC.h" +#include +#include +#include +#include +#include +#include +#include + +namespace +{ +std::atomic publishPaused{false}; +std::atomic releasePublish{false}; + +void pauseMonotonicPublish() +{ + publishPaused.store(true, std::memory_order_release); + while (!releasePublish.load(std::memory_order_acquire)) + std::this_thread::yield(); +} +} // namespace + +void setUp(void) +{ + Time::resetMonotonicForTests(); // absolute uptime assertions must not depend on case order +} +void tearDown(void) +{ + Time::useRealClock(); // don't leak the fake clock into other suites + resetRTCStateForTests(); +} + +// Step the injected clock the way the firmware does: the main loop calls serviceMonotonic() every +// iteration, so any advance is followed by a publish. +static void advanceAndService(uint32_t deltaMs) +{ + Time::advanceTestMillis(deltaMs); + Time::serviceMonotonic(); +} + +// --- injection --- + +void test_getMillis_returns_injected_value() +{ + Time::setTestMillis(123456); + TEST_ASSERT_EQUAL_UINT32(123456, Time::getMillis()); +} + +void test_advanceTestMillis_steps_clock() +{ + Time::setTestMillis(1000); + Time::advanceTestMillis(500); + TEST_ASSERT_EQUAL_UINT32(1500, Time::getMillis()); +} + +// Advancing past 0xFFFFFFFF wraps like millis() does, rather than saturating. This is the property +// the Throttle wrap tests are built on, so it is worth pinning here too. +void test_advanceTestMillis_wraps_like_millis() +{ + Time::setTestMillis(0xFFFFFF00u); + Time::advanceTestMillis(0x200u); + TEST_ASSERT_EQUAL_UINT32(0x00000100u, Time::getMillis()); +} + +// --- getMillisMonotonic(): the published wrap carry --- + +void test_monotonic_matches_millis_before_any_wrap() +{ + Time::setTestMillis(123456); + TEST_ASSERT_EQUAL_UINT64(123456u, Time::getMillisMonotonic()); +} + +void test_monotonic_counts_a_wrap() +{ + Time::setTestMillis(0xFFFFFF00u); + Time::serviceMonotonic(); + TEST_ASSERT_EQUAL_UINT64(0xFFFFFF00u, Time::getMillisMonotonic()); + + advanceAndService(0x200u); // crosses the 32-bit wrap; low word is now 0x00000100 + TEST_ASSERT_EQUAL_UINT64(0x100000100ull, Time::getMillisMonotonic()); +} + +// The property that lets readers stay pure: a reader adds its own unsigned elapsed time to the +// published snapshot, so it is exact across a wrap that no publish has observed yet. Nothing here +// needs to detect the boundary, which is why concurrent readers cannot double-count it. +void test_monotonic_reader_crosses_the_wrap_without_a_publish() +{ + Time::setTestMillis(0xFFFFFF00u); + Time::serviceMonotonic(); // last publish before the wrap + + Time::advanceTestMillis(0x200u); // cross the wrap with no publish at all + TEST_ASSERT_EQUAL_UINT64(0x100000100ull, Time::getMillisMonotonic()); +} + +// Reads must not advance the carry. Under the old read-modify-write accessor each reader bumped +// the wrap counter itself, which is what made two of them able to count one wrap twice. +void test_monotonic_reads_do_not_advance_the_carry() +{ + Time::setTestMillis(0xFFFFFF00u); + Time::serviceMonotonic(); + + Time::advanceTestMillis(0x200u); + for (int i = 0; i < 8; i++) + TEST_ASSERT_EQUAL_UINT64(0x100000100ull, Time::getMillisMonotonic()); + + Time::serviceMonotonic(); // the eight reads must not have left eight wraps behind + TEST_ASSERT_EQUAL_UINT64(0x100000100ull, Time::getMillisMonotonic()); +} + +void test_monotonic_counts_every_wrap_when_serviced_each_window() +{ + Time::setTestMillis(0x80000000u); + Time::serviceMonotonic(); + TEST_ASSERT_EQUAL_UINT64(0x80000000ull, Time::getMillisMonotonic()); + + // Three full 2^32 cycles, published once per half-cycle - well inside the required + // one-publish-per-49.7-days window. + for (int wrap = 1; wrap <= 3; wrap++) { + advanceAndService(0x80000000u); // crosses the wrap; low word back to 0 + advanceAndService(0x80000000u); // completes the cycle; low word back to 0x80000000 + TEST_ASSERT_EQUAL_UINT64(0x80000000ull + ((uint64_t)wrap << 32), Time::getMillisMonotonic()); + } +} + +// The documented contract, pinned: a full 2^32 ms elapsing between two publishes is +// indistinguishable from no time passing, so the wrap is lost. This is why the main loop's +// per-iteration serviceMonotonic() matters - and it is now the only obligation, where before every +// reader had to participate. +void test_monotonic_misses_a_wrap_not_serviced_within_the_window() +{ + Time::setTestMillis(1000); + Time::serviceMonotonic(); + TEST_ASSERT_EQUAL_UINT64(1000u, Time::getMillisMonotonic()); + + Time::advanceTestMillis(0x80000000u); + advanceAndService(0x80000000u); // full cycle with no publish in between: low word is 1000 again + + TEST_ASSERT_EQUAL_UINT64(1000u, Time::getMillisMonotonic()); // the elapsed 2^32 ms is lost +} + +void test_getUptimeSecs_stays_exact_across_the_wrap() +{ + Time::setTestMillis(4294967000u); // 4294967 whole seconds, 296ms short of the wrap + Time::serviceMonotonic(); + TEST_ASSERT_EQUAL_UINT32(4294967u, Time::getUptimeSecs()); + + advanceAndService(1000); // crosses the wrap + TEST_ASSERT_EQUAL_UINT32(4294968u, Time::getUptimeSecs()); +} + +// --- concurrent readers --- + +// Readers run flat out while the clock is stepped across several wraps. Under the old accessor two +// readers interleaving inside the wrap window could each bump the counter, jumping every later +// reading 2^32 ms forward; here they only ever read, so the final value has to be exact. +// +// A one-instruction race is not something a test can hit on demand, so this is corroboration +// rather than the guarantee - the guarantee is structural, and test_monotonic_reads_do_not_advance +// _the_carry pins it. What this case does catch is any future change that puts a write back on the +// read path. +void test_monotonic_exact_with_concurrent_readers() +{ + constexpr int kReaders = 4; + constexpr int kWraps = 3; + constexpr uint32_t kStep = 0x40000000u; // quarter of a cycle, so each wrap is crossed mid-step + + Time::setTestMillis(0xFFFFF000u); + Time::serviceMonotonic(); + + std::atomic stop{false}; + std::atomic wentBackwards{false}; + std::vector readers; + for (int i = 0; i < kReaders; i++) { + readers.emplace_back([&stop, &wentBackwards]() { + uint64_t previous = 0; + while (!stop.load(std::memory_order_relaxed)) { + const uint64_t now = Time::getMillisMonotonic(); + if (now < previous) + wentBackwards.store(true, std::memory_order_relaxed); + previous = now; + } + }); + } + + uint64_t expected = 0xFFFFF000ull; + for (int i = 0; i < kWraps * 4; i++) { + advanceAndService(kStep); + expected += kStep; + } + + stop.store(true, std::memory_order_relaxed); + for (auto &reader : readers) + reader.join(); + + TEST_ASSERT_FALSE_MESSAGE(wentBackwards.load(std::memory_order_relaxed), "monotonic clock retreated for a reader"); + TEST_ASSERT_EQUAL_UINT64(expected, Time::getMillisMonotonic()); +} + +// nRF BLE callbacks run above the main loop. A reader that preempts publication must be able to +// consume the previous complete snapshot without waiting for the suspended writer. +void test_monotonic_reader_completes_while_publish_is_paused() +{ + Time::setTestMillis(100); + Time::serviceMonotonic(); + Time::advanceTestMillis(1); + + publishPaused.store(false, std::memory_order_relaxed); + releasePublish.store(false, std::memory_order_relaxed); + Time::setMonotonicPublishHookForTests(pauseMonotonicPublish); + + std::thread writer([]() { Time::serviceMonotonic(); }); + while (!publishPaused.load(std::memory_order_acquire)) + std::this_thread::yield(); + + std::atomic readerStarted{false}; + std::atomic readerDone{false}; + uint64_t readerValue = 0; + std::thread reader([&readerStarted, &readerDone, &readerValue]() { + readerStarted.store(true, std::memory_order_release); + readerValue = Time::getMillisMonotonic(); + readerDone.store(true, std::memory_order_release); + }); + while (!readerStarted.load(std::memory_order_acquire)) + std::this_thread::yield(); + const auto deadline = std::chrono::steady_clock::now() + std::chrono::milliseconds(100); + while (!readerDone.load(std::memory_order_acquire) && std::chrono::steady_clock::now() < deadline) + std::this_thread::yield(); + const bool completedWhilePaused = readerDone.load(std::memory_order_acquire); + + releasePublish.store(true, std::memory_order_release); + writer.join(); + reader.join(); + Time::setMonotonicPublishHookForTests(nullptr); + + TEST_ASSERT_TRUE_MESSAGE(completedWhilePaused, "reader waited for a lower-priority publisher"); + TEST_ASSERT_EQUAL_UINT64(101u, readerValue); +} + +// --- getTime(): the wall clock must not retreat at the millis() wrap --- + +// Epoch used by the wall-clock cases; must sit between BUILD_EPOCH (stamped at build time) and +// BUILD_EPOCH + 40 years or perhapsSetRTC() rejects it as implausible - so derive it. +#ifdef BUILD_EPOCH +static constexpr uint32_t kTestEpoch = (uint32_t)BUILD_EPOCH + 3600; +#else +static constexpr uint32_t kTestEpoch = 1800000000u; +#endif + +void test_getTime_stays_exact_across_the_wrap() +{ + resetRTCStateForTests(); + Time::setTestMillis(0xFFFFFF00u); // 256ms short of the wrap + Time::serviceMonotonic(); + + struct timeval tv = {}; + tv.tv_sec = kTestEpoch; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &tv)); + TEST_ASSERT_EQUAL_UINT32(kTestEpoch, getTime(false)); + + advanceAndService(400u * 1000u); // crosses the wrap partway through + // With a 32-bit anchor this read came back 49.7 days in the past. + TEST_ASSERT_EQUAL_UINT32(kTestEpoch + 400, getTime(false)); +} + +// The anchor must also be correct when the time-set itself happens after a counted wrap, i.e. +// when the monotonic clock is already past 32-bit range. +void test_getTime_anchored_after_a_wrap_is_exact() +{ + resetRTCStateForTests(); + Time::setTestMillis(0xFFFFFF00u); + Time::serviceMonotonic(); // latch the pre-wrap value + advanceAndService(0x200u); // cross the wrap; monotonic is now > 2^32 + + struct timeval tv = {}; + tv.tv_sec = kTestEpoch; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &tv)); + + advanceAndService(100u * 1000u); + TEST_ASSERT_EQUAL_UINT32(kTestEpoch + 100, getTime(false)); +} + +// A reader on another thread must not be able to perturb the wall clock. This is the user-visible +// shape of the race: getTime() is reached from the nRF52 BLE task and the portduino web server +// threads, and a double-counted wrap put every rx_time and last_heard ~49.7 days in the future. +void test_getTime_unaffected_by_concurrent_readers_across_the_wrap() +{ + resetRTCStateForTests(); + Time::setTestMillis(0xFFFFF800u); // exactly 0x800 short of the wrap, so the first advance lands on it + Time::serviceMonotonic(); + + struct timeval tv = {}; + tv.tv_sec = kTestEpoch; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &tv)); + + std::atomic stop{false}; + std::vector readers; + for (int i = 0; i < 4; i++) { + readers.emplace_back([&stop]() { + while (!stop.load(std::memory_order_relaxed)) + (void)getTime(false); // what the BLE / web-server threads actually call + }); + } + + advanceAndService(0x800u); // cross the wrap while the readers are running + advanceAndService(60u * 1000u); // and some ordinary time after it + + stop.store(true, std::memory_order_relaxed); + for (auto &reader : readers) + reader.join(); + + TEST_ASSERT_EQUAL_UINT32(kTestEpoch + 62, getTime(false)); // 0x800ms + 60s, rounded down +} + +// --- real clock fallback --- + +void test_real_clock_advances_when_not_injected() +{ + Time::useRealClock(); + uint32_t t0 = Time::getMillis(); + testDelay(5); + uint32_t t1 = Time::getMillis(); + TEST_ASSERT_TRUE(t1 >= t0); // real millis() is monotonic over a short delay +} + +void setup() +{ + initializeTestEnvironment(); + UNITY_BEGIN(); + RUN_TEST(test_getMillis_returns_injected_value); + RUN_TEST(test_advanceTestMillis_steps_clock); + RUN_TEST(test_advanceTestMillis_wraps_like_millis); + RUN_TEST(test_monotonic_matches_millis_before_any_wrap); + RUN_TEST(test_monotonic_counts_a_wrap); + RUN_TEST(test_monotonic_reader_crosses_the_wrap_without_a_publish); + RUN_TEST(test_monotonic_reads_do_not_advance_the_carry); + RUN_TEST(test_monotonic_counts_every_wrap_when_serviced_each_window); + RUN_TEST(test_monotonic_misses_a_wrap_not_serviced_within_the_window); + RUN_TEST(test_getUptimeSecs_stays_exact_across_the_wrap); + RUN_TEST(test_monotonic_exact_with_concurrent_readers); + RUN_TEST(test_monotonic_reader_completes_while_publish_is_paused); + RUN_TEST(test_getTime_stays_exact_across_the_wrap); + RUN_TEST(test_getTime_anchored_after_a_wrap_is_exact); + RUN_TEST(test_getTime_unaffected_by_concurrent_readers_across_the_wrap); + RUN_TEST(test_real_clock_advances_when_not_injected); + exit(UNITY_END()); +} + +void loop() {}