Monotonic time & prep for router graceful retirement

bin/run-tests.sh

@@ -0,0 +1,145 @@
+#!/usr/bin/env bash
+# Run native PlatformIO unit tests and emit a single, unambiguous RED/AMBER/GREEN verdict.
+#
+# Why this exists: PlatformIO reports failures three different ways ([FAILED], :FAIL:,
+# [ERRORED]) and an all-pass run prints "N succeeded" with NO "0 failed" clause — so naive
+# greps produce false greens (see .notes/test-passfail-filter.md). This script encodes the
+# correct logic once, and cross-checks the number of suites that actually ran against the
+# canonical set in test/ so a suite silently going missing shows up as AMBER, not green.
+#
+# Usage:
+#   ./bin/run-tests.sh                      # run all suites, full RAG + count cross-check
+#   ./bin/run-tests.sh -f test_utf8         # run one suite (no count cross-check)
+#   ./bin/run-tests.sh -e native            # override env (default: coverage)
+#   ./bin/run-tests.sh --quiet              # only print the final RESULT line
+#
+# Exit codes: 0 = GREEN, 1 = RED, 2 = AMBER.
+#
+# The final line is machine-readable, e.g.:
+#   RESULT: GREEN 19/19 suites passed
+#   RESULT: AMBER 17/19 suites ran (missing: test_radio test_serial) — all that ran passed
+#   RESULT: RED test_traffic_management: 1 failed  (or: build/crash error)
+
+set -uo pipefail
+
+SCRIPT_DIR="$(cd "$(dirname "$0")" && pwd)"
+ROOT_DIR="$(cd "$SCRIPT_DIR/.." && pwd)"
+cd "$ROOT_DIR"
+
+ENV="coverage"
+FILTER=""
+QUIET=false
+PASSTHRU=()
+
+while [[ $# -gt 0 ]]; do
+	case "$1" in
+	-f)
+		FILTER="$2"
+		PASSTHRU+=("-f" "$2")
+		shift 2
+		;;
+	-e)
+		ENV="$2"
+		shift 2
+		;;
+	--quiet)
+		QUIET=true
+		shift
+		;;
+	*)
+		PASSTHRU+=("$1")
+		shift
+		;;
+	esac
+done
+
+# Locate pio (PATH, then the standard PlatformIO venv).
+PIO="$(command -v pio || command -v platformio || echo "$HOME/.platformio/penv/bin/pio")"
+if [[ ! -x $PIO ]] && ! command -v "$PIO" >/dev/null 2>&1; then
+	echo "RESULT: RED pio not found (looked in PATH and ~/.platformio/penv/bin)"
+	exit 1
+fi
+
+LOG="$(mktemp -t meshtest.XXXXXX.log)"
+trap 'rm -f "$LOG"' EXIT
+
+# Canonical suite set = the directories in test/. This is the source of truth for
+# "what should run"; a filtered run only expects its filtered suite.
+mapfile -t ALL_SUITES < <(find test -maxdepth 1 -type d -name 'test_*' -printf '%f\n' | sort)
+EXPECTED_COUNT=${#ALL_SUITES[@]}
+
+if ! $QUIET; then
+	echo "Running: $PIO test -e $ENV ${PASSTHRU[*]-} (expecting $EXPECTED_COUNT suites)"
+fi
+
+# Run pio, tee to log. PIPESTATUS[0] is pio's real exit (NOT tee's).
+if $QUIET; then
+	"$PIO" test -e "$ENV" "${PASSTHRU[@]}" >"$LOG" 2>&1
+else
+	"$PIO" test -e "$ENV" "${PASSTHRU[@]}" 2>&1 | tee "$LOG"
+fi
+PIO_RC=${PIPESTATUS[0]}
+
+# --- Outcome detection -------------------------------------------------------
+# The SAME outcome is spelled differently depending on which layer emitted the line — this is
+# the trap that produces false greens (grepping ":PASS" misses pio's "[PASSED]", grepping
+# "[FAILED]" misses Unity's ":FAIL:"). So every regex below matches BOTH spellings:
+#   pass:  Unity per-assertion ":PASS"   | pio per-suite "[PASSED]"      | summary "N succeeded"
+#   fail:  Unity per-assertion ":FAIL:"  | pio per-suite "[FAILED]"      | summary "M failed"
+#   error: pio build/crash "[ERRORED]"   | Unity "M Failures"            | compiler "error:"
+# Match \b after :PASS/:FAIL so ":PASSED"/":FAILED" forms are also caught either way.
+FAIL_RE=':FAIL\b|\[FAILED\]|\[ERRORED\]|[1-9][0-9]* failed|[0-9]+ Tests [1-9][0-9]* Failures|error:|undefined reference|Segmentation fault|terminate called|SIGHUP|SIGSEGV|SIGABRT'
+# Positive proof tests actually ran & passed (absence != success). Accept any pass spelling:
+# the per-test/per-suite tokens OR a success summary line.
+PASS_RE=':PASS\b|\[PASSED\]|test cases: *[0-9]+ succeeded|[0-9]+ Tests 0 Failures'
+
+# Suites that produced a per-suite verdict. pio emits "coverage:test_x [PASSED|FAILED|ERRORED]";
+# a SKIPPED suite (hardware-only on native) is "accounted for" too, so it doesn't read as missing.
+mapfile -t RAN_SUITES < <(grep -oE "${ENV}:test_[a-z0-9_]+ \[(PASSED|FAILED|ERRORED)\]" "$LOG" |
+	sed -E "s/^${ENV}:(test_[a-z0-9_]+) .*/\1/" | sort -u)
+RAN_COUNT=${#RAN_SUITES[@]}
+# Suites pio explicitly skipped (don't count these as "missing" in the canonical cross-check).
+mapfile -t SKIPPED_SUITES < <(grep -oE "${ENV}:test_[a-z0-9_]+.*\bSKIPPED\b" "$LOG" |
+	grep -oE "test_[a-z0-9_]+" | sort -u)
+
+verdict_red() {
+	local detail
+	detail="$(grep -nE '\[FAILED\]|:FAIL:|\[ERRORED\]' "$LOG" | head -3 | sed 's/^/    /')"
+	echo ""
+	echo "RED — failures detected:"
+	[[ -n $detail ]] && echo "$detail"
+	grep -E 'test cases:' "$LOG" | tail -1 | sed 's/^/    /'
+	echo "RESULT: RED $(grep -oE '[0-9]+ failed' "$LOG" | tail -1 || echo 'build/crash error')"
+	exit 1
+}
+
+# RED: pio non-zero, any failure marker, or no positive summary at all (build died early).
+if [[ $PIO_RC -ne 0 ]] || grep -qE "$FAIL_RE" "$LOG"; then
+	verdict_red
+fi
+if ! grep -qE "$PASS_RE" "$LOG"; then
+	echo ""
+	echo "RESULT: RED no success summary found (build error / no tests ran?) — see log"
+	exit 1
+fi
+
+# AMBER: everything that ran passed, but (full run only) a canonical suite neither ran NOR was
+# explicitly skipped — i.e. it silently went missing. SKIPPED suites are accounted for.
+ACCOUNTED_COUNT=$((RAN_COUNT + ${#SKIPPED_SUITES[@]}))
+if [[ -z $FILTER && $ACCOUNTED_COUNT -lt $EXPECTED_COUNT ]]; then
+	missing=()
+	for s in "${ALL_SUITES[@]}"; do
+		printf '%s\n' "${RAN_SUITES[@]}" "${SKIPPED_SUITES[@]}" | grep -qx "$s" || missing+=("$s")
+	done
+	echo ""
+	echo "RESULT: AMBER ${RAN_COUNT}/${EXPECTED_COUNT} suites ran (missing: ${missing[*]}) — all that ran passed"
+	exit 2
+fi
+
+# GREEN.
+if [[ -n $FILTER ]]; then
+	echo "RESULT: GREEN ${RAN_COUNT} suite(s) passed (filtered: $FILTER)"
+else
+	echo "RESULT: GREEN ${RAN_COUNT}/${EXPECTED_COUNT} suites passed"
+fi
+exit 0

src/DebugConfiguration.cpp

@@ -191,7 +191,7 @@ inline bool Syslog::_sendLog(uint16_t pri, const char *appName, const char *mess
         this->_client->print(F(" "));
     }
     this->_client->print(F("["));
-    this->_client->print(int(millis() / 1000));
+    this->_client->print(int(Time::getMillis() / 1000));
     this->_client->print(F("]: "));
     this->_client->print(message);
     this->_client->endPacket();

src/GPSStatus.h

@@ -83,7 +83,7 @@ class GPSStatus : public Status
 
     uint32_t getNumSatellites() const { return p.sats_in_view; }
 
-    /// Return millis() when the last GPS fix occurred (0 = never)
+    /// Return Time::getMillis() when the last GPS fix occurred (0 = never)
     uint32_t getLastFixMillis() const { return lastFixMillis; }
 
     bool matches(const GPSStatus *newStatus) const
@@ -118,7 +118,7 @@ class GPSStatus : public Status
         if (isDirty) {
             if (hasLock) {
                 // Record time of last valid GPS fix
-                lastFixMillis = millis();
+                lastFixMillis = Time::getMillis();
 
                 // In debug logs, identify position by @timestamp:stage (stage 3 = notify)
                 LOG_DEBUG("New GPS pos@%x:3 lat=%f lon=%f alt=%d pdop=%.2f track=%.2f speed=%.2f sats=%d", p.timestamp,

src/MessageStore.cpp

@@ -70,7 +70,7 @@ static inline void assignTimestamp(StoredMessage &sm)
         sm.timestamp = nowSecs;
         sm.isBootRelative = false;
     } else {
-        sm.timestamp = millis() / 1000;
+        sm.timestamp = Time::getMillis() / 1000;
         sm.isBootRelative = true;
     }
 }
@@ -129,7 +129,7 @@ static inline void markMessageStoreUnsaved()
     g_messageStoreHasUnsavedChanges = true;
 
     if (g_lastAutoSaveMs == 0) {
-        g_lastAutoSaveMs = millis();
+        g_lastAutoSaveMs = Time::getMillis();
     }
 }
 
@@ -139,7 +139,7 @@ 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;
@@ -304,7 +304,7 @@ void MessageStore::saveToFlash()
 
     // Reset autosave state after any save
     g_messageStoreHasUnsavedChanges = false;
-    g_lastAutoSaveMs = millis();
+    g_lastAutoSaveMs = Time::getMillis();
 }
 
 void MessageStore::loadFromFlash()
@@ -338,7 +338,7 @@ void MessageStore::loadFromFlash()
 #endif
     // Loading messages does not trigger an autosave
     g_messageStoreHasUnsavedChanges = false;
-    g_lastAutoSaveMs = millis();
+    g_lastAutoSaveMs = Time::getMillis();
 }
 
 #else
@@ -362,7 +362,7 @@ void MessageStore::clearAllMessages()
 
 #if ENABLE_MESSAGE_PERSISTENCE
     g_messageStoreHasUnsavedChanges = false;
-    g_lastAutoSaveMs = millis();
+    g_lastAutoSaveMs = Time::getMillis();
 #endif
 }
 
@@ -470,7 +470,7 @@ void MessageStore::upgradeBootRelativeTimestamps()
     if (nowSecs == 0)
         return; // Still no valid RTC
 
-    uint32_t bootNow = millis() / 1000;
+    uint32_t bootNow = Time::getMillis() / 1000;
 
     auto fix = [&](std::deque<StoredMessage> &dq) {
         for (auto &m : dq) {

src/MessageStore.h

@@ -13,6 +13,7 @@
 #define ENABLE_MESSAGE_PERSISTENCE 1
 #endif
 
+#include "Time.h"
 #include "mesh/generated/meshtastic/mesh.pb.h"
 #include <cstdint>
 #include <deque>
@@ -65,7 +66,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::getMillis()/1000 fallback; false = epoch/RTC absolute
     AckStatus ackStatus;  // Delivery status (only meaningful for our own sent messages)
 
     // Text storage metadata — rebuilt from flash at boot

src/Power.cpp

@@ -425,7 +425,7 @@ class AnalogBatteryLevel : public HasBatteryLevel
         // Do not call analogRead() often.
         const uint32_t min_read_interval = 5000;
         if (!initial_read_done || !Throttle::isWithinTimespanMs(last_read_time_ms, min_read_interval)) {
-            last_read_time_ms = millis();
+            last_read_time_ms = Time::getMillis();
 
             uint32_t raw = 0;
             float scaled = 0;
@@ -803,12 +803,12 @@ bool Power::setup()
 
 void Power::powerCommandsCheck()
 {
-    if (rebootAtMsec && millis() > rebootAtMsec) {
+    if (rebootAtMsec && Time::getMillis() > rebootAtMsec) {
         LOG_INFO("Rebooting");
         reboot();
     }
 
-    if (shutdownAtMsec && millis() > shutdownAtMsec) {
+    if (shutdownAtMsec && Time::getMillis() > shutdownAtMsec) {
         shutdownAtMsec = 0;
         shutdown();
     }
@@ -960,7 +960,7 @@ void Power::readPowerStatus()
     if (hasBattery == OptTrue && !Throttle::isWithinTimespanMs(lastLogTime, 50 * 1000)) {
         LOG_DEBUG("Battery: usbPower=%d, isCharging=%d, batMv=%d, batPct=%d", powerStatus2.getHasUSB(),
                   powerStatus2.getIsCharging(), powerStatus2.getBatteryVoltageMv(), powerStatus2.getBatteryChargePercent());
-        lastLogTime = millis();
+        lastLogTime = Time::getMillis();
     }
     newStatus.notifyObservers(&powerStatus2);
 

src/PowerFSM.cpp

@@ -104,7 +104,7 @@ extern Power *power;
 static void shutdownEnter()
 {
     LOG_POWERFSM("State: SHUTDOWN");
-    shutdownAtMsec = millis();
+    shutdownAtMsec = Time::getMillis();
 }
 
 #include "error.h"

src/PowerFSMThread.h

@@ -27,11 +27,12 @@ class PowerFSMThread : public OSThread
         canSleep = (state != &statePOWER) && (state != &stateSERIAL);
 
         if (powerStatus->getHasUSB()) {
-            timeLastPowered = millis();
+            timeLastPowered = Time::getMillis();
         } 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
+                   Time::getMillis() >
+                       (timeLastPowered +
+                        Default::getConfiguredOrDefaultMs(
+                            config.power.on_battery_shutdown_after_secs))) { // shutdown after 30 minutes unpowered
             powerFSM.trigger(EVENT_SHUTDOWN);
         }
 

src/RedirectablePrint.cpp

@@ -137,27 +137,27 @@ void RedirectablePrint::log_to_serial(const char *logLevel, const char *format,
         if (color) {
             ::printf("\u001b[0m");
         }
-        ::printf("| %02d:%02d:%02d %u.%03u ", hour, min, sec, millis() / 1000, millis() % 1000);
+        ::printf("| %02d:%02d:%02d %u.%03u ", hour, min, sec, Time::getMillis() / 1000, Time::getMillis() % 1000);
 #else
         printf("%s ", logLevel);
         if (color) {
             printf("\u001b[0m");
         }
-        printf("| %02d:%02d:%02d %u ", hour, min, sec, millis() / 1000);
+        printf("| %02d:%02d:%02d %u ", hour, min, sec, Time::getMillis() / 1000);
 #endif
     } else {
 #ifdef ARCH_PORTDUINO
         ::printf("%s ", logLevel);
         if (color) {
             ::printf("\u001b[0m");
         }
-        ::printf("| ??:??:?? %u.%03u ", millis() / 1000, millis() % 1000);
+        ::printf("| ??:??:?? %u.%03u ", Time::getMillis() / 1000, Time::getMillis() % 1000);
 #else
         printf("%s ", logLevel);
         if (color) {
             printf("\u001b[0m");
         }
-        printf("| ??:??:?? %u ", millis() / 1000);
+        printf("| ??:??:?? %u ", Time::getMillis() / 1000);
 #endif
     }
     auto thread = concurrency::OSThread::currentThread;

src/SerialConsole.cpp

@@ -67,7 +67,7 @@ SerialConsole::SerialConsole() : StreamAPI(&Port), RedirectablePrint(&Port), con
     Port.begin(SERIAL_BAUD);
 #if defined(ARCH_NRF52) || defined(CONFIG_IDF_TARGET_ESP32S2) || defined(CONFIG_IDF_TARGET_ESP32S3) || defined(ARCH_RP2040) ||   \
     defined(CONFIG_IDF_TARGET_ESP32C3) || defined(CONFIG_IDF_TARGET_ESP32C6)
-    time_t timeout = millis();
+    time_t timeout = Time::getMillis();
     while (!Port) {
         if (Throttle::isWithinTimespanMs(timeout, FIVE_SECONDS_MS)) {
             delay(100);

src/Time.cpp

@@ -0,0 +1,32 @@
+/**
+ * @file Time.cpp
+ * @brief Monotonic uptime clock with test injection and a rollover-immune 64-bit form.
+ *
+ * getMillis() is a thin wrapper over the platform millis() (or the injected test clock).
+ * getMillis64() extends it to 64 bits with a software carry: it samples the 32-bit clock and
+ * bumps a high word each time the low word wraps. The sampler must be polled at least once per
+ * ~49.7-day wrap window to catch every wrap — trivially satisfied by normal device activity.
+ * It keeps mutable static state, so it is not ISR-safe (documented in Time.h).
+ */
+#include "Time.h"
+
+uint32_t Time::getMillis()
+{
+#ifdef PIO_UNIT_TESTING
+    if (Time::useTestClock)
+        return Time::testNowMs;
+#endif
+    return millis();
+}
+
+uint64_t Time::getMillis64()
+{
+    static uint32_t lastLow = 0;  // last 32-bit sample
+    static uint32_t highWord = 0; // number of observed wraps
+
+    uint32_t now = Time::getMillis();
+    if (now < lastLow)
+        highWord++; // low word wrapped since last call
+    lastLow = now;
+    return (static_cast<uint64_t>(highWord) << 32) | now;
+}