From 230da77642e4c7fa0df488909d89384b16c315b8 Mon Sep 17 00:00:00 2001 From: Ben Meadors Date: Thu, 13 Aug 2026 12:15:21 -0500 Subject: [PATCH] fix(time): convert the millis() rollover sites #11291's CI guard cannot see (#11483) * MeshPacketQueue: fix millis() rollover in the late-packet drop test replaceLowerPriorityPacket() read `backPacket->tx_after < now`, with `now` taken from millis() on the line above. tx_after is an absolute deadline, so that comparison inverts while the deadline sits on the far side of the 32-bit wrap: a queued late packet reads as not-yet-due for the rest of the wrap window, or every late packet reads as droppable at once. The same statement ordered two deadlines against each other with `backPacket->tx_after > p->tx_after`, which has the same problem. #11291 swept every site where millis() sits next to the comparison operator, and its CI guard matches that shape. Stashing the clock in a local first is the same bug written so the guard cannot see it. Both tests now subtract before comparing: the due test through Throttle::deadlinePassedAt(), and the ordering through the elapsed-since-now form already used in AdminModule's oldest-slot scan. The snapshot comes from Time::getMillis() so the deadlines and the test read one clock, per the convention deadlinePassedAt() documents. The `dt` the log line reports is now derived from the same elapsed value rather than recomputed. Behaviour is otherwise unchanged, save the boundary: deadlinePassedAt() is inclusive, so a deadline landing exactly on `now` reads as due rather than one millisecond early. Co-Authored-By: Claude Opus 5 * RadioLibInterface: don't widen a uint32_t deadline delta into a 64-bit long TRANSMIT_DELAY_COMPLETED tested whether the front packet was still waiting with long delay_remaining = txp->tx_after ? txp->tx_after - millis() : 0; if (delay_remaining > 0) ... The subtraction is uint32_t. Where long is 32-bit - every embedded target - an already-due deadline lands negative and the packet transmits, which is why this has never been visible on device. Where long is 64-bit (portduino, and the native test build) the same value zero-extends to ~4.29e9, reads as positive, and the packet is rescheduled 49.7 days out. It stays parked until some later notifyLater() with overwrite happens to reset the timer. That is not an edge case. notifyLater() schedules through setIntervalFromNow(), so the thread wakes at or after the deadline; being a millisecond past due is the ordinary path through this branch. Ask Throttle instead. deadlinePassedAt() is the unsigned half-range test, so there is no signed conversion to get wrong at any width, and the remaining delay handed to notifyLater() is computed from the same snapshot. On 32-bit the behaviour is identical, including at the boundary: a deadline equal to now transmitted before and still does. Co-Authored-By: Claude Opus 5 * ExpressLRSFiveWay: convert the two remaining raw window checks to Throttle runOnce() dismissed the alert frame with `now > alertingSinceMs + 2000` and chose its poll rate with `now < keyDownStart + 20000`, both against a millis() snapshot in a local. Same rollover inversion as any other naive compare, and invisible to the millis-deadline-check guard because millis() is not adjacent to the operator. update() in the same file was already on Throttle. hasElapsed()/isWithinTimespanMs() with the stored event give the full ~49.7 day range and need no snapshot. Sentinels are unchanged in meaning: `alerting` is the armed flag for alertingSinceMs and is tested first, and keyDownStart == 0 reads as "recent" for the first 20s of uptime exactly as `now < 0 + 20000` did - a poll rate either way. The arm sites move to Time::getMillis() so the writes land on the clock Throttle reads, which also puts them within reach of Time::setTestMillis(). Co-Authored-By: Claude Opus 5 * GPSUpdateScheduling: record whether a search is running, don't infer it elapsedSearchMs() answered "am I searching?" by ordering two raw millis() stamps: searchStartedMs > searchEndedMs. Whichever stamp lands on the far side of the 32-bit wrap reads as the larger one, so the answer inverts once per wrap cycle, in both directions: - a search that started before the wrap and ended after it keeps reading as "searching". elapsedSearchMs() then grows without bound and searchedTooLong() aborts a search that is not running. - a search that started after the wrap, following one that ended before it, reads as "idle". elapsedSearchMs() returns 0, so an unproductive search is never aborted and the receiver stays powered until it locks. Both self-heal at the next informSearching(), which bounds the damage to one GPS cycle - but the ordering test cannot be made wrap-correct, because the two stamps carry no information about which wrap they belong to. It does not need to be. Whether a search is in progress is a fact the three inform*() calls already have in hand; the ordering was only ever standing in for it. Add the flag and set it there. elapsedSearchMs() keeps its unsigned subtraction, which was always the correct part. The file's clock reads move to Time::getMillis() so the suite can drive them across the wrap. Behaviour-preserving in production - Time::getMillis() is millis() unless a test injects a clock. test_gps_update_scheduling/ gains seven cases: the idle/searching/ended states, elapsed exactness across the wrap, both inversion directions above, and reset(). The two wrap cases fail on the old predicate. Co-Authored-By: Claude Opus 5 * MessageStore: date boot-relative messages in uptime seconds A message received before the wall clock is trustworthy is stamped boot-relative and healed by upgradeBootRelativeTimestamps() once the RTC arrives. Both the stamp and the "same boot?" test were millis() / 1000, which wraps every 49.7 days: a stamp taken before the wrap reads as newer than `bootNow` afterwards, so `m.timestamp <= bootNow` declines to heal it and the message shows "???" until it ages out. MessageRenderer's own copy of the test falls the same way and prints invalidTime. Neither produces a wrong time - the guard is what fails safe - but Time::getUptimeSecs() landed in #11291 for exactly this, and does not wrap for 136 years. Both sites take it, which makes the comparison exact rather than merely fail-safe. While here, the autosave tick had its own hand-rolled deadline helper - `reachedMs(now, target)` as `(int32_t)(now - target) >= 0`. Wrap-correct, but a competing idiom for what Throttle::isWithinTimespanMs() already answers, and the signed cast is the form #11291 replaced everywhere else. Deleted; the stamps read Time::getMillis() so the whole path is on one clock. Co-Authored-By: Claude Opus 5 * WebServer: drop the hand-rolled millis() wrap branch getAdaptiveInterval() special-cased the wrap by hand: if (currentTime >= lastActivityTime) timeSinceActivity = currentTime - lastActivityTime; else timeSinceActivity = (UINT32_MAX - lastActivityTime) + currentTime + 1; Those two expressions are the same number - unsigned subtraction already computes the difference modulo 2^32 - so this is not a bug, just eight lines reimplementing what Throttle does. It also reads like a site that has thought about the wrap and settled it, which makes it a bad example to copy. Two isWithinTimespanMs() calls against the stored activity stamp, matching ethApiServer's shape for the same adaptive-interval decision. The stamps move to Time::getMillis() so the writes and the reads share a clock. Co-Authored-By: Claude Opus 5 * MeshPacketQueue: only order elapsed times once both deadlines have passed The late-packet eviction I rewrote compared how long ago each deadline passed: backElapsed < (uint32_t)(now - p->tx_after) That is only an ordering when both deadlines are in the past. An incoming packet whose tx_after is still in the future subtracts to a near-2^32 elapsed, which reads as the most overdue packet in the queue rather than the least - so a full queue would drop the overdue packet it was about to transmit in favour of one that is not ready yet. The comparison it replaced, `backPacket->tx_after > p->tx_after`, got this right away from the wrap; I lost it in the conversion. Classify before ordering: p->tx_after must be unset, or passed, before its elapsed time means anything. Two expired deadlines still order by which is further overdue, which is what the branch is for. Caught by CodeRabbit on #11483. test/test_meshpacket_queue/ pins the branch: the future-dated arrival that started this, both directions of the both-expired ordering, the undelayed arrival, and all of it again with the deadlines and `now` on opposite sides of the wrap. maxLen is 1 so the suite reaches the branch without dragging in CompareMeshPacketFunc and a NodeDB. Co-Authored-By: Claude Opus 5 * ExpressLRSFiveWay: treat "no key pressed yet" as no activity keyDownStart is 0 until the first press of a boot, and the fast-poll window read that as a press at time zero: 100ms polling for the first 20s of uptime with no activity at all, re-triggering once per millis() wrap. The arithmetic this replaced (`now < keyDownStart + 20000`) did the same, so it is not a regression - but the sentinel is exactly what the conventions say to test before the elapsed comparison, and "has there been recent key activity" has an honest answer here. 250ms is the documented floor for not missing presses, so an idle node simply starts there and moves to 100ms on the first press. Also trims the wrap-cases comment in test_gps_update_scheduling to the two-line house limit. Both from CodeRabbit review on #11483. Co-Authored-By: Claude Opus 5 --------- Co-authored-by: Claude Opus 5 --- src/MessageStore.cpp | 25 ++- src/MessageStore.h | 2 +- src/gps/GPSUpdateScheduling.cpp | 24 +-- src/gps/GPSUpdateScheduling.h | 1 + src/graphics/draw/MessageRenderer.cpp | 3 +- src/input/ExpressLRSFiveWay.cpp | 17 +- src/mesh/MeshPacketQueue.cpp | 13 +- src/mesh/RadioLibInterface.cpp | 9 +- src/mesh/http/WebServer.cpp | 18 +- test/test_gps_update_scheduling/test_main.cpp | 104 ++++++++++- test/test_meshpacket_queue/test_main.cpp | 164 ++++++++++++++++++ 11 files changed, 326 insertions(+), 54 deletions(-) create mode 100644 test/test_meshpacket_queue/test_main.cpp diff --git a/src/MessageStore.cpp b/src/MessageStore.cpp index 913a40c45..cca57acb0 100644 --- a/src/MessageStore.cpp +++ b/src/MessageStore.cpp @@ -5,6 +5,8 @@ #include "NodeDB.h" #include "SPILock.h" #include "SafeFile.h" +#include "Throttle.h" +#include "UptimeClock.h" #include "gps/RTC.h" #include "memory/MemAudit.h" #include // memcpy @@ -86,7 +88,9 @@ static inline void assignTimestamp(StoredMessage &sm) sm.timestamp = nowSecs; sm.isBootRelative = false; } else { - sm.timestamp = millis() / 1000; + // Uptime seconds, not millis()/1000: a stamp taken before the 32-bit wrap otherwise reads as + // newer than "now" afterwards, and upgradeBootRelativeTimestamps() then declines to heal it. + sm.timestamp = Time::getUptimeSecs(); sm.isBootRelative = true; } } @@ -134,18 +138,13 @@ static inline uint32_t autosaveIntervalMs() return sec * 1000UL; } -static inline bool reachedMs(uint32_t now, uint32_t target) -{ - return (int32_t)(now - target) >= 0; -} - // Mark new messages in RAM that need to be saved later static inline void markMessageStoreUnsaved() { g_messageStoreHasUnsavedChanges = true; if (g_lastAutoSaveMs == 0) { - g_lastAutoSaveMs = millis(); + g_lastAutoSaveMs = Time::getMillis(); } } @@ -155,14 +154,14 @@ static inline void autosaveTick(MessageStore *store) if (!store) return; - uint32_t now = millis(); + uint32_t now = Time::getMillis(); if (g_lastAutoSaveMs == 0) { g_lastAutoSaveMs = now; return; } - if (!reachedMs(now, g_lastAutoSaveMs + autosaveIntervalMs())) + if (Throttle::isWithinTimespanMs(g_lastAutoSaveMs, autosaveIntervalMs())) return; // Autosave interval reached, only save if there are unsaved messages. @@ -340,7 +339,7 @@ void MessageStore::saveToFlash() // Reset autosave state after any save g_messageStoreHasUnsavedChanges = false; - g_lastAutoSaveMs = millis(); + g_lastAutoSaveMs = Time::getMillis(); } void MessageStore::loadFromFlash() @@ -379,7 +378,7 @@ void MessageStore::loadFromFlash() #endif // Loading messages does not trigger an autosave g_messageStoreHasUnsavedChanges = false; - g_lastAutoSaveMs = millis(); + g_lastAutoSaveMs = Time::getMillis(); } #else @@ -410,7 +409,7 @@ void MessageStore::clearAllMessages() #if ENABLE_MESSAGE_PERSISTENCE g_messageStoreHasUnsavedChanges = false; - g_lastAutoSaveMs = millis(); + g_lastAutoSaveMs = Time::getMillis(); #endif } @@ -548,7 +547,7 @@ void MessageStore::upgradeBootRelativeTimestamps() if (nowSecs == 0) return; // Still no valid RTC - uint32_t bootNow = millis() / 1000; + uint32_t bootNow = Time::getUptimeSecs(); auto fix = [&](std::deque &dq) { for (auto &m : dq) { diff --git a/src/MessageStore.h b/src/MessageStore.h index 366c1a37d..dfc8673e7 100644 --- a/src/MessageStore.h +++ b/src/MessageStore.h @@ -67,7 +67,7 @@ struct StoredMessage { uint8_t channelIndex; // Channel index used uint32_t dest; // Destination node (broadcast or direct) MessageType type; // Derived from dest (explicit classification) - bool isBootRelative; // true = millis()/1000 fallback; false = epoch/RTC absolute + bool isBootRelative; // true = Time::getUptimeSecs() fallback; false = epoch/RTC absolute AckStatus ackStatus; // Delivery status (only meaningful for our own sent messages) // Text storage metadata - rebuilt from flash at boot diff --git a/src/gps/GPSUpdateScheduling.cpp b/src/gps/GPSUpdateScheduling.cpp index fe2c3ae78..7f37e100c 100644 --- a/src/gps/GPSUpdateScheduling.cpp +++ b/src/gps/GPSUpdateScheduling.cpp @@ -1,6 +1,7 @@ #include "GPSUpdateScheduling.h" #include "Default.h" +#include "UptimeClock.h" // Sampled from the original `2750 * seconds^1.22` curve. Interpolation tracks it within 0.6% for // inputs >=10s and 1.7% below that; the 1s/2s/3s points keep the convex first segment from @@ -30,14 +31,16 @@ uint32_t gpsHardsleepThresholdMs(uint32_t predictedSearchSecs) // Mark the time when searching for GPS position begins void GPSUpdateScheduling::informSearching() { - searchStartedMs = millis(); + searching = true; + searchStartedMs = Time::getMillis(); } // Mark the time when searching for GPS is complete, // then update the predicted lock-time void GPSUpdateScheduling::informGotLock() { - searchEndedMs = millis(); + searching = false; + searchEndedMs = Time::getMillis(); LOG_DEBUG("Took %us to get lock", (searchEndedMs - searchStartedMs) / 1000); updateLockTimePrediction(); consecutiveFailures = 0; // Drop back to fast cadence as soon as we acquire any fix @@ -49,7 +52,8 @@ void GPSUpdateScheduling::informGotLock() // down() to fall into GPS_IDLE, leaving the chip awake on subsequent indoor cycles. void GPSUpdateScheduling::informSearchFailed() { - searchEndedMs = millis(); + searching = false; + searchEndedMs = Time::getMillis(); consecutiveFailures++; LOG_DEBUG("GPS search ended without fix after %us (consecutive failures: %u)", (searchEndedMs - searchStartedMs) / 1000, consecutiveFailures); @@ -59,6 +63,7 @@ void GPSUpdateScheduling::informSearchFailed() // When re-enabling GPS with user button. void GPSUpdateScheduling::reset() { + searching = false; searchStartedMs = 0; searchEndedMs = 0; searchCount = 0; @@ -70,7 +75,7 @@ void GPSUpdateScheduling::reset() // Used by GPS hardware directly, to enter timed hardware sleep uint32_t GPSUpdateScheduling::msUntilNextSearch() { - uint32_t now = millis(); + uint32_t now = Time::getMillis(); // Target interval (seconds), between GPS updates uint32_t updateInterval = Default::getConfiguredOrDefaultMs(config.position.gps_update_interval, default_gps_update_interval); @@ -105,13 +110,12 @@ uint32_t GPSUpdateScheduling::msUntilNextSearch() // Used to abort a search in progress, if it runs unacceptably long uint32_t GPSUpdateScheduling::elapsedSearchMs() { - // If searching - if (searchStartedMs > searchEndedMs) - return millis() - searchStartedMs; + // Recorded, not inferred from searchStartedMs > searchEndedMs: ordering two stamps inverts + // across the 32-bit wrap, and the inform*() calls already know which state we are in. + if (!searching) + return 0; // Not searching. We shouldn't really consume this value - // If not searching - 0ms. We shouldn't really consume this value - else - return 0; + return Time::getMillis() - searchStartedMs; } // Is it now time to begin searching for a GPS position? diff --git a/src/gps/GPSUpdateScheduling.h b/src/gps/GPSUpdateScheduling.h index d7609d704..d7e11ad1a 100644 --- a/src/gps/GPSUpdateScheduling.h +++ b/src/gps/GPSUpdateScheduling.h @@ -25,6 +25,7 @@ class GPSUpdateScheduling private: void updateLockTimePrediction(); // Called from informGotLock + bool searching = false; // Set by the inform*() calls; never inferred from stamp ordering uint32_t searchStartedMs = 0; uint32_t searchEndedMs = 0; uint32_t searchCount = 0; diff --git a/src/graphics/draw/MessageRenderer.cpp b/src/graphics/draw/MessageRenderer.cpp index 05a283b8f..1b2372917 100644 --- a/src/graphics/draw/MessageRenderer.cpp +++ b/src/graphics/draw/MessageRenderer.cpp @@ -6,6 +6,7 @@ #include "MessageStore.h" #include "NodeDB.h" #include "UIRenderer.h" +#include "UptimeClock.h" #include "gps/RTC.h" #include "graphics/EmoteRenderer.h" #include "graphics/Screen.h" @@ -571,7 +572,7 @@ void drawTextMessageFrame(OLEDDisplay *display, OLEDDisplayUiState *state, int16 } } else if (m.timestamp > 0 && nowSecs == 0) { // RTC not valid: only trust boot-relative if same boot - uint32_t bootNow = millis() / 1000; + uint32_t bootNow = Time::getUptimeSecs(); if (m.isBootRelative && m.timestamp <= bootNow) { seconds = bootNow - m.timestamp; invalidTime = false; diff --git a/src/input/ExpressLRSFiveWay.cpp b/src/input/ExpressLRSFiveWay.cpp index 01712ad2a..e9efeda52 100644 --- a/src/input/ExpressLRSFiveWay.cpp +++ b/src/input/ExpressLRSFiveWay.cpp @@ -1,5 +1,6 @@ #include "ExpressLRSFiveWay.h" #include "Throttle.h" +#include "UptimeClock.h" #ifdef INPUTBROKER_EXPRESSLRSFIVEWAY_TYPE @@ -79,7 +80,7 @@ void ExpressLRSFiveWay::update(int *keyValue, bool *keyLongPressed) if (keyInProcess == NO_PRESS) { // New key down if (newKey != NO_PRESS) { - keyDownStart = millis(); + keyDownStart = Time::getMillis(); // DBGLN("down=%u", newKey); } } else { @@ -114,11 +115,10 @@ void ExpressLRSFiveWay::update(int *keyValue, bool *keyLongPressed) // Meshtastic: runs at regular intervals int32_t ExpressLRSFiveWay::runOnce() { - uint32_t now = millis(); - // Dismiss any alert frames after 2 seconds // Feedback for GPS toggle / adhoc ping - if (alerting && now > alertingSinceMs + 2000) { + // `alerting` is the armed flag, so alertingSinceMs never reaches the comparison unarmed. + if (alerting && Throttle::hasElapsed(alertingSinceMs, 2000)) { alerting = false; screen->endAlert(); } @@ -131,8 +131,9 @@ int32_t ExpressLRSFiveWay::runOnce() // Do something about this key press determineAction((KeyType)keyValue, longPressed ? LONG : SHORT); - // If there has been recent key activity, poll the joystick slightly more frequently - if (now < keyDownStart + (20 * 1000UL)) // Within last 20 seconds + // If there has been recent key activity, poll the joystick slightly more frequently. keyDownStart + // is 0 until the first press of a boot, which is no activity rather than activity at time zero. + if (keyDownStart != 0 && Throttle::isWithinTimespanMs(keyDownStart, 20 * 1000UL)) // Within last 20 seconds return 100; // Otherwise, poll slightly less often @@ -203,7 +204,7 @@ void ExpressLRSFiveWay::toggleGPS() gps->toggleGpsMode(); screen->startAlert("GPS Toggled"); alerting = true; - alertingSinceMs = millis(); + alertingSinceMs = Time::getMillis(); } #endif } @@ -226,7 +227,7 @@ void ExpressLRSFiveWay::sendAdhocPing() }); alerting = true; - alertingSinceMs = millis(); + alertingSinceMs = Time::getMillis(); } // Shutdown the node (enter deep-sleep) diff --git a/src/mesh/MeshPacketQueue.cpp b/src/mesh/MeshPacketQueue.cpp index 4aad40c69..58e9cf0bf 100644 --- a/src/mesh/MeshPacketQueue.cpp +++ b/src/mesh/MeshPacketQueue.cpp @@ -1,5 +1,7 @@ #include "MeshPacketQueue.h" #include "NodeDB.h" +#include "Throttle.h" +#include "UptimeClock.h" #include "configuration.h" #include @@ -186,9 +188,14 @@ bool MeshPacketQueue::replaceLowerPriorityPacket(meshtastic_MeshPacket *p) if (backPacket->tx_after) { // Check if there's a late packet at the queue end - auto now = millis(); - if (backPacket->tx_after < now && (!p->tx_after || backPacket->tx_after > p->tx_after)) { - int32_t dt = (int32_t)(backPacket->tx_after - now); + const uint32_t now = Time::getMillis(); + // Elapsed times only order two deadlines that have both passed: a future one subtracts to a + // near-2^32 elapsed and would read as the most overdue packet in the queue. + const uint32_t backElapsed = now - backPacket->tx_after; + const bool newGoesFirst = + !p->tx_after || (Throttle::deadlinePassedAt(now, p->tx_after) && backElapsed < (uint32_t)(now - p->tx_after)); + if (Throttle::deadlinePassedAt(now, backPacket->tx_after) && newGoesFirst) { + int32_t dt = -(int32_t)backElapsed; if (p->tx_after) { LOG_WARN("Dropping late packet 0x%08x with TX delay %dms to make room in the TX queue for packet 0x%08x with " "TX delay %ums", diff --git a/src/mesh/RadioLibInterface.cpp b/src/mesh/RadioLibInterface.cpp index a826a5131..195a5738a 100644 --- a/src/mesh/RadioLibInterface.cpp +++ b/src/mesh/RadioLibInterface.cpp @@ -4,6 +4,7 @@ #include "PowerMon.h" #include "SPILock.h" #include "Throttle.h" +#include "UptimeClock.h" #include "configuration.h" #include "error.h" #include "main.h" @@ -436,10 +437,12 @@ void RadioLibInterface::onNotify(uint32_t notification) } else { meshtastic_MeshPacket *txp = txQueue.getFront(); assert(txp); - long delay_remaining = txp->tx_after ? txp->tx_after - millis() : 0; - if (delay_remaining > 0) { + const uint32_t now = Time::getMillis(); + // Not `long remaining = tx_after - millis()`: that uint32_t subtraction widens to + // ~4.29e9 where long is 64-bit (portduino), rescheduling a due packet ~49.7 days out. + if (txp->tx_after && !Throttle::deadlinePassedAt(now, txp->tx_after)) { // There's still some delay pending on this packet, so resume waiting for it to elapse - notifyLater(delay_remaining, TRANSMIT_DELAY_COMPLETED, txTimerOverwrite); + notifyLater(txp->tx_after - now, TRANSMIT_DELAY_COMPLETED, txTimerOverwrite); #if !MESHTASTIC_EXCLUDE_BEACON } else if (MeshBeaconModule::beaconTxConfigInvalid(txp)) { // The beacon's target radio config is invalid (bad preset/region, or an diff --git a/src/mesh/http/WebServer.cpp b/src/mesh/http/WebServer.cpp index 84ea8fea4..fd1be5378 100644 --- a/src/mesh/http/WebServer.cpp +++ b/src/mesh/http/WebServer.cpp @@ -1,6 +1,7 @@ #include "configuration.h" #if !MESHTASTIC_EXCLUDE_WEBSERVER #include "NodeDB.h" +#include "UptimeClock.h" #include "graphics/Screen.h" #include "main.h" #include "mesh/http/WebServer.h" @@ -191,28 +192,19 @@ WebServerThread::WebServerThread() : concurrency::OSThread("WebServer") if (!config.network.wifi_enabled && !config.network.eth_enabled) { disable(); } - lastActivityTime = millis(); + lastActivityTime = Time::getMillis(); } void WebServerThread::markActivity() { - lastActivityTime = millis(); + lastActivityTime = Time::getMillis(); } int32_t WebServerThread::getAdaptiveInterval() { - uint32_t currentTime = millis(); - uint32_t timeSinceActivity; - - if (currentTime >= lastActivityTime) { - timeSinceActivity = currentTime - lastActivityTime; - } else { - timeSinceActivity = (UINT32_MAX - lastActivityTime) + currentTime + 1; - } - - if (timeSinceActivity < ACTIVE_THRESHOLD_MS) { + if (Throttle::isWithinTimespanMs(lastActivityTime, ACTIVE_THRESHOLD_MS)) { return ACTIVE_INTERVAL_MS; - } else if (timeSinceActivity < MEDIUM_THRESHOLD_MS) { + } else if (Throttle::isWithinTimespanMs(lastActivityTime, MEDIUM_THRESHOLD_MS)) { return MEDIUM_INTERVAL_MS; } else { return IDLE_INTERVAL_MS; diff --git a/test/test_gps_update_scheduling/test_main.cpp b/test/test_gps_update_scheduling/test_main.cpp index 00c01c0f6..72efe8904 100644 --- a/test/test_gps_update_scheduling/test_main.cpp +++ b/test/test_gps_update_scheduling/test_main.cpp @@ -1,12 +1,19 @@ #include "Arduino.h" #include "TestUtil.h" +#include "UptimeClock.h" #include "gps/GPSUpdateScheduling.h" #include #include #include -void setUp(void) {} -void tearDown(void) {} +void setUp(void) +{ + Time::setTestMillis(0); +} +void tearDown(void) +{ + Time::useRealClock(); +} // Confirms gpsHardsleepThresholdMs()'s pow()-free lookup table tracks the original // `2750 * pow(seconds, 1.22)` curve closely. @@ -74,6 +81,92 @@ static void test_clamp_boundary(void) TEST_ASSERT_EQUAL_UINT32(gpsHardsleepThresholdMs(900), gpsHardsleepThresholdMs(901)); } +// elapsedSearchMs() across the 32-bit millis() wrap. Ordering the two raw stamps, as it used to, +// reports an idle receiver as searching or a searching one as idle, and searchedTooLong() acts on it. + +// A search that has not started yet reads as idle, not as a search of length millis(). +static void test_elapsed_is_zero_before_any_search(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(90 * 1000); + TEST_ASSERT_EQUAL_UINT32(0, s.elapsedSearchMs()); +} + +static void test_elapsed_tracks_the_clock_while_searching(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(10 * 1000); + s.informSearching(); + Time::advanceTestMillis(7 * 1000); + TEST_ASSERT_EQUAL_UINT32(7 * 1000, s.elapsedSearchMs()); +} + +static void test_elapsed_is_zero_once_the_search_ends(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(10 * 1000); + s.informSearching(); + Time::advanceTestMillis(7 * 1000); + s.informGotLock(); + Time::advanceTestMillis(60 * 1000); + TEST_ASSERT_EQUAL_UINT32(0, s.elapsedSearchMs()); + + s.informSearching(); + Time::advanceTestMillis(3 * 1000); + s.informSearchFailed(); + TEST_ASSERT_EQUAL_UINT32(0, s.elapsedSearchMs()); +} + +// Start before the wrap, still searching after it: elapsed must be the real 10s, not ~49.7 days. +static void test_elapsed_is_exact_across_the_wrap(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(0xFFFFF000u); + s.informSearching(); + Time::advanceTestMillis(0x1000u + 6 * 1000); // 4.096s to the wrap, then 6s past it + TEST_ASSERT_EQUAL_UINT32(0x1000u + 6 * 1000, s.elapsedSearchMs()); +} + +// The regression: started before the wrap, ended after it, so searchStartedMs > searchEndedMs. +// The receiver is idle and elapsed must say so. +static void test_search_ending_after_the_wrap_reads_as_idle(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(0xFFFFF000u); + s.informSearching(); + Time::advanceTestMillis(0x1000u + 2 * 1000); + s.informGotLock(); + // The stamps really are inverted: the search ended at a smaller millis() than it started at. + TEST_ASSERT_LESS_THAN_UINT32(0xFFFFF000u, Time::getMillis()); + Time::advanceTestMillis(30 * 60 * 1000); + TEST_ASSERT_EQUAL_UINT32(0, s.elapsedSearchMs()); +} + +// The mirror image: the previous search ended before the wrap, this one started after it, so +// searchStartedMs < searchEndedMs while a search is genuinely in progress. +static void test_search_starting_after_the_wrap_reads_as_searching(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(0xFFFFF000u); + s.informSearching(); + Time::advanceTestMillis(1000); + s.informGotLock(); + Time::advanceTestMillis(0x1000u); // over the wrap + s.informSearching(); + Time::advanceTestMillis(12 * 1000); + TEST_ASSERT_EQUAL_UINT32(12 * 1000, s.elapsedSearchMs()); +} + +static void test_reset_clears_the_search_state(void) +{ + GPSUpdateScheduling s; + Time::setTestMillis(10 * 1000); + s.informSearching(); + Time::advanceTestMillis(5 * 1000); + s.reset(); + TEST_ASSERT_EQUAL_UINT32(0, s.elapsedSearchMs()); +} + void setup() { delay(10); @@ -85,6 +178,13 @@ void setup() RUN_TEST(test_exact_at_table_breakpoints); RUN_TEST(test_clamps_above_table_range); RUN_TEST(test_clamp_boundary); + RUN_TEST(test_elapsed_is_zero_before_any_search); + RUN_TEST(test_elapsed_tracks_the_clock_while_searching); + RUN_TEST(test_elapsed_is_zero_once_the_search_ends); + RUN_TEST(test_elapsed_is_exact_across_the_wrap); + RUN_TEST(test_search_ending_after_the_wrap_reads_as_idle); + RUN_TEST(test_search_starting_after_the_wrap_reads_as_searching); + RUN_TEST(test_reset_clears_the_search_state); exit(UNITY_END()); } diff --git a/test/test_meshpacket_queue/test_main.cpp b/test/test_meshpacket_queue/test_main.cpp new file mode 100644 index 000000000..37709c004 --- /dev/null +++ b/test/test_meshpacket_queue/test_main.cpp @@ -0,0 +1,164 @@ +// Unit tests for MeshPacketQueue::replaceLowerPriorityPacket()'s late-packet branch - the one that +// evicts an overdue packet from a full queue to make room for a new arrival. +// +// tx_after is an absolute millis() deadline, so every decision here has to subtract before comparing +// or it inverts across the 32-bit wrap. The subtlety the cases below pin is that an *elapsed* time +// only orders two deadlines that have both passed: a deadline still in the future subtracts to a +// near-2^32 elapsed, which reads as the most overdue packet in the queue rather than the least. +// +// maxLen is 1 throughout. That is enough to reach the branch (any enqueue into a full queue goes +// through it) and it keeps CompareMeshPacketFunc out of the picture - std::upper_bound over an +// empty range never invokes the comparator, so the suite needs no NodeDB. + +#include "Arduino.h" +#include "TestUtil.h" +#include "UptimeClock.h" +#include "configuration.h" +#include "mesh/MeshPacketQueue.h" +#include "mesh/MeshTypes.h" +#include +#include + +namespace +{ + +// A packet that is only ever a queue occupant: id and tx_after are all the branch reads. +meshtastic_MeshPacket *makePacket(uint32_t id, uint32_t txAfter) +{ + meshtastic_MeshPacket *p = packetPool.allocZeroed(); + TEST_ASSERT_NOT_NULL(p); + p->id = id; + p->tx_after = txAfter; + p->priority = meshtastic_MeshPacket_Priority_DEFAULT; + return p; +} + +// Drains whatever is still queued back to the pool, so a failing case cannot starve a later one. +void drain(MeshPacketQueue &q) +{ + while (meshtastic_MeshPacket *p = q.dequeue()) + packetPool.release(p); +} + +} // namespace + +void setUp(void) +{ + Time::setTestMillis(0); +} +void tearDown(void) +{ + Time::useRealClock(); +} + +// The regression: the incoming packet is not due yet, so it must not displace an overdue one. +// `now - p->tx_after` underflows to ~49.7 days of "elapsed", which an unguarded comparison reads as +// the more urgent packet. +static void test_future_incoming_deadline_does_not_evict_an_overdue_packet(void) +{ + Time::setTestMillis(1000); + MeshPacketQueue q(1); + + meshtastic_MeshPacket *back = makePacket(0x1001, 900); // 100ms overdue + meshtastic_MeshPacket *fresh = makePacket(0x1002, 1100); // 100ms in the future + TEST_ASSERT_TRUE(q.enqueue(back)); + + TEST_ASSERT_FALSE(q.enqueue(fresh)); + TEST_ASSERT_EQUAL_HEX32(0x1001, q.getFront()->id); + + packetPool.release(fresh); + drain(q); +} + +// The ordering the branch does want: both deadlines have passed and the arrival is the more overdue +// of the two, so the queued packet gives up its slot. +static void test_more_overdue_incoming_packet_evicts_the_late_back_packet(void) +{ + Time::setTestMillis(1000); + MeshPacketQueue q(1); + + meshtastic_MeshPacket *back = makePacket(0x2001, 900); // 100ms overdue + meshtastic_MeshPacket *fresh = makePacket(0x2002, 800); // 200ms overdue + TEST_ASSERT_TRUE(q.enqueue(back)); + + TEST_ASSERT_TRUE(q.enqueue(fresh)); // back is released by the queue + TEST_ASSERT_EQUAL_HEX32(0x2002, q.getFront()->id); + + drain(q); +} + +// The other half of that ordering: a less overdue arrival leaves the queue alone. +static void test_less_overdue_incoming_packet_is_rejected(void) +{ + Time::setTestMillis(1000); + MeshPacketQueue q(1); + + meshtastic_MeshPacket *back = makePacket(0x3001, 800); // 200ms overdue + meshtastic_MeshPacket *fresh = makePacket(0x3002, 900); // 100ms overdue + TEST_ASSERT_TRUE(q.enqueue(back)); + + TEST_ASSERT_FALSE(q.enqueue(fresh)); + TEST_ASSERT_EQUAL_HEX32(0x3001, q.getFront()->id); + + packetPool.release(fresh); + drain(q); +} + +// An arrival with no TX delay at all always wins the slot from an overdue packet. +static void test_undelayed_incoming_packet_evicts_the_late_back_packet(void) +{ + Time::setTestMillis(1000); + MeshPacketQueue q(1); + + meshtastic_MeshPacket *back = makePacket(0x4001, 900); + meshtastic_MeshPacket *fresh = makePacket(0x4002, 0); // no tx_after + TEST_ASSERT_TRUE(q.enqueue(back)); + + TEST_ASSERT_TRUE(q.enqueue(fresh)); + TEST_ASSERT_EQUAL_HEX32(0x4002, q.getFront()->id); + + drain(q); +} + +// Both deadlines were set before the wrap and `now` is after it, so every raw comparison in the +// branch inverts. The decisions must come out the same as they do away from the boundary. +static void test_decisions_survive_the_millis_wrap(void) +{ + // 0xFFFFFF00 and 0xFFFFFE00 are 256ms and 512ms before the wrap; now is 256ms after it. + Time::setTestMillis(0x00000100); + MeshPacketQueue q(1); + + meshtastic_MeshPacket *back = makePacket(0x5001, 0xFFFFFF00); // 512ms overdue + meshtastic_MeshPacket *older = makePacket(0x5002, 0xFFFFFE00); // 768ms overdue + TEST_ASSERT_TRUE(q.enqueue(back)); + TEST_ASSERT_TRUE(q.enqueue(older)); + TEST_ASSERT_EQUAL_HEX32(0x5002, q.getFront()->id); + drain(q); + + // ...and a not-yet-due arrival still loses, with the deadline on the far side of the wrap. + MeshPacketQueue q2(1); + meshtastic_MeshPacket *back2 = makePacket(0x5003, 0xFFFFFF00); // 512ms overdue + meshtastic_MeshPacket *fresh = makePacket(0x5004, 0x00000300); // 512ms in the future + TEST_ASSERT_TRUE(q2.enqueue(back2)); + + TEST_ASSERT_FALSE(q2.enqueue(fresh)); + TEST_ASSERT_EQUAL_HEX32(0x5003, q2.getFront()->id); + + packetPool.release(fresh); + drain(q2); +} + +void setup() +{ + delay(10); + initializeTestEnvironment(); + UNITY_BEGIN(); + RUN_TEST(test_future_incoming_deadline_does_not_evict_an_overdue_packet); + RUN_TEST(test_more_overdue_incoming_packet_evicts_the_late_back_packet); + RUN_TEST(test_less_overdue_incoming_packet_is_rejected); + RUN_TEST(test_undelayed_incoming_packet_evicts_the_late_back_packet); + RUN_TEST(test_decisions_survive_the_millis_wrap); + exit(UNITY_END()); +} + +void loop() {}