From af117dac778d247084d75c22691e4990e560c70b Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 20:34:26 +0100 Subject: [PATCH 1/9] Add explicit presence for MeshPacket.rx_time (arrival time) rx_time is now proto3 optional with a has_rx_time presence bit, matching the rx_rssi treatment. A node with no GPS and no phone connected yet has no time source at all, so a bare 0 was indistinguishable from a genuine 1970-01-01 reading; downstream consumers (replay packets, JSON serialization) now check has_rx_time instead of the value. --- protobufs | 2 +- src/Time.cpp | 32 ++++++++++ src/Time.h | 61 +++++++++++++++++++ src/configuration.h | 4 ++ src/gps/RTC.cpp | 10 +++ src/mesh/MeshService.cpp | 54 +++++++++++++++- src/mesh/MeshService.h | 6 ++ src/mesh/NodeDB.cpp | 13 +++- src/mesh/PhoneAPI.cpp | 16 +++++ src/mesh/RadioInterface.cpp | 2 +- src/mesh/Router.cpp | 33 ++++++++-- src/mesh/generated/meshtastic/mesh.pb.h | 15 +++-- src/modules/MeshBeaconModule.cpp | 9 ++- src/modules/NodeInfoModule.cpp | 4 +- src/modules/StoreForwardModule.cpp | 9 +++ src/serialization/MeshPacketSerializer.cpp | 10 ++- .../test_meshpacket_serializer/test_helpers.h | 1 + test/test_traffic_management/test_main.cpp | 1 + 18 files changed, 264 insertions(+), 18 deletions(-) create mode 100644 src/Time.cpp create mode 100644 src/Time.h diff --git a/protobufs b/protobufs index 94cdec45ae7..cd290ba246f 160000 --- a/protobufs +++ b/protobufs @@ -1 +1 @@ -Subproject commit 94cdec45ae729650d5a1b0cea356cad12747983b +Subproject commit cd290ba246fb5130cb449055248f7e22c15bcafb diff --git a/src/Time.cpp b/src/Time.cpp new file mode 100644 index 00000000000..a955c31612a --- /dev/null +++ b/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(highWord) << 32) | now; +} diff --git a/src/Time.h b/src/Time.h new file mode 100644 index 00000000000..f447c0a0dbb --- /dev/null +++ b/src/Time.h @@ -0,0 +1,61 @@ +#pragma once +#ifndef _MT_TIME_H +#define _MT_TIME_H + +#include + +/** + * Monotonic uptime clock - the single seam for "milliseconds since boot". + * + * Why this exists: + * - Test injection: any unit test can drive a virtual timebase via setTestMillis() / + * advanceTestMillis() instead of sleeping real seconds. One seam for all suites - no + * per-module test clock (this replaces the ad-hoc HopScalingModule::s_testNowMs / + * TrafficManagementModule::clockMs patterns). + * - Rollover immunity: getMillis64() never wraps (uint32 millis() wraps at ~49.7 days, which + * routers/repeaters exceed). Use it for any "duration over days" logic. + * + * This is uptime, NOT wall-clock. For wall-clock seconds (RTC/GPS/NTP) use getTime() in + * src/gps/RTC.h - a separate axis that can jump and be unset. + * + * Hot/ISR paths use getMillis() (32-bit, a drop-in for millis(), rollover-safe only with the + * unsigned-subtraction idiom `(uint32_t)(now - then)`). getMillis64() keeps mutable static + * carry state and is NOT ISR-safe - call it from normal task context only. + * An interrupt landing mid-update of that state (a read-then-write with no locking) could tear + * it, corrupting the high word for every caller afterward, not just the interrupted one. + */ +namespace Time +{ +#ifdef PIO_UNIT_TESTING +// Test-only virtual clock. Default: OFF - getMillis() returns real millis() so suites that +// rely on real time are unaffected by the seam. A test opts in by calling setTestMillis(). +inline uint32_t testNowMs = 0; +inline bool useTestClock = false; + +inline void setTestMillis(uint32_t ms) +{ + testNowMs = ms; + useTestClock = true; +} +inline void advanceTestMillis(uint32_t deltaMs) +{ + testNowMs += deltaMs; + useTestClock = true; +} +// Restore real-clock behaviour (call in test tearDown if a suite mixes real and fake time). +inline void useRealClock() +{ + useTestClock = false; + testNowMs = 0; +} +#endif + +/// Milliseconds since boot, 32-bit (wraps ~49.7 days). Drop-in for millis(). +uint32_t getMillis(); + +/// Milliseconds since boot, 64-bit, rollover-immune. Non-ISR use only. +uint64_t getMillis64(); + +} // namespace Time + +#endif diff --git a/src/configuration.h b/src/configuration.h index 672d8b6f190..059d53af2bd 100644 --- a/src/configuration.h +++ b/src/configuration.h @@ -26,6 +26,10 @@ along with this program. If not, see . #include +// Monotonic uptime clock seam (Time::getMillis / getMillis64). Hosted here so the whole +// codebase can use it without per-file includes; see src/Time.h. +#include "Time.h" + #if __has_include("Melopero_RV3028.h") #include "Melopero_RV3028.h" #endif diff --git a/src/gps/RTC.cpp b/src/gps/RTC.cpp index 94288529e16..24b4d1f01be 100644 --- a/src/gps/RTC.cpp +++ b/src/gps/RTC.cpp @@ -2,6 +2,7 @@ #include "configuration.h" #include "detect/ScanI2C.h" #include "main.h" +#include "mesh/MeshService.h" #include "modules/NodeInfoModule.h" #include #include @@ -17,12 +18,21 @@ uint32_t lastSetFromPhoneNtpOrGps = 0; static uint32_t lastTimeValidationWarning = 0; static const uint32_t TIME_VALIDATION_WARNING_INTERVAL_MS = 15000; // 15 seconds +// Despite the name, this now reacts to two distinct quality-crossing events sharing one call +// site: NodeInfo recheck on "we had no time source at all before" (unchanged), and rx_time +// reconciliation on "we just reached RTCQualityFromNet or better" (new) - see +// MeshService::reconcilePendingRxTimes(). The thresholds differ, so both checks are independent. static void triggerNodeInfoCheckOnTimeSource(RTCQuality oldQuality, RTCQuality newQuality) { if (oldQuality == RTCQualityNone && newQuality > RTCQualityNone && nodeInfoModule) { LOG_DEBUG("Time source acquired (%s -> %s), triggering NodeInfo recheck", RtcName(oldQuality), RtcName(newQuality)); nodeInfoModule->triggerImmediateNodeInfoCheck(); } + if (oldQuality < RTCQualityFromNet && newQuality >= RTCQualityFromNet && service) { + LOG_DEBUG("Time source reached net quality (%s -> %s), reconciling pending rx_time placeholders", RtcName(oldQuality), + RtcName(newQuality)); + service->reconcilePendingRxTimes(); + } } RTCQuality getRTCQuality() diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index 782b0dc73e0..272bd2c6d75 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -180,6 +180,36 @@ NodeNum MeshService::getNodenumFromRequestId(uint32_t request_id) return nodenum; } +// A packet stamped with has_rx_time == false is carrying a millis() snapshot from the moment it +// was received, not a wall-clock reading (see Router::dispatchReceived) - the device had no +// trustworthy time source yet, commonly because it has no GPS and the phone hadn't connected. +// Once the clock becomes trustworthy, back-calculate the real reception epoch from how much +// uptime has elapsed since that snapshot, rather than leaving the packet stuck presence-absent +// (or worse, silently wrong) for its remaining time in the queue. +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(); + + for (int i = 0; i < toPhoneQueue.numUsed(); i++) { + meshtastic_MeshPacket *p = toPhoneQueue.dequeuePtr(0); + if (!p->has_rx_time) { + // Unsigned subtraction is wraparound-safe across a getMillis() rollover, matching + // the idiom already used throughout this codebase for elapsed-time math. Note this + // is only 32-bit-safe even though Time::getMillis64() exists: rx_time is a 32-bit + // wire field, so the placeholder stashed at receipt (Router::dispatchReceived) was + // never more than a 32-bit snapshot to begin with - a 64-bit "now" here would have + // nothing wider to compare against. + const uint32_t elapsedMs = nowMillis - p->rx_time; + p->rx_time = nowEpoch - (elapsedMs / 1000); + p->has_rx_time = true; + } + toPhoneQueue.enqueue(p, 0); + } +} + #if MESHTASTIC_ENABLE_FRAME_INJECTION // Deliver a client-supplied frame into the receive pipeline as if it arrived off the LoRa chip. Mirrors // the portduino SimRadio SIMULATOR_APP unwrap so the same host wire format works on real hardware: the @@ -220,7 +250,14 @@ void MeshService::injectAsReceived(meshtastic_MeshPacket &p) mp->rx_rssi = -40; mp->has_rx_rssi = true; } - mp->rx_time = getValidTime(RTCQualityFromNet); + // rx_time has explicit presence: store a Time::getMillis() placeholder, not a literal 0, when + // we don't have a trustworthy wall clock yet (this packet re-enters the receive pipeline via + // enqueueReceivedMessage below, so Router::dispatchReceived will normally overwrite this + // anyway - but don't rely on that; a bare 0 would misdirect + // MeshService::reconcilePendingRxTimes() if it were ever read before that happens). + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + mp->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); + mp->has_rx_time = haveTime; LOG_INFO("inject: RX from=0x%08x to=0x%08x id=0x%08x ch=%d %s", mp->from, mp->to, mp->id, mp->channel, mp->which_payload_variant == meshtastic_MeshPacket_encrypted_tag ? "encrypted" : "decoded"); router->enqueueReceivedMessage(mp); @@ -258,7 +295,13 @@ void MeshService::handleToRadio(meshtastic_MeshPacket &p) if (p.id == 0) p.id = generatePacketId(); // If the phone didn't supply one, then pick one - p.rx_time = getValidTime(RTCQualityFromNet); // Record the time the packet arrived from the phone + // Record the time the packet arrived from the phone. rx_time has explicit presence: store a + // Time::getMillis() placeholder, not a literal 0, on the rare chance the phone connected + // without yet handing us net-quality time - a bare 0 would misdirect + // MeshService::reconcilePendingRxTimes() if this packet is later echoed into toPhoneQueue. + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + p.rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); + p.has_rx_time = haveTime; IF_SCREEN(if (p.decoded.portnum == meshtastic_PortNum_TEXT_MESSAGE_APP && p.decoded.payload.size > 0 && p.to != NODENUM_BROADCAST && p.to != 0) // DM only @@ -595,6 +638,13 @@ bool MeshService::isToPhoneQueueEmpty() uint32_t MeshService::GetTimeSinceMeshPacket(const meshtastic_MeshPacket *mp) { + // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() + // placeholder rather than a wall-clock reading (see Router::dispatchReceived), which would + // otherwise subtract to a huge bogus "age" here instead of a negative one the clamp below + // would catch. + if (!mp->has_rx_time) + return 0; + uint32_t now = getTime(); uint32_t last_seen = mp->rx_time; diff --git a/src/mesh/MeshService.h b/src/mesh/MeshService.h index b529d283619..e35feca5dd8 100644 --- a/src/mesh/MeshService.h +++ b/src/mesh/MeshService.h @@ -137,6 +137,12 @@ 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 whose rx_time is still an unresolved millis() + // placeholder (has_rx_time == false, see Router::dispatchReceived) into a real epoch, now + // that the wall clock is trustworthy. Called from RTC.cpp the moment RTC quality crosses + // RTCQualityFromNet - typically, the phone just connected and told us the real time. + void reconcilePendingRxTimes(); + // Release QueueStatus packet to pool void releaseQueueStatusToPool(meshtastic_QueueStatus *p) { queueStatusPool.release(p); } diff --git a/src/mesh/NodeDB.cpp b/src/mesh/NodeDB.cpp index c7d139aaa34..9e3fc7e567b 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -3233,6 +3233,13 @@ uint32_t sinceLastSeen(const meshtastic_NodeInfoLite *n) uint32_t sinceReceived(const meshtastic_MeshPacket *p) { + // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() + // placeholder rather than a wall-clock reading (see Router::dispatchReceived), which would + // otherwise subtract to a huge bogus "age" here instead of a negative one the clamp below + // would catch. + if (!p->has_rx_time) + return 0; + uint32_t now = getTime(); int delta = (int)(now - p->rx_time); @@ -3629,7 +3636,11 @@ void NodeDB::updateFrom(const meshtastic_MeshPacket &mp) return; } - if (mp.rx_time) // if the packet has a valid timestamp use it to update our last_heard + // rx_time has explicit presence: a truthy-but-unknown rx_time is now possible (a millis() + // placeholder pending MeshService::reconcilePendingRxTimes()), so gate on has_rx_time, not + // truthiness - `if (mp.rx_time)` would otherwise stamp last_heard with a boot-relative + // millis() count rather than a real epoch. + if (mp.has_rx_time) info->last_heard = mp.rx_time; // Gate on the packet actually having been received over our own radio, not on rx_snr being diff --git a/src/mesh/PhoneAPI.cpp b/src/mesh/PhoneAPI.cpp index 75385f03fdd..5bea4fddf47 100644 --- a/src/mesh/PhoneAPI.cpp +++ b/src/mesh/PhoneAPI.cpp @@ -1258,6 +1258,10 @@ meshtastic_MeshPacket PhoneAPI::makeReplayPositionPacket(NodeNum num, const mesh // fix time (which is often 0 and, when present, already round-trips inside the payload // via ConvertToPosition). pkt.rx_time = header ? header->last_heard : 0; + // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only + // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a + // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + pkt.has_rx_time = (header && header->last_heard != 0); // Stable per-node/per-fix id: replaying the same unchanged history on every // reconnect must not look like a brand new packet to the phone's history/dedup. pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_PortNum_POSITION_APP); @@ -1285,6 +1289,10 @@ meshtastic_MeshPacket PhoneAPI::makeReplayTelemetryPacket(NodeNum num, const mes // No native timestamp on telemetry packets here; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; + // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only + // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a + // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_device_metrics_tag); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; @@ -1391,6 +1399,10 @@ meshtastic_MeshPacket PhoneAPI::makeReplayEnvironmentPacket(uint32_t num, const pkt.to = NODENUM_BROADCAST; const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; + // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only + // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a + // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_environment_metrics_tag); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; @@ -1456,6 +1468,10 @@ meshtastic_MeshPacket PhoneAPI::makeReplayStatusPacket(uint32_t num, const mesht // StatusMessage has no native timestamp; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; + // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only + // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a + // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_PortNum_NODE_STATUS_APP); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; diff --git a/src/mesh/RadioInterface.cpp b/src/mesh/RadioInterface.cpp index ec1b9c9cbce..9c199f5a7cd 100644 --- a/src/mesh/RadioInterface.cpp +++ b/src/mesh/RadioInterface.cpp @@ -877,7 +877,7 @@ void printPacket(const char *prefix, const meshtastic_MeshPacket *p) out += DEBUG_PORT.mt_sprintf(" len=%d", p->encrypted.size + sizeof(PacketHeader)); } - if (p->rx_time != 0) + if (p->has_rx_time) // rx_time has explicit presence; a millis() placeholder isn't a real reading to print out += DEBUG_PORT.mt_sprintf(" rxtime=%u", p->rx_time); if (p->rx_snr != 0.0) out += DEBUG_PORT.mt_sprintf(" rxSNR=%g", p->rx_snr); diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index 2ec9b43b313..c79694d21d5 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -280,8 +280,12 @@ meshtastic_MeshPacket *Router::allocForSending() p->to = NODENUM_BROADCAST; p->hop_limit = Default::getConfiguredOrDefaultHopLimit(config.lora.hop_limit); p->id = generatePacketId(); - p->rx_time = - getValidTime(RTCQualityFromNet); // Just in case we process the packet locally - make sure it has a valid timestamp + // Just in case we process the packet locally - make sure it has a timestamp. rx_time has + // explicit presence (see dispatchReceived): fall back to a Time::getMillis() placeholder, + // not a fabricated real-looking value, when we don't have a trustworthy wall clock yet. + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); + p->has_rx_time = haveTime; return p; } @@ -1307,10 +1311,22 @@ void Router::dispatchReceived(meshtastic_MeshPacket *p, RxSource src) // Also, we should set the time from the ISR and it should have msec level resolution. // Keep the decoded working packet and encrypted MQTT copy on the same local arrival timestamp. - const uint32_t rxTime = getValidTime(RTCQualityFromNet); + // + // rx_time has explicit presence. When we don't yet have a trustworthy wall clock (no GPS, + // and the phone hasn't connected/handed us net time yet), stash Time::getMillis() as a + // placeholder instead of a fabricated real-looking value - has_rx_time=false marks it as not + // yet known. MeshService::reconcilePendingRxTimes() rewrites any such placeholder still + // sitting in toPhoneQueue into a real epoch, backdated by elapsed uptime, the moment the + // clock becomes trustworthy. Any other reader of rx_time must check has_rx_time first - the + // raw value is meaningless (a monotonic snapshot, not a wall-clock reading) while it's false. + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + const uint32_t rxTime = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); p->rx_time = rxTime; - if (p_encrypted) + p->has_rx_time = haveTime; + if (p_encrypted) { p_encrypted->rx_time = rxTime; + p_encrypted->has_rx_time = haveTime; + } // Take those raw bytes and convert them back into a well structured protobuf we can understand auto decodedState = perhapsDecode(p); @@ -1443,7 +1459,14 @@ void Router::perhapsHandleReceived(meshtastic_MeshPacket *p) #if ARCH_PORTDUINO // Even ignored packets get logged in the trace if (portduino_config.traceFilename != "" || portduino_config.logoutputlevel == level_trace) { - p->rx_time = getValidTime(RTCQualityFromNet); // store the arrival timestamp for the phone + // store the arrival timestamp for the phone. rx_time has explicit presence: store a + // Time::getMillis() placeholder, not a literal 0, when the wall clock isn't trustworthy + // yet - this packet continues on through the rest of receive processing after the trace + // dump below, so a bare 0 here would carry the same reconcilePendingRxTimes() risk + // forward as every other rx_time write site. + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); + p->has_rx_time = haveTime; LOG_TRACE("%s", MeshPacketSerializer::JsonSerializeEncrypted(p).c_str()); } #endif diff --git a/src/mesh/generated/meshtastic/mesh.pb.h b/src/mesh/generated/meshtastic/mesh.pb.h index 637aae3ab86..60d817d734b 100644 --- a/src/mesh/generated/meshtastic/mesh.pb.h +++ b/src/mesh/generated/meshtastic/mesh.pb.h @@ -1079,7 +1079,14 @@ typedef struct _meshtastic_MeshPacket { /* The time this message was received by the esp32 (secs since 1970). Note: this field is _never_ sent on the radio link itself (to save space) Times are typically not sent over the mesh, but they will be added to any Packet - (chain of SubPacket) sent to the phone (so the phone can know exact time of reception) */ + (chain of SubPacket) sent to the phone (so the phone can know exact time of reception) + Explicit presence: firmware cannot always attach a trustworthy wall-clock timestamp at the + moment of reception - a node with no GPS and no phone connected yet has no time source at + all. has_rx_time disambiguates that state from a genuine (if coincidental) 1970-01-01 + reading. A packet delivered with this field absent may still be re-timestamped once a valid + clock becomes available, before the phone ever sees it - "absent" is not guaranteed + permanent, only "not yet known at last observation". */ + bool has_rx_time; uint32_t rx_time; /* *Never* sent over the radio links. Set during reception to indicate the SNR of this packet. @@ -1740,7 +1747,7 @@ extern "C" { #define meshtastic_Waypoint_init_default {0, false, 0, false, 0, 0, 0, "", "", 0, 0, false, meshtastic_BoundingBox_init_default, 0, 0, 0} #define meshtastic_StatusMessage_init_default {""} #define meshtastic_MqttClientProxyMessage_init_default {"", 0, {{0, {0}}}, 0} -#define meshtastic_MeshPacket_init_default {0, 0, 0, 0, {meshtastic_Data_init_default}, 0, 0, 0, 0, 0, _meshtastic_MeshPacket_Priority_MIN, false, 0, _meshtastic_MeshPacket_Delayed_MIN, 0, 0, {0, {0}}, 0, 0, 0, 0, _meshtastic_MeshPacket_TransportMechanism_MIN, 0} +#define meshtastic_MeshPacket_init_default {0, 0, 0, 0, {meshtastic_Data_init_default}, 0, false, 0, 0, 0, 0, _meshtastic_MeshPacket_Priority_MIN, false, 0, _meshtastic_MeshPacket_Delayed_MIN, 0, 0, {0, {0}}, 0, 0, 0, 0, _meshtastic_MeshPacket_TransportMechanism_MIN, 0} #define meshtastic_NodeInfo_init_default {0, false, meshtastic_User_init_default, false, meshtastic_Position_init_default, 0, 0, false, meshtastic_DeviceMetrics_init_default, 0, 0, false, 0, 0, 0, 0, 0, 0} #define meshtastic_MyNodeInfo_init_default {0, 0, 0, {0, {0}}, "", _meshtastic_FirmwareEdition_MIN, 0} #define meshtastic_LogRecord_init_default {"", 0, "", _meshtastic_LogRecord_Level_MIN} @@ -1779,7 +1786,7 @@ extern "C" { #define meshtastic_Waypoint_init_zero {0, false, 0, false, 0, 0, 0, "", "", 0, 0, false, meshtastic_BoundingBox_init_zero, 0, 0, 0} #define meshtastic_StatusMessage_init_zero {""} #define meshtastic_MqttClientProxyMessage_init_zero {"", 0, {{0, {0}}}, 0} -#define meshtastic_MeshPacket_init_zero {0, 0, 0, 0, {meshtastic_Data_init_zero}, 0, 0, 0, 0, 0, _meshtastic_MeshPacket_Priority_MIN, false, 0, _meshtastic_MeshPacket_Delayed_MIN, 0, 0, {0, {0}}, 0, 0, 0, 0, _meshtastic_MeshPacket_TransportMechanism_MIN, 0} +#define meshtastic_MeshPacket_init_zero {0, 0, 0, 0, {meshtastic_Data_init_zero}, 0, false, 0, 0, 0, 0, _meshtastic_MeshPacket_Priority_MIN, false, 0, _meshtastic_MeshPacket_Delayed_MIN, 0, 0, {0, {0}}, 0, 0, 0, 0, _meshtastic_MeshPacket_TransportMechanism_MIN, 0} #define meshtastic_NodeInfo_init_zero {0, false, meshtastic_User_init_zero, false, meshtastic_Position_init_zero, 0, 0, false, meshtastic_DeviceMetrics_init_zero, 0, 0, false, 0, 0, 0, 0, 0, 0} #define meshtastic_MyNodeInfo_init_zero {0, 0, 0, {0, {0}}, "", _meshtastic_FirmwareEdition_MIN, 0} #define meshtastic_LogRecord_init_zero {"", 0, "", _meshtastic_LogRecord_Level_MIN} @@ -2199,7 +2206,7 @@ X(a, STATIC, SINGULAR, UINT32, channel, 3) \ X(a, STATIC, ONEOF, MESSAGE, (payload_variant,decoded,decoded), 4) \ X(a, STATIC, ONEOF, BYTES, (payload_variant,encrypted,encrypted), 5) \ X(a, STATIC, SINGULAR, FIXED32, id, 6) \ -X(a, STATIC, SINGULAR, FIXED32, rx_time, 7) \ +X(a, STATIC, OPTIONAL, FIXED32, rx_time, 7) \ X(a, STATIC, SINGULAR, FLOAT, rx_snr, 8) \ X(a, STATIC, SINGULAR, UINT32, hop_limit, 9) \ X(a, STATIC, SINGULAR, BOOL, want_ack, 10) \ diff --git a/src/modules/MeshBeaconModule.cpp b/src/modules/MeshBeaconModule.cpp index 2e9d865a66e..2ec2d96de98 100644 --- a/src/modules/MeshBeaconModule.cpp +++ b/src/modules/MeshBeaconModule.cpp @@ -342,7 +342,14 @@ void MeshBeaconBroadcastModule::sendBeacon() p->hop_limit = 0; // all beacon packets are zero hopped to limit spamming. p->priority = meshtastic_MeshPacket_Priority_BACKGROUND; p->want_ack = false; - p->rx_time = getValidTime(RTCQualityFromNet); + // rx_time has explicit presence: store a Time::getMillis() placeholder, not a literal 0, + // when we don't have a trustworthy wall clock yet - a bare 0 here would later be + // mistaken by MeshService::reconcilePendingRxTimes() for a genuine monotonic snapshot + // if this packet is ever echoed back into toPhoneQueue, backdating it by our entire + // uptime instead of leaving it correctly unknown. + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); + p->has_rx_time = haveTime; }; // ── Packet type decisions ──────────────────────────────────────────────── diff --git a/src/modules/NodeInfoModule.cpp b/src/modules/NodeInfoModule.cpp index 5b8d4622395..1c4048c9012 100644 --- a/src/modules/NodeInfoModule.cpp +++ b/src/modules/NodeInfoModule.cpp @@ -33,7 +33,9 @@ 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); - const uint32_t now = mp.rx_time ? mp.rx_time : getTime(); + // has_rx_time, not truthiness: rx_time may hold a millis() placeholder (not a wall-clock + // reading) while has_rx_time is false - see Router::dispatchReceived. + const uint32_t now = mp.has_rx_time ? mp.rx_time : getTime(); auto it = lastNodeInfoSeen.find(sender); if (it != lastNodeInfoSeen.end()) { uint32_t sinceLast = now >= it->second ? now - it->second : 0; diff --git a/src/modules/StoreForwardModule.cpp b/src/modules/StoreForwardModule.cpp index 3c6d2de7dd6..c70666f3b7a 100644 --- a/src/modules/StoreForwardModule.cpp +++ b/src/modules/StoreForwardModule.cpp @@ -257,6 +257,15 @@ meshtastic_MeshPacket *StoreForwardModule::preparePayload(NodeNum dest, uint32_t p->channel = this->packetHistory[i].channel; p->decoded.reply_id = this->packetHistory[i].reply_id; p->rx_time = this->packetHistory[i].time; + // packetHistory[i].time was captured via getTime() at store time (StoreForwardModule.cpp + // ~line 195), which - unlike getValidTime(RTCQualityFromNet) - never hard-fails to 0; with + // no RTC source at all it silently returns a boot-relative seconds count instead. This + // module has no presence bit of its own to tell the two apart, and isn't covered by + // MeshService::reconcilePendingRxTimes() (a different buffer entirely), so this is only an + // approximation: assume the stored time is trustworthy iff our *current* clock is, since + // RTC quality monotonically improves and rarely regresses. A history entry stored while + // time-blind and never revisited will still under-report its age if quality later improves. + p->has_rx_time = (getRTCQuality() >= RTCQualityFromNet); p->decoded.emoji = (uint32_t)this->packetHistory[i].emoji; p->rx_rssi = this->packetHistory[i].rx_rssi; p->has_rx_rssi = true; // rx_rssi has explicit presence; the stored value was a genuine measurement diff --git a/src/serialization/MeshPacketSerializer.cpp b/src/serialization/MeshPacketSerializer.cpp index 88d13449697..a8bfa1e2805 100644 --- a/src/serialization/MeshPacketSerializer.cpp +++ b/src/serialization/MeshPacketSerializer.cpp @@ -420,7 +420,10 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, } jsonObj["id"] = (Json::UInt)mp->id; - jsonObj["timestamp"] = (Json::UInt)mp->rx_time; + // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() + // placeholder (see Router::dispatchReceived), not a wall-clock reading - emit 0 rather than + // leak it, keeping "timestamp" a key that's always present (unlike the optional rssi/snr below). + jsonObj["timestamp"] = mp->has_rx_time ? (Json::UInt)mp->rx_time : 0; jsonObj["to"] = (Json::UInt)mp->to; jsonObj["from"] = (Json::UInt)mp->from; jsonObj["channel"] = (Json::UInt)mp->channel; @@ -452,7 +455,10 @@ std::string MeshPacketSerializer::JsonSerializeEncrypted(const meshtastic_MeshPa jsonObj["id"] = (Json::UInt)mp->id; jsonObj["time_ms"] = (double)millis(); - jsonObj["timestamp"] = (Json::UInt)mp->rx_time; + // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() + // placeholder (see Router::dispatchReceived), not a wall-clock reading - emit 0 rather than + // leak it, keeping "timestamp" a key that's always present (unlike the optional rssi/snr below). + jsonObj["timestamp"] = mp->has_rx_time ? (Json::UInt)mp->rx_time : 0; jsonObj["to"] = (Json::UInt)mp->to; jsonObj["from"] = (Json::UInt)mp->from; jsonObj["channel"] = (Json::UInt)mp->channel; diff --git a/test/test_meshpacket_serializer/test_helpers.h b/test/test_meshpacket_serializer/test_helpers.h index da8c89fffe1..1793c1bf107 100644 --- a/test/test_meshpacket_serializer/test_helpers.h +++ b/test/test_meshpacket_serializer/test_helpers.h @@ -37,6 +37,7 @@ static meshtastic_MeshPacket create_test_packet(meshtastic_PortNum port, const u packet.want_ack = false; packet.priority = meshtastic_MeshPacket_Priority_UNSET; packet.rx_time = 1609459200; + packet.has_rx_time = true; // rx_time has explicit presence; mark this synthetic reading as measured packet.rx_snr = 10.5f; packet.hop_start = 3; packet.rx_rssi = -85; diff --git a/test/test_traffic_management/test_main.cpp b/test/test_traffic_management/test_main.cpp index afdcb96462f..34f5a545601 100644 --- a/test/test_traffic_management/test_main.cpp +++ b/test/test_traffic_management/test_main.cpp @@ -766,6 +766,7 @@ static void test_tm_nodeinfo_directResponse_psramCacheRespondsAndPreservesBitfie observed.decoded.bitfield = BITFIELD_WANT_RESPONSE_MASK; observed.channel = 2; observed.rx_time = 123456; + observed.has_rx_time = true; // rx_time has explicit presence; mark this synthetic reading as measured ProcessMessage observedResult = module.handleReceived(observed); TEST_ASSERT_EQUAL_INT(static_cast(ProcessMessage::CONTINUE), static_cast(observedResult)); From 50742ed0f0555fb9ab1691aee93b95e0a5f637a6 Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 21:38:54 +0100 Subject: [PATCH 2/9] Dedupe rx_time stamping into a shared helper; trim a debug log string Extract the repeated haveTime/rx_time/has_rx_time stamp logic (5 call sites across Router.cpp, MeshBeaconModule.cpp, MeshService.cpp) into Router::computeRxTimeStamp()/stampRxTime(). Also shorten the new RTC.cpp LOG_DEBUG string. Saves 48 bytes of flash on rak4631 (measured), no behavior change. --- src/gps/RTC.cpp | 3 +-- src/mesh/MeshService.cpp | 8 ++------ src/mesh/Router.cpp | 32 ++++++++++++++++++++------------ src/mesh/Router.h | 12 ++++++++++++ src/modules/MeshBeaconModule.cpp | 4 +--- 5 files changed, 36 insertions(+), 23 deletions(-) diff --git a/src/gps/RTC.cpp b/src/gps/RTC.cpp index 24b4d1f01be..c1bb294ce4e 100644 --- a/src/gps/RTC.cpp +++ b/src/gps/RTC.cpp @@ -29,8 +29,7 @@ static void triggerNodeInfoCheckOnTimeSource(RTCQuality oldQuality, RTCQuality n nodeInfoModule->triggerImmediateNodeInfoCheck(); } if (oldQuality < RTCQualityFromNet && newQuality >= RTCQualityFromNet && service) { - LOG_DEBUG("Time source reached net quality (%s -> %s), reconciling pending rx_time placeholders", RtcName(oldQuality), - RtcName(newQuality)); + LOG_DEBUG("RTC net quality reached (%s -> %s), reconciling rx_time", RtcName(oldQuality), RtcName(newQuality)); service->reconcilePendingRxTimes(); } } diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index 272bd2c6d75..d45a9d0456a 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -255,9 +255,7 @@ void MeshService::injectAsReceived(meshtastic_MeshPacket &p) // enqueueReceivedMessage below, so Router::dispatchReceived will normally overwrite this // anyway - but don't rely on that; a bare 0 would misdirect // MeshService::reconcilePendingRxTimes() if it were ever read before that happens). - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - mp->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - mp->has_rx_time = haveTime; + stampRxTime(mp); LOG_INFO("inject: RX from=0x%08x to=0x%08x id=0x%08x ch=%d %s", mp->from, mp->to, mp->id, mp->channel, mp->which_payload_variant == meshtastic_MeshPacket_encrypted_tag ? "encrypted" : "decoded"); router->enqueueReceivedMessage(mp); @@ -299,9 +297,7 @@ void MeshService::handleToRadio(meshtastic_MeshPacket &p) // Time::getMillis() placeholder, not a literal 0, on the rare chance the phone connected // without yet handing us net-quality time - a bare 0 would misdirect // MeshService::reconcilePendingRxTimes() if this packet is later echoed into toPhoneQueue. - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - p.rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - p.has_rx_time = haveTime; + stampRxTime(&p); IF_SCREEN(if (p.decoded.portnum == meshtastic_PortNum_TEXT_MESSAGE_APP && p.decoded.payload.size > 0 && p.to != NODENUM_BROADCAST && p.to != 0) // DM only diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index c79694d21d5..1393e33803f 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -269,6 +269,19 @@ PacketId generatePacketId() return id; } +RxTimeStamp computeRxTimeStamp() +{ + const bool haveTime = getRTCQuality() >= RTCQualityFromNet; + return {haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(), haveTime}; +} + +void stampRxTime(meshtastic_MeshPacket *p) +{ + const RxTimeStamp ts = computeRxTimeStamp(); + p->rx_time = ts.time; + p->has_rx_time = ts.valid; +} + meshtastic_MeshPacket *Router::allocForSending() { meshtastic_MeshPacket *p = packetPool.allocZeroed(); @@ -283,9 +296,7 @@ meshtastic_MeshPacket *Router::allocForSending() // Just in case we process the packet locally - make sure it has a timestamp. rx_time has // explicit presence (see dispatchReceived): fall back to a Time::getMillis() placeholder, // not a fabricated real-looking value, when we don't have a trustworthy wall clock yet. - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - p->has_rx_time = haveTime; + stampRxTime(p); return p; } @@ -1319,13 +1330,12 @@ void Router::dispatchReceived(meshtastic_MeshPacket *p, RxSource src) // sitting in toPhoneQueue into a real epoch, backdated by elapsed uptime, the moment the // clock becomes trustworthy. Any other reader of rx_time must check has_rx_time first - the // raw value is meaningless (a monotonic snapshot, not a wall-clock reading) while it's false. - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - const uint32_t rxTime = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - p->rx_time = rxTime; - p->has_rx_time = haveTime; + const RxTimeStamp rxStamp = computeRxTimeStamp(); + p->rx_time = rxStamp.time; + p->has_rx_time = rxStamp.valid; if (p_encrypted) { - p_encrypted->rx_time = rxTime; - p_encrypted->has_rx_time = haveTime; + p_encrypted->rx_time = rxStamp.time; + p_encrypted->has_rx_time = rxStamp.valid; } // Take those raw bytes and convert them back into a well structured protobuf we can understand @@ -1464,9 +1474,7 @@ void Router::perhapsHandleReceived(meshtastic_MeshPacket *p) // yet - this packet continues on through the rest of receive processing after the trace // dump below, so a bare 0 here would carry the same reconcilePendingRxTimes() risk // forward as every other rx_time write site. - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - p->has_rx_time = haveTime; + stampRxTime(p); LOG_TRACE("%s", MeshPacketSerializer::JsonSerializeEncrypted(p).c_str()); } #endif diff --git a/src/mesh/Router.h b/src/mesh/Router.h index 4a6356cb585..857b5e8c4ab 100644 --- a/src/mesh/Router.h +++ b/src/mesh/Router.h @@ -10,6 +10,18 @@ #include "concurrency/OSThread.h" #include +/// rx_time/has_rx_time for a packet observed "now": a real epoch when the wall clock is +/// trustworthy (RTCQualityFromNet or better), otherwise a Time::getMillis() placeholder with +/// valid left false - see Router::dispatchReceived for why the distinction matters. +struct RxTimeStamp { + uint32_t time; + bool valid; +}; +RxTimeStamp computeRxTimeStamp(); + +/// Stamp p->rx_time/p->has_rx_time with computeRxTimeStamp(). +void stampRxTime(meshtastic_MeshPacket *p); + /** * A mesh aware router that supports multiple interfaces. */ diff --git a/src/modules/MeshBeaconModule.cpp b/src/modules/MeshBeaconModule.cpp index 2ec2d96de98..fce49327c75 100644 --- a/src/modules/MeshBeaconModule.cpp +++ b/src/modules/MeshBeaconModule.cpp @@ -347,9 +347,7 @@ void MeshBeaconBroadcastModule::sendBeacon() // mistaken by MeshService::reconcilePendingRxTimes() for a genuine monotonic snapshot // if this packet is ever echoed back into toPhoneQueue, backdating it by our entire // uptime instead of leaving it correctly unknown. - const bool haveTime = getRTCQuality() >= RTCQualityFromNet; - p->rx_time = haveTime ? getValidTime(RTCQualityFromNet) : Time::getMillis(); - p->has_rx_time = haveTime; + stampRxTime(p); }; // ── Packet type decisions ──────────────────────────────────────────────── From bd44b4e8cb49fa200c5ac8376cecbf88d1bd3558 Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 23:08:26 +0100 Subject: [PATCH 3/9] Fix has_rx_rssi presence carried unconditionally through StoreForward replay preparePayload() set has_rx_rssi = true unconditionally on replay, regardless of whether the packet's rx_rssi at store time was a genuine measurement (e.g. MQTT-relayed packets carry no real RSSI). Store the presence bit alongside rx_rssi in PacketHistoryStruct and restore it on replay instead. Flagged by Copilot on #11271 (same root cause the has_rx_time explicit presence work fixes) but never addressed before that PR merged. --- src/modules/StoreForwardModule.cpp | 3 ++- src/modules/StoreForwardModule.h | 1 + 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/src/modules/StoreForwardModule.cpp b/src/modules/StoreForwardModule.cpp index c70666f3b7a..093c5ea3400 100644 --- a/src/modules/StoreForwardModule.cpp +++ b/src/modules/StoreForwardModule.cpp @@ -201,6 +201,7 @@ void StoreForwardModule::historyAdd(const meshtastic_MeshPacket &mp) this->packetHistory[this->packetHistoryTotalCount].emoji = (bool)p.emoji; this->packetHistory[this->packetHistoryTotalCount].payload_size = p.payload.size; this->packetHistory[this->packetHistoryTotalCount].rx_rssi = mp.rx_rssi; + this->packetHistory[this->packetHistoryTotalCount].has_rx_rssi = mp.has_rx_rssi; this->packetHistory[this->packetHistoryTotalCount].rx_snr = mp.rx_snr; this->packetHistory[this->packetHistoryTotalCount].hop_start = mp.hop_start; this->packetHistory[this->packetHistoryTotalCount].hop_limit = mp.hop_limit; @@ -268,7 +269,7 @@ meshtastic_MeshPacket *StoreForwardModule::preparePayload(NodeNum dest, uint32_t p->has_rx_time = (getRTCQuality() >= RTCQualityFromNet); p->decoded.emoji = (uint32_t)this->packetHistory[i].emoji; p->rx_rssi = this->packetHistory[i].rx_rssi; - p->has_rx_rssi = true; // rx_rssi has explicit presence; the stored value was a genuine measurement + p->has_rx_rssi = this->packetHistory[i].has_rx_rssi; // presence captured at store time, not replay time p->rx_snr = this->packetHistory[i].rx_snr; p->hop_start = this->packetHistory[i].hop_start; p->hop_limit = this->packetHistory[i].hop_limit; diff --git a/src/modules/StoreForwardModule.h b/src/modules/StoreForwardModule.h index 77565b22c49..14dcbda3046 100644 --- a/src/modules/StoreForwardModule.h +++ b/src/modules/StoreForwardModule.h @@ -21,6 +21,7 @@ struct PacketHistoryStruct { uint8_t payload[meshtastic_Constants_DATA_PAYLOAD_LEN]; pb_size_t payload_size; int32_t rx_rssi; + bool has_rx_rssi; // whether rx_rssi was a genuine measurement (e.g. not MQTT-relayed) when captured float rx_snr; uint8_t hop_start; uint8_t hop_limit; From 54597e9f0c959e379cbff419bf2c041cd02593c6 Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 23:14:42 +0100 Subject: [PATCH 4/9] Trim comment blocks to the repo's 1-2 line guideline .github/copilot-instructions.md:338 caps code comments at 1-2 lines; several blocks added across the rx_time explicit-presence work ran well past that. Also consolidates Time.cpp's file-level doc comment into Time.h, where the rest of the Time:: API contract already lives. No behavior change. --- src/Time.cpp | 11 +------- src/Time.h | 14 +++++---- src/gps/RTC.cpp | 5 +--- src/mesh/MeshService.cpp | 33 ++++++---------------- src/mesh/MeshService.h | 6 ++-- src/mesh/NodeDB.cpp | 10 ++----- src/mesh/PhoneAPI.cpp | 20 ++++++------- src/mesh/Router.cpp | 20 ++----------- src/mesh/Router.h | 5 ++-- src/modules/MeshBeaconModule.cpp | 5 ---- src/serialization/MeshPacketSerializer.cpp | 8 ++---- 11 files changed, 37 insertions(+), 100 deletions(-) diff --git a/src/Time.cpp b/src/Time.cpp index a955c31612a..fea92fd115d 100644 --- a/src/Time.cpp +++ b/src/Time.cpp @@ -1,13 +1,4 @@ -/** - * @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). - */ +// See Time.h for the full contract. #include "Time.h" uint32_t Time::getMillis() diff --git a/src/Time.h b/src/Time.h index f447c0a0dbb..17ce46fdc3a 100644 --- a/src/Time.h +++ b/src/Time.h @@ -19,16 +19,18 @@ * src/gps/RTC.h - a separate axis that can jump and be unset. * * Hot/ISR paths use getMillis() (32-bit, a drop-in for millis(), rollover-safe only with the - * unsigned-subtraction idiom `(uint32_t)(now - then)`). getMillis64() keeps mutable static - * carry state and is NOT ISR-safe - call it from normal task context only. - * An interrupt landing mid-update of that state (a read-then-write with no locking) could tear - * it, corrupting the high word for every caller afterward, not just the interrupted one. + * unsigned-subtraction idiom `(uint32_t)(now - then)`). 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, so it 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 carry state, so it is + * NOT ISR-safe - call it from normal task context only. An interrupt landing mid-update of that + * state (a read-then-write with no locking) could tear it, corrupting the high word for every + * caller afterward, not just the interrupted one. */ namespace Time { #ifdef PIO_UNIT_TESTING -// Test-only virtual clock. Default: OFF - getMillis() returns real millis() so suites that -// rely on real time are unaffected by the seam. A test opts in by calling setTestMillis(). +// Test-only virtual clock; OFF by default so suites relying on real time are unaffected. inline uint32_t testNowMs = 0; inline bool useTestClock = false; diff --git a/src/gps/RTC.cpp b/src/gps/RTC.cpp index c1bb294ce4e..589ac7db50f 100644 --- a/src/gps/RTC.cpp +++ b/src/gps/RTC.cpp @@ -18,10 +18,7 @@ uint32_t lastSetFromPhoneNtpOrGps = 0; static uint32_t lastTimeValidationWarning = 0; static const uint32_t TIME_VALIDATION_WARNING_INTERVAL_MS = 15000; // 15 seconds -// Despite the name, this now reacts to two distinct quality-crossing events sharing one call -// site: NodeInfo recheck on "we had no time source at all before" (unchanged), and rx_time -// reconciliation on "we just reached RTCQualityFromNet or better" (new) - see -// MeshService::reconcilePendingRxTimes(). The thresholds differ, so both checks are independent. +// Despite the name, also fires MeshService::reconcilePendingRxTimes() on reaching net-quality time. static void triggerNodeInfoCheckOnTimeSource(RTCQuality oldQuality, RTCQuality newQuality) { if (oldQuality == RTCQualityNone && newQuality > RTCQualityNone && nodeInfoModule) { diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index d45a9d0456a..ddd77809498 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -180,12 +180,8 @@ NodeNum MeshService::getNodenumFromRequestId(uint32_t request_id) return nodenum; } -// A packet stamped with has_rx_time == false is carrying a millis() snapshot from the moment it -// was received, not a wall-clock reading (see Router::dispatchReceived) - the device had no -// trustworthy time source yet, commonly because it has no GPS and the phone hadn't connected. -// Once the clock becomes trustworthy, back-calculate the real reception epoch from how much -// uptime has elapsed since that snapshot, rather than leaving the packet stuck presence-absent -// (or worse, silently wrong) for its remaining time in the queue. +// Back-calculate the real epoch for any queued packet still carrying a millis() rx_time +// placeholder, now that the clock is trustworthy. void MeshService::reconcilePendingRxTimes() { const uint32_t nowEpoch = getValidTime(RTCQualityFromNet); @@ -196,12 +192,8 @@ void MeshService::reconcilePendingRxTimes() for (int i = 0; i < toPhoneQueue.numUsed(); i++) { meshtastic_MeshPacket *p = toPhoneQueue.dequeuePtr(0); if (!p->has_rx_time) { - // Unsigned subtraction is wraparound-safe across a getMillis() rollover, matching - // the idiom already used throughout this codebase for elapsed-time math. Note this - // is only 32-bit-safe even though Time::getMillis64() exists: rx_time is a 32-bit - // wire field, so the placeholder stashed at receipt (Router::dispatchReceived) was - // never more than a 32-bit snapshot to begin with - a 64-bit "now" here would have - // nothing wider to compare against. + // 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; @@ -250,11 +242,8 @@ void MeshService::injectAsReceived(meshtastic_MeshPacket &p) mp->rx_rssi = -40; mp->has_rx_rssi = true; } - // rx_time has explicit presence: store a Time::getMillis() placeholder, not a literal 0, when - // we don't have a trustworthy wall clock yet (this packet re-enters the receive pipeline via - // enqueueReceivedMessage below, so Router::dispatchReceived will normally overwrite this - // anyway - but don't rely on that; a bare 0 would misdirect - // MeshService::reconcilePendingRxTimes() if it were ever read before that happens). + // dispatchReceived normally overwrites this once the packet re-enters the pipeline below, + // but don't rely on that. stampRxTime(mp); LOG_INFO("inject: RX from=0x%08x to=0x%08x id=0x%08x ch=%d %s", mp->from, mp->to, mp->id, mp->channel, mp->which_payload_variant == meshtastic_MeshPacket_encrypted_tag ? "encrypted" : "decoded"); @@ -293,10 +282,7 @@ void MeshService::handleToRadio(meshtastic_MeshPacket &p) if (p.id == 0) p.id = generatePacketId(); // If the phone didn't supply one, then pick one - // Record the time the packet arrived from the phone. rx_time has explicit presence: store a - // Time::getMillis() placeholder, not a literal 0, on the rare chance the phone connected - // without yet handing us net-quality time - a bare 0 would misdirect - // MeshService::reconcilePendingRxTimes() if this packet is later echoed into toPhoneQueue. + // Record the time the packet arrived from the phone. stampRxTime(&p); IF_SCREEN(if (p.decoded.portnum == meshtastic_PortNum_TEXT_MESSAGE_APP && p.decoded.payload.size > 0 && @@ -634,10 +620,7 @@ bool MeshService::isToPhoneQueueEmpty() uint32_t MeshService::GetTimeSinceMeshPacket(const meshtastic_MeshPacket *mp) { - // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() - // placeholder rather than a wall-clock reading (see Router::dispatchReceived), which would - // otherwise subtract to a huge bogus "age" here instead of a negative one the clamp below - // would catch. + // rx_time may be a millis() placeholder while has_rx_time is false - don't age it as wall-clock. if (!mp->has_rx_time) return 0; diff --git a/src/mesh/MeshService.h b/src/mesh/MeshService.h index e35feca5dd8..6ab1fe26a5d 100644 --- a/src/mesh/MeshService.h +++ b/src/mesh/MeshService.h @@ -137,10 +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 whose rx_time is still an unresolved millis() - // placeholder (has_rx_time == false, see Router::dispatchReceived) into a real epoch, now - // that the wall clock is trustworthy. Called from RTC.cpp the moment RTC quality crosses - // RTCQualityFromNet - typically, the phone just connected and told us the real time. + // Rewrite any queued-for-phone packet still carrying a millis() 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/NodeDB.cpp b/src/mesh/NodeDB.cpp index 9e3fc7e567b..8cb403d8ce8 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -3233,10 +3233,7 @@ uint32_t sinceLastSeen(const meshtastic_NodeInfoLite *n) uint32_t sinceReceived(const meshtastic_MeshPacket *p) { - // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() - // placeholder rather than a wall-clock reading (see Router::dispatchReceived), which would - // otherwise subtract to a huge bogus "age" here instead of a negative one the clamp below - // would catch. + // rx_time may be a millis() placeholder while has_rx_time is false - don't age it as wall-clock. if (!p->has_rx_time) return 0; @@ -3636,10 +3633,7 @@ void NodeDB::updateFrom(const meshtastic_MeshPacket &mp) return; } - // rx_time has explicit presence: a truthy-but-unknown rx_time is now possible (a millis() - // placeholder pending MeshService::reconcilePendingRxTimes()), so gate on has_rx_time, not - // truthiness - `if (mp.rx_time)` would otherwise stamp last_heard with a boot-relative - // millis() count rather than a real epoch. + // Gate on has_rx_time, not truthiness - rx_time may hold a millis() placeholder. if (mp.has_rx_time) info->last_heard = mp.rx_time; diff --git a/src/mesh/PhoneAPI.cpp b/src/mesh/PhoneAPI.cpp index 5bea4fddf47..094dfd28b49 100644 --- a/src/mesh/PhoneAPI.cpp +++ b/src/mesh/PhoneAPI.cpp @@ -1258,9 +1258,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayPositionPacket(NodeNum num, const mesh // fix time (which is often 0 and, when present, already round-trips inside the payload // via ConvertToPosition). pkt.rx_time = header ? header->last_heard : 0; - // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only - // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a - // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), + // so a legacy 0 unambiguously means "never". pkt.has_rx_time = (header && header->last_heard != 0); // Stable per-node/per-fix id: replaying the same unchanged history on every // reconnect must not look like a brand new packet to the phone's history/dedup. @@ -1289,9 +1288,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayTelemetryPacket(NodeNum num, const mes // No native timestamp on telemetry packets here; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only - // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a - // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), + // so a legacy 0 unambiguously means "never". pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_device_metrics_tag); pkt.channel = header ? header->channel : 0; @@ -1399,9 +1397,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayEnvironmentPacket(uint32_t num, const pkt.to = NODENUM_BROADCAST; const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only - // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a - // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), + // so a legacy 0 unambiguously means "never". pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_environment_metrics_tag); pkt.channel = header ? header->channel : 0; @@ -1468,9 +1465,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayStatusPacket(uint32_t num, const mesht // StatusMessage has no native timestamp; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // rx_time has explicit presence; last_heard has no presence bit of its own, but it is only - // ever written from a genuine has_rx_time-gated reception (see NodeDB::updateFrom), so a - // truthiness check on it is exact, not a heuristic - a legacy 0 unambiguously means "never". + // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), + // so a legacy 0 unambiguously means "never". pkt.has_rx_time = (header && header->last_heard != 0); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_PortNum_NODE_STATUS_APP); pkt.channel = header ? header->channel : 0; diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index 1393e33803f..fe3a2d4d384 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -293,9 +293,7 @@ meshtastic_MeshPacket *Router::allocForSending() p->to = NODENUM_BROADCAST; p->hop_limit = Default::getConfiguredOrDefaultHopLimit(config.lora.hop_limit); p->id = generatePacketId(); - // Just in case we process the packet locally - make sure it has a timestamp. rx_time has - // explicit presence (see dispatchReceived): fall back to a Time::getMillis() placeholder, - // not a fabricated real-looking value, when we don't have a trustworthy wall clock yet. + // Just in case we process the packet locally - make sure it has a timestamp. stampRxTime(p); return p; @@ -1320,16 +1318,8 @@ void Router::dispatchReceived(meshtastic_MeshPacket *p, RxSource src) if (src == RX_SRC_RADIO) applyRoutingAuthCache(p); - // Also, we should set the time from the ISR and it should have msec level resolution. // Keep the decoded working packet and encrypted MQTT copy on the same local arrival timestamp. - // - // rx_time has explicit presence. When we don't yet have a trustworthy wall clock (no GPS, - // and the phone hasn't connected/handed us net time yet), stash Time::getMillis() as a - // placeholder instead of a fabricated real-looking value - has_rx_time=false marks it as not - // yet known. MeshService::reconcilePendingRxTimes() rewrites any such placeholder still - // sitting in toPhoneQueue into a real epoch, backdated by elapsed uptime, the moment the - // clock becomes trustworthy. Any other reader of rx_time must check has_rx_time first - the - // raw value is meaningless (a monotonic snapshot, not a wall-clock reading) while it's false. + // See computeRxTimeStamp() for the placeholder/has_rx_time semantics. const RxTimeStamp rxStamp = computeRxTimeStamp(); p->rx_time = rxStamp.time; p->has_rx_time = rxStamp.valid; @@ -1469,11 +1459,7 @@ void Router::perhapsHandleReceived(meshtastic_MeshPacket *p) #if ARCH_PORTDUINO // Even ignored packets get logged in the trace if (portduino_config.traceFilename != "" || portduino_config.logoutputlevel == level_trace) { - // store the arrival timestamp for the phone. rx_time has explicit presence: store a - // Time::getMillis() placeholder, not a literal 0, when the wall clock isn't trustworthy - // yet - this packet continues on through the rest of receive processing after the trace - // dump below, so a bare 0 here would carry the same reconcilePendingRxTimes() risk - // forward as every other rx_time write site. + // Store the arrival timestamp for the phone before it's traced. stampRxTime(p); LOG_TRACE("%s", MeshPacketSerializer::JsonSerializeEncrypted(p).c_str()); } diff --git a/src/mesh/Router.h b/src/mesh/Router.h index 857b5e8c4ab..be686ee159f 100644 --- a/src/mesh/Router.h +++ b/src/mesh/Router.h @@ -10,9 +10,8 @@ #include "concurrency/OSThread.h" #include -/// rx_time/has_rx_time for a packet observed "now": a real epoch when the wall clock is -/// trustworthy (RTCQualityFromNet or better), otherwise a Time::getMillis() placeholder with -/// valid left false - see Router::dispatchReceived for why the distinction matters. +/// rx_time/has_rx_time for "now": a real epoch when the clock is trustworthy, else a +/// Time::getMillis() placeholder with valid=false. struct RxTimeStamp { uint32_t time; bool valid; diff --git a/src/modules/MeshBeaconModule.cpp b/src/modules/MeshBeaconModule.cpp index fce49327c75..cc5c6e807b9 100644 --- a/src/modules/MeshBeaconModule.cpp +++ b/src/modules/MeshBeaconModule.cpp @@ -342,11 +342,6 @@ void MeshBeaconBroadcastModule::sendBeacon() p->hop_limit = 0; // all beacon packets are zero hopped to limit spamming. p->priority = meshtastic_MeshPacket_Priority_BACKGROUND; p->want_ack = false; - // rx_time has explicit presence: store a Time::getMillis() placeholder, not a literal 0, - // when we don't have a trustworthy wall clock yet - a bare 0 here would later be - // mistaken by MeshService::reconcilePendingRxTimes() for a genuine monotonic snapshot - // if this packet is ever echoed back into toPhoneQueue, backdating it by our entire - // uptime instead of leaving it correctly unknown. stampRxTime(p); }; diff --git a/src/serialization/MeshPacketSerializer.cpp b/src/serialization/MeshPacketSerializer.cpp index a8bfa1e2805..f889c4f3cac 100644 --- a/src/serialization/MeshPacketSerializer.cpp +++ b/src/serialization/MeshPacketSerializer.cpp @@ -420,9 +420,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, } jsonObj["id"] = (Json::UInt)mp->id; - // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() - // placeholder (see Router::dispatchReceived), not a wall-clock reading - emit 0 rather than - // leak it, keeping "timestamp" a key that's always present (unlike the optional rssi/snr below). + // Emit 0 rather than leak a millis() placeholder when has_rx_time is false. jsonObj["timestamp"] = mp->has_rx_time ? (Json::UInt)mp->rx_time : 0; jsonObj["to"] = (Json::UInt)mp->to; jsonObj["from"] = (Json::UInt)mp->from; @@ -455,9 +453,7 @@ std::string MeshPacketSerializer::JsonSerializeEncrypted(const meshtastic_MeshPa jsonObj["id"] = (Json::UInt)mp->id; jsonObj["time_ms"] = (double)millis(); - // rx_time has explicit presence: while has_rx_time is false, rx_time may hold a millis() - // placeholder (see Router::dispatchReceived), not a wall-clock reading - emit 0 rather than - // leak it, keeping "timestamp" a key that's always present (unlike the optional rssi/snr below). + // Emit 0 rather than leak a millis() placeholder when has_rx_time is false. jsonObj["timestamp"] = mp->has_rx_time ? (Json::UInt)mp->rx_time : 0; jsonObj["to"] = (Json::UInt)mp->to; jsonObj["from"] = (Json::UInt)mp->from; From cc02d5781da29a1b7591a22746c37707acccf3cb Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 23:15:01 +0100 Subject: [PATCH 5/9] Add rx_time explicit-presence test coverage - test_meshpacket_serializer: has_rx_time=false fixture plus tests asserting JsonSerialize/JsonSerializeEncrypted emit 0 rather than leaking the millis() placeholder, alongside the has_rx_time=true baseline. - test_stream_api: two tests driving a real PhoneAPI handshake (want_config_id through STATE_SEND_PACKETS) that simulate a phone time-giving transaction arriving before vs. after a queued packet is drained - covering both the reconciled and the ships-with-placeholder-absent paths of MeshService::reconcilePendingRxTimes(). --- .../ports/test_timestamp.cpp | 37 ++++++ .../test_meshpacket_serializer/test_helpers.h | 11 ++ .../test_serializer.cpp | 8 ++ test/test_stream_api/test_main.cpp | 122 ++++++++++++++++++ 4 files changed, 178 insertions(+) create mode 100644 test/test_meshpacket_serializer/ports/test_timestamp.cpp diff --git a/test/test_meshpacket_serializer/ports/test_timestamp.cpp b/test/test_meshpacket_serializer/ports/test_timestamp.cpp new file mode 100644 index 00000000000..333945f80a3 --- /dev/null +++ b/test/test_meshpacket_serializer/ports/test_timestamp.cpp @@ -0,0 +1,37 @@ +#include "../test_helpers.h" + +void test_timestamp_present_when_has_rx_time() +{ + const char *test_text = "hi"; + meshtastic_MeshPacket packet = + create_test_packet(meshtastic_PortNum_TEXT_MESSAGE_APP, reinterpret_cast(test_text), strlen(test_text)); + + std::string json = MeshPacketSerializer::JsonSerialize(&packet, false); + Json::Value root = parse_json(json); + TEST_ASSERT_TRUE(root.isMember("timestamp")); + TEST_ASSERT_EQUAL_UINT32(1609459200u, root["timestamp"].asUInt()); +} + +void test_timestamp_zeroed_when_rx_time_absent() +{ + const char *test_text = "hi"; + meshtastic_MeshPacket packet = create_test_packet_no_rx_time(meshtastic_PortNum_TEXT_MESSAGE_APP, + reinterpret_cast(test_text), strlen(test_text)); + + 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 +} + +void test_encrypted_timestamp_zeroed_when_rx_time_absent() +{ + const char *test_text = "hi"; + meshtastic_MeshPacket packet = create_test_packet_no_rx_time(meshtastic_PortNum_TEXT_MESSAGE_APP, + reinterpret_cast(test_text), strlen(test_text)); + + std::string json = MeshPacketSerializer::JsonSerializeEncrypted(&packet); + Json::Value root = parse_json(json); + TEST_ASSERT_TRUE(root.isMember("timestamp")); + TEST_ASSERT_EQUAL_UINT32(0u, root["timestamp"].asUInt()); +} diff --git a/test/test_meshpacket_serializer/test_helpers.h b/test/test_meshpacket_serializer/test_helpers.h index 1793c1bf107..2dc06cec78f 100644 --- a/test/test_meshpacket_serializer/test_helpers.h +++ b/test/test_meshpacket_serializer/test_helpers.h @@ -63,3 +63,14 @@ static meshtastic_MeshPacket create_test_packet(meshtastic_PortNum port, const u return packet; } + +// Same as create_test_packet(), but with rx_time absent (has_rx_time = false) and a nonzero +// millis()-style placeholder in rx_time, to verify serializers treat it as unknown, not a reading. +static meshtastic_MeshPacket create_test_packet_no_rx_time(meshtastic_PortNum port, const uint8_t *payload, size_t payload_size, + 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.has_rx_time = false; + return packet; +} diff --git a/test/test_meshpacket_serializer/test_serializer.cpp b/test/test_meshpacket_serializer/test_serializer.cpp index 484db8d7486..58483ff9196 100644 --- a/test/test_meshpacket_serializer/test_serializer.cpp +++ b/test/test_meshpacket_serializer/test_serializer.cpp @@ -19,6 +19,9 @@ void test_telemetry_environment_metrics_complete_coverage(); void test_telemetry_environment_metrics_unset_fields(); void test_encrypted_packet_serialization(); void test_empty_encrypted_packet(); +void test_timestamp_present_when_has_rx_time(); +void test_timestamp_zeroed_when_rx_time_absent(); +void test_encrypted_timestamp_zeroed_when_rx_time_absent(); void setup() { @@ -52,6 +55,11 @@ void setup() RUN_TEST(test_encrypted_packet_serialization); RUN_TEST(test_empty_encrypted_packet); + // rx_time explicit-presence tests + RUN_TEST(test_timestamp_present_when_has_rx_time); + RUN_TEST(test_timestamp_zeroed_when_rx_time_absent); + RUN_TEST(test_encrypted_timestamp_zeroed_when_rx_time_absent); + UNITY_END(); } diff --git a/test/test_stream_api/test_main.cpp b/test/test_stream_api/test_main.cpp index 1fbd370a090..b410c1e51b1 100644 --- a/test/test_stream_api/test_main.cpp +++ b/test/test_stream_api/test_main.cpp @@ -1,7 +1,9 @@ #include "MeshTypes.h" #include "SerialConsole.h" #include "TestUtil.h" +#include "Time.h" #include "configuration.h" +#include "gps/RTC.h" #include "mesh-pb-constants.h" #include "mesh/MeshService.h" #include "mesh/NodeDB.h" @@ -10,6 +12,7 @@ #include #include #include +#include #include #include #include @@ -522,6 +525,123 @@ static void test_want_config_includes_status_message_module_config(void) TEST_ASSERT_TRUE(foundStatusMessageConfig); } +/// Queue a packet as Router::dispatchReceived would have, before any time source existed. +static void queuePendingTimePlaceholderPacket(NodeNum from, uint32_t placeholderMillis) +{ + 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.has_rx_time = false; + service->sendToPhone(packetPool.allocCopy(pending)); +} + +static void startHandshake(PhoneAPITestShim &api) +{ + meshtastic_ToRadio request = meshtastic_ToRadio_init_zero; + request.which_payload_variant = meshtastic_ToRadio_want_config_id_tag; + request.want_config_id = SPECIAL_NONCE_ONLY_CONFIG; + uint8_t requestBytes[meshtastic_ToRadio_size]; + const size_t requestSize = pb_encode_to_bytes(requestBytes, sizeof(requestBytes), &meshtastic_ToRadio_msg, &request); + api.handleToRadio(requestBytes, requestSize); +} + +/// Drain the config stream looking for the first packet from `from`; false if never delivered. +static bool drainHandshakeForPacketFrom(PhoneAPITestShim &api, NodeNum from, meshtastic_MeshPacket &outPacket) +{ + for (unsigned i = 0; i < 256; ++i) { + uint8_t responseBytes[meshtastic_FromRadio_size]; + const size_t responseSize = api.getFromRadio(responseBytes); + if (responseSize == 0) + return false; + meshtastic_FromRadio response = meshtastic_FromRadio_init_zero; + TEST_ASSERT_TRUE(pb_decode_from_bytes(responseBytes, responseSize, &meshtastic_FromRadio_msg, &response)); + if (response.which_payload_variant == meshtastic_FromRadio_packet_tag && response.packet.from == from) { + outPacket = response.packet; + return true; + } + } + return false; +} + +// Time given at the start of the handshake, before the queued packet is drained: reconciliation +// (fired by the RTC quality crossing hook in RTC.cpp) rewrites the placeholder in place. +static void test_time_given_at_handshake_start_reconciles_queued_packet(void) +{ + resetRTCStateForTests(); + ScopedMeshService scopedService; + NodeDB testNodeDB; + NodeDB *const savedNodeDB = nodeDB; + nodeDB = &testNodeDB; + Time::setTestMillis(5000); + + const NodeNum sender = 0x12345678; + queuePendingTimePlaceholderPacket(sender, 2000); // "received" 3s before the test's current millis() + + PhoneAPITestShim api; + startHandshake(api); + + struct timeval networkTime; + networkTime.tv_sec = time(NULL) + SEC_PER_DAY; + networkTime.tv_usec = 0; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &networkTime)); + + meshtastic_MeshPacket delivered; + TEST_ASSERT_TRUE_MESSAGE(drainHandshakeForPacketFrom(api, sender, delivered), + "queued packet was not delivered during the handshake"); + TEST_ASSERT_TRUE(delivered.has_rx_time); + TEST_ASSERT_UINT32_WITHIN(2, (uint32_t)networkTime.tv_sec - 3, delivered.rx_time); + + api.close(); + nodeDB = savedNodeDB; + Time::useRealClock(); + resetRTCStateForTests(); +} + +// Time given at the end - after the queued packet already left via the handshake: the delivered +// copy keeps its unresolved placeholder, since reconciliation can only rewrite what's still queued. +static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packet(void) +{ + resetRTCStateForTests(); + ScopedMeshService scopedService; + NodeDB testNodeDB; + NodeDB *const savedNodeDB = nodeDB; + nodeDB = &testNodeDB; + Time::setTestMillis(5000); + + const NodeNum sender = 0x12345678; + queuePendingTimePlaceholderPacket(sender, 2000); + + PhoneAPITestShim api; + startHandshake(api); + + // rx_time is proto3 optional: with has_rx_time false, the field is omitted from the wire + // entirely (not just flagged invalid), so the decoded copy reads back 0, not the in-memory + // placeholder - the placeholder itself never left the device. + meshtastic_MeshPacket delivered; + TEST_ASSERT_TRUE_MESSAGE(drainHandshakeForPacketFrom(api, sender, delivered), + "queued packet was not delivered during the handshake"); + TEST_ASSERT_FALSE(delivered.has_rx_time); + TEST_ASSERT_EQUAL_UINT32(0u, delivered.rx_time); + + // Time-giving transaction happens only now, at the end of the handshake. + struct timeval networkTime; + networkTime.tv_sec = time(NULL) + SEC_PER_DAY; + networkTime.tv_usec = 0; + TEST_ASSERT_EQUAL_INT(RTCSetResultSuccess, perhapsSetRTC(RTCQualityFromNet, &networkTime)); + + // The already-delivered copy is a value, not a queue reference - untouched either way. + TEST_ASSERT_FALSE(delivered.has_rx_time); + TEST_ASSERT_EQUAL_UINT32(0u, delivered.rx_time); + + api.close(); + nodeDB = savedNodeDB; + Time::useRealClock(); + resetRTCStateForTests(); +} + /// Unity per-test setup; fixtures are local to each test. void setUp(void) {} /// Unity per-test teardown; fixtures clean themselves up. @@ -544,6 +664,8 @@ void setup() RUN_TEST(test_lockdown_admin_gate_ignores_wire_from); RUN_TEST(test_lockdown_admin_gate_rejects_undecodable_admin); 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); // 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()); From c81f7110e1e231a1204afab0382569a561392c7f Mon Sep 17 00:00:00 2001 From: nomdetom Date: Tue, 28 Jul 2026 23:43:41 +0100 Subject: [PATCH 6/9] Fix three correctness issues flagged in review - Time.h: drop the reserved-identifier include guard (_MT_TIME_H); pragma once already covers it, matching convention elsewhere (e.g. RTC.h). - Time.cpp: rebase getMillis64()'s wrap accumulator when the test seam swaps clock sources, so a real<->injected clock jump isn't miscounted as a genuine 32-bit wrap. - NodeInfoModule: the 12h reply-suppression window is a local dedup duration, not a wall-clock reading - switch it to Time::getMillis64() so RTC-quality jumps and replayed packets' stale rx_time can't perturb it. - StoreForwardModule: has_rx_time was derived from *current* RTC quality at replay time rather than stored at capture time, so a history entry saved while time-blind could be misreported as a valid epoch once the clock later improved. Persist the presence bit in PacketHistoryStruct instead. --- src/Time.cpp | 9 +++++++++ src/Time.h | 7 +++---- src/modules/NodeInfoModule.cpp | 6 +++--- src/modules/StoreForwardModule.cpp | 13 ++++--------- src/modules/StoreForwardModule.h | 1 + 5 files changed, 20 insertions(+), 16 deletions(-) diff --git a/src/Time.cpp b/src/Time.cpp index fea92fd115d..5f41e159daf 100644 --- a/src/Time.cpp +++ b/src/Time.cpp @@ -16,6 +16,15 @@ uint64_t Time::getMillis64() static uint32_t highWord = 0; // number of observed wraps uint32_t now = Time::getMillis(); +#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; + } +#endif if (now < lastLow) highWord++; // low word wrapped since last call lastLow = now; diff --git a/src/Time.h b/src/Time.h index 17ce46fdc3a..268fc60aef1 100644 --- a/src/Time.h +++ b/src/Time.h @@ -1,6 +1,4 @@ #pragma once -#ifndef _MT_TIME_H -#define _MT_TIME_H #include @@ -33,11 +31,13 @@ namespace Time // 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 inline void setTestMillis(uint32_t ms) { testNowMs = ms; useTestClock = true; + clockSourceChanged = true; } inline void advanceTestMillis(uint32_t deltaMs) { @@ -49,6 +49,7 @@ inline void useRealClock() { useTestClock = false; testNowMs = 0; + clockSourceChanged = true; } #endif @@ -59,5 +60,3 @@ uint32_t getMillis(); uint64_t getMillis64(); } // namespace Time - -#endif diff --git a/src/modules/NodeInfoModule.cpp b/src/modules/NodeInfoModule.cpp index 1c4048c9012..abbf25ae0a7 100644 --- a/src/modules/NodeInfoModule.cpp +++ b/src/modules/NodeInfoModule.cpp @@ -33,9 +33,9 @@ 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); - // has_rx_time, not truthiness: rx_time may hold a millis() placeholder (not a wall-clock - // reading) while has_rx_time is false - see Router::dispatchReceived. - const uint32_t now = mp.has_rx_time ? mp.rx_time : getTime(); + // 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); auto it = lastNodeInfoSeen.find(sender); if (it != lastNodeInfoSeen.end()) { uint32_t sinceLast = now >= it->second ? now - it->second : 0; diff --git a/src/modules/StoreForwardModule.cpp b/src/modules/StoreForwardModule.cpp index 093c5ea3400..bd023716a11 100644 --- a/src/modules/StoreForwardModule.cpp +++ b/src/modules/StoreForwardModule.cpp @@ -193,6 +193,9 @@ void StoreForwardModule::historyAdd(const meshtastic_MeshPacket &mp) } this->packetHistory[this->packetHistoryTotalCount].time = getTime(); + // getTime() silently falls back to a boot-relative count with no RTC source at all; record + // whether it was actually trustworthy so replay doesn't have to guess from current quality. + this->packetHistory[this->packetHistoryTotalCount].has_rx_time = (getRTCQuality() >= RTCQualityFromNet); this->packetHistory[this->packetHistoryTotalCount].to = mp.to; this->packetHistory[this->packetHistoryTotalCount].channel = mp.channel; this->packetHistory[this->packetHistoryTotalCount].from = getFrom(&mp); @@ -258,15 +261,7 @@ meshtastic_MeshPacket *StoreForwardModule::preparePayload(NodeNum dest, uint32_t p->channel = this->packetHistory[i].channel; p->decoded.reply_id = this->packetHistory[i].reply_id; p->rx_time = this->packetHistory[i].time; - // packetHistory[i].time was captured via getTime() at store time (StoreForwardModule.cpp - // ~line 195), which - unlike getValidTime(RTCQualityFromNet) - never hard-fails to 0; with - // no RTC source at all it silently returns a boot-relative seconds count instead. This - // module has no presence bit of its own to tell the two apart, and isn't covered by - // MeshService::reconcilePendingRxTimes() (a different buffer entirely), so this is only an - // approximation: assume the stored time is trustworthy iff our *current* clock is, since - // RTC quality monotonically improves and rarely regresses. A history entry stored while - // time-blind and never revisited will still under-report its age if quality later improves. - p->has_rx_time = (getRTCQuality() >= RTCQualityFromNet); + p->has_rx_time = this->packetHistory[i].has_rx_time; // presence captured at store time, not replay time p->decoded.emoji = (uint32_t)this->packetHistory[i].emoji; p->rx_rssi = this->packetHistory[i].rx_rssi; p->has_rx_rssi = this->packetHistory[i].has_rx_rssi; // presence captured at store time, not replay time diff --git a/src/modules/StoreForwardModule.h b/src/modules/StoreForwardModule.h index 14dcbda3046..82406b70a0e 100644 --- a/src/modules/StoreForwardModule.h +++ b/src/modules/StoreForwardModule.h @@ -12,6 +12,7 @@ struct PacketHistoryStruct { uint32_t time; + bool has_rx_time; // whether `time` was a trustworthy epoch when captured, not a getTime() boot-relative fallback uint32_t to; uint32_t from; uint32_t id; From 2cdd0b062e748fac9f0ef48f3aebd257422edc2e Mon Sep 17 00:00:00 2001 From: nomdetom Date: Wed, 29 Jul 2026 00:16:51 +0100 Subject: [PATCH 7/9] tryfix CI --- src/Time.cpp | 1 + src/Time.h | 2 +- variants/native/portduino/platformio.ini | 2 +- 3 files changed, 3 insertions(+), 2 deletions(-) diff --git a/src/Time.cpp b/src/Time.cpp index 5f41e159daf..26c3067e81d 100644 --- a/src/Time.cpp +++ b/src/Time.cpp @@ -1,5 +1,6 @@ // See Time.h for the full contract. #include "Time.h" +#include uint32_t Time::getMillis() { diff --git a/src/Time.h b/src/Time.h index 268fc60aef1..acb04b7cf43 100644 --- a/src/Time.h +++ b/src/Time.h @@ -1,6 +1,6 @@ #pragma once -#include +#include /** * Monotonic uptime clock - the single seam for "milliseconds since boot". diff --git a/variants/native/portduino/platformio.ini b/variants/native/portduino/platformio.ini index 22fb6223c34..9d878d5f0c1 100644 --- a/variants/native/portduino/platformio.ini +++ b/variants/native/portduino/platformio.ini @@ -423,7 +423,7 @@ build_src_filter = + + + + + + + + - + + + + + + + + + + + + + + + + + + + + From cdd14a4c2c9c518c7a6fc8481d126a183c855f33 Mon Sep 17 00:00:00 2001 From: nomdetom Date: Wed, 29 Jul 2026 01:35:05 +0100 Subject: [PATCH 8/9] post review fixes --- src/Time.h | 62 ----------------------- src/{Time.cpp => UptimeClock.cpp} | 4 +- src/UptimeClock.h | 46 +++++++++++++++++ src/configuration.h | 4 -- src/gps/RTC.cpp | 13 +++-- src/mesh/MeshService.cpp | 22 +++++--- src/mesh/MeshService.h | 1 + src/mesh/NodeDB.cpp | 5 +- src/mesh/NodeDB.h | 7 ++- src/mesh/PhoneAPI.cpp | 31 +++++++----- src/mesh/Router.cpp | 1 + src/modules/NodeInfoModule.cpp | 1 + src/modules/Telemetry/HealthTelemetry.cpp | 7 ++- src/modules/Telemetry/PowerTelemetry.cpp | 7 ++- test/test_stream_api/test_main.cpp | 7 ++- variants/native/portduino/platformio.ini | 2 +- 16 files changed, 117 insertions(+), 103 deletions(-) delete mode 100644 src/Time.h rename src/{Time.cpp => UptimeClock.cpp} (92%) create mode 100644 src/UptimeClock.h diff --git a/src/Time.h b/src/Time.h deleted file mode 100644 index acb04b7cf43..00000000000 --- a/src/Time.h +++ /dev/null @@ -1,62 +0,0 @@ -#pragma once - -#include - -/** - * Monotonic uptime clock - the single seam for "milliseconds since boot". - * - * Why this exists: - * - Test injection: any unit test can drive a virtual timebase via setTestMillis() / - * advanceTestMillis() instead of sleeping real seconds. One seam for all suites - no - * per-module test clock (this replaces the ad-hoc HopScalingModule::s_testNowMs / - * TrafficManagementModule::clockMs patterns). - * - Rollover immunity: getMillis64() never wraps (uint32 millis() wraps at ~49.7 days, which - * routers/repeaters exceed). Use it for any "duration over days" logic. - * - * This is uptime, NOT wall-clock. For wall-clock seconds (RTC/GPS/NTP) use getTime() in - * src/gps/RTC.h - a separate axis that can jump and be unset. - * - * Hot/ISR paths use getMillis() (32-bit, a drop-in for millis(), rollover-safe only with the - * unsigned-subtraction idiom `(uint32_t)(now - then)`). 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, so it 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 carry state, so it is - * NOT ISR-safe - call it from normal task context only. An interrupt landing mid-update of that - * state (a read-then-write with no locking) could tear it, corrupting the high word for every - * caller afterward, not just the interrupted one. - */ -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 - -inline void setTestMillis(uint32_t ms) -{ - testNowMs = ms; - useTestClock = true; - clockSourceChanged = true; -} -inline void advanceTestMillis(uint32_t deltaMs) -{ - testNowMs += deltaMs; - useTestClock = true; -} -// 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; -} -#endif - -/// Milliseconds since boot, 32-bit (wraps ~49.7 days). Drop-in for millis(). -uint32_t getMillis(); - -/// Milliseconds since boot, 64-bit, rollover-immune. Non-ISR use only. -uint64_t getMillis64(); - -} // namespace Time diff --git a/src/Time.cpp b/src/UptimeClock.cpp similarity index 92% rename from src/Time.cpp rename to src/UptimeClock.cpp index 26c3067e81d..5f85f50ff23 100644 --- a/src/Time.cpp +++ b/src/UptimeClock.cpp @@ -1,5 +1,5 @@ -// See Time.h for the full contract. -#include "Time.h" +// See UptimeClock.h for the full contract. +#include "UptimeClock.h" #include uint32_t Time::getMillis() diff --git a/src/UptimeClock.h b/src/UptimeClock.h new file mode 100644 index 00000000000..9329a7bf608 --- /dev/null +++ b/src/UptimeClock.h @@ -0,0 +1,46 @@ +#pragma once + +#include + +// 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 + +inline void setTestMillis(uint32_t ms) +{ + testNowMs = ms; + useTestClock = true; + clockSourceChanged = true; +} +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; +} +// 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; +} +#endif + +/// Milliseconds since boot, 32-bit (wraps ~49.7 days). Drop-in for millis(). +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(); + +} // namespace Time diff --git a/src/configuration.h b/src/configuration.h index 059d53af2bd..672d8b6f190 100644 --- a/src/configuration.h +++ b/src/configuration.h @@ -26,10 +26,6 @@ along with this program. If not, see . #include -// Monotonic uptime clock seam (Time::getMillis / getMillis64). Hosted here so the whole -// codebase can use it without per-file includes; see src/Time.h. -#include "Time.h" - #if __has_include("Melopero_RV3028.h") #include "Melopero_RV3028.h" #endif diff --git a/src/gps/RTC.cpp b/src/gps/RTC.cpp index 589ac7db50f..217bbb4c396 100644 --- a/src/gps/RTC.cpp +++ b/src/gps/RTC.cpp @@ -18,8 +18,7 @@ uint32_t lastSetFromPhoneNtpOrGps = 0; static uint32_t lastTimeValidationWarning = 0; static const uint32_t TIME_VALIDATION_WARNING_INTERVAL_MS = 15000; // 15 seconds -// Despite the name, also fires MeshService::reconcilePendingRxTimes() on reaching net-quality time. -static void triggerNodeInfoCheckOnTimeSource(RTCQuality oldQuality, RTCQuality newQuality) +static void onTimeSourceQualityChanged(RTCQuality oldQuality, RTCQuality newQuality) { if (oldQuality == RTCQualityNone && newQuality > RTCQualityNone && nodeInfoModule) { LOG_DEBUG("Time source acquired (%s -> %s), triggering NodeInfo recheck", RtcName(oldQuality), RtcName(newQuality)); @@ -134,7 +133,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } else { @@ -180,7 +179,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } else { @@ -216,7 +215,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } @@ -241,7 +240,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } @@ -387,7 +386,7 @@ RTCSetResult perhapsSetRTC(RTCQuality q, const struct timeval *tv, bool forceUpd #endif readFromRTC(); - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); return RTCSetResultSuccess; } else { return RTCSetResultNotSet; // RTC was already set with a higher quality time diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index ddd77809498..2f3dbb1a5fc 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -12,6 +12,7 @@ #include "Power.h" #include "PowerFSM.h" #include "TypeConversions.h" +#include "UptimeClock.h" #include "gps/RTC.h" #include "graphics/draw/MessageRenderer.h" #include "main.h" @@ -189,8 +190,12 @@ void MeshService::reconcilePendingRxTimes() return; const uint32_t nowMillis = Time::getMillis(); - for (int i = 0; i < toPhoneQueue.numUsed(); i++) { + // 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. + for (int remaining = toPhoneQueue.numUsed(); remaining > 0; remaining--) { meshtastic_MeshPacket *p = toPhoneQueue.dequeuePtr(0); + 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. @@ -198,7 +203,11 @@ void MeshService::reconcilePendingRxTimes() p->rx_time = nowEpoch - (elapsedMs / 1000); p->has_rx_time = true; } - toPhoneQueue.enqueue(p, 0); + if (!toPhoneQueue.enqueue(p, 0)) { // mirrors sendToPhone()'s degrade-on-failure path + LOG_CRIT("Failed to requeue a packet into toPhoneQueue!"); + releaseToPool(p); + fromNum++; // notify observers so the phone can resync + } } } @@ -242,8 +251,8 @@ void MeshService::injectAsReceived(meshtastic_MeshPacket &p) mp->rx_rssi = -40; mp->has_rx_rssi = true; } - // dispatchReceived normally overwrites this once the packet re-enters the pipeline below, - // but don't rely on that. + // dispatchReceived() restamps this when the packet re-enters the pipeline below; stamp it + // here anyway so the packet is never observable with an unset arrival time. stampRxTime(mp); LOG_INFO("inject: RX from=0x%08x to=0x%08x id=0x%08x ch=%d %s", mp->from, mp->to, mp->id, mp->channel, mp->which_payload_variant == meshtastic_MeshPacket_encrypted_tag ? "encrypted" : "decoded"); @@ -620,9 +629,10 @@ 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 wall-clock. + // rx_time may be a millis() 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 0; + return SINCE_UNKNOWN; uint32_t now = getTime(); diff --git a/src/mesh/MeshService.h b/src/mesh/MeshService.h index 6ab1fe26a5d..bae955969e5 100644 --- a/src/mesh/MeshService.h +++ b/src/mesh/MeshService.h @@ -209,6 +209,7 @@ class MeshService ErrorCode sendQueueStatusToPhone(const meshtastic_QueueStatus &qs, ErrorCode res, uint32_t mesh_packet_id); + /// Seconds since the packet arrived, or SINCE_UNKNOWN if it carries no trustworthy rx_time. uint32_t GetTimeSinceMeshPacket(const meshtastic_MeshPacket *mp); private: diff --git a/src/mesh/NodeDB.cpp b/src/mesh/NodeDB.cpp index 8cb403d8ce8..7af89e79dca 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -3233,9 +3233,10 @@ 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 wall-clock. + // rx_time may be a millis() 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 0; + return SINCE_UNKNOWN; uint32_t now = getTime(); diff --git a/src/mesh/NodeDB.h b/src/mesh/NodeDB.h index 5320c571b99..152fdee1d47 100644 --- a/src/mesh/NodeDB.h +++ b/src/mesh/NodeDB.h @@ -166,10 +166,15 @@ inline bool isRadioProfileFile(const char *filename) strcmp(filename, backupFileName) == 0; } +/// "No trustworthy arrival time", as distinct from "zero seconds ago". Deliberately huge so the +/// display formatters fall into their existing unknown-age branches ("unknown age" / "?"). +inline constexpr uint32_t SINCE_UNKNOWN = UINT32_MAX; + /// Given a node, return how many seconds in the past (vs now) that we last heard from it uint32_t sinceLastSeen(const meshtastic_NodeInfoLite *n); -/// Given a packet, return how many seconds in the past (vs now) it was received +/// Given a packet, return how many seconds in the past (vs now) it was received, +/// or SINCE_UNKNOWN if it carries no trustworthy rx_time. uint32_t sinceReceived(const meshtastic_MeshPacket *p); /// Outcome of mapping a single on-wire last-byte (next_hop / relay_node) back to a full NodeNum. diff --git a/src/mesh/PhoneAPI.cpp b/src/mesh/PhoneAPI.cpp index 094dfd28b49..70d869bea81 100644 --- a/src/mesh/PhoneAPI.cpp +++ b/src/mesh/PhoneAPI.cpp @@ -1238,6 +1238,17 @@ void setReplayHopFields(meshtastic_MeshPacket &pkt, const meshtastic_NodeInfoLit pkt.hop_limit = hopsAway < hopLimit ? (uint8_t)(hopLimit - hopsAway) : 0; } +/// 2020-01-01: a boot-relative counter needs ~50 years of uptime to reach this, so it cannot be +/// confused with a real epoch. +constexpr uint32_t MIN_PLAUSIBLE_EPOCH = 1577836800u; + +/// Not every last_heard writer gates on RTC quality - NodeDB::addFromContact stamps it with a bare +/// getTime(), which is boot-relative seconds on a node that has never had a clock. +bool lastHeardIsWallClock(const meshtastic_NodeInfoLite *header) +{ + return header && header->last_heard >= MIN_PLAUSIBLE_EPOCH; +} + } // namespace // Replayed packets deliberately leave rx_rssi absent. NodeInfoLite stores no RSSI, and @@ -1258,9 +1269,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayPositionPacket(NodeNum num, const mesh // fix time (which is often 0 and, when present, already round-trips inside the payload // via ConvertToPosition). pkt.rx_time = header ? header->last_heard : 0; - // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), - // so a legacy 0 unambiguously means "never". - pkt.has_rx_time = (header && header->last_heard != 0); + // Present only when last_heard is a genuine epoch - see lastHeardIsWallClock(). + pkt.has_rx_time = lastHeardIsWallClock(header); // Stable per-node/per-fix id: replaying the same unchanged history on every // reconnect must not look like a brand new packet to the phone's history/dedup. pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_PortNum_POSITION_APP); @@ -1288,9 +1298,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayTelemetryPacket(NodeNum num, const mes // No native timestamp on telemetry packets here; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), - // so a legacy 0 unambiguously means "never". - pkt.has_rx_time = (header && header->last_heard != 0); + // Present only when last_heard is a genuine epoch - see lastHeardIsWallClock(). + pkt.has_rx_time = lastHeardIsWallClock(header); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_device_metrics_tag); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; @@ -1397,9 +1406,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayEnvironmentPacket(uint32_t num, const pkt.to = NODENUM_BROADCAST; const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), - // so a legacy 0 unambiguously means "never". - pkt.has_rx_time = (header && header->last_heard != 0); + // Present only when last_heard is a genuine epoch - see lastHeardIsWallClock(). + pkt.has_rx_time = lastHeardIsWallClock(header); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_Telemetry_environment_metrics_tag); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; @@ -1465,9 +1473,8 @@ meshtastic_MeshPacket PhoneAPI::makeReplayStatusPacket(uint32_t num, const mesht // StatusMessage has no native timestamp; use last_heard. const meshtastic_NodeInfoLite *header = nodeDB->getMeshNode(num); pkt.rx_time = header ? header->last_heard : 0; - // last_heard is only ever written from a has_rx_time-gated reception (NodeDB::updateFrom), - // so a legacy 0 unambiguously means "never". - pkt.has_rx_time = (header && header->last_heard != 0); + // Present only when last_heard is a genuine epoch - see lastHeardIsWallClock(). + pkt.has_rx_time = lastHeardIsWallClock(header); pkt.id = makeReplayPacketId(num, pkt.rx_time, meshtastic_PortNum_NODE_STATUS_APP); pkt.channel = header ? header->channel : 0; pkt.rx_snr = header ? header->snr : 0; diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index fe3a2d4d384..cf0e05c9ae8 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -5,6 +5,7 @@ #include "MeshService.h" #include "NodeDB.h" #include "PositionPrecision.h" +#include "UptimeClock.h" #include "gps/RTC.h" #include "configuration.h" diff --git a/src/modules/NodeInfoModule.cpp b/src/modules/NodeInfoModule.cpp index abbf25ae0a7..cf6180ca28e 100644 --- a/src/modules/NodeInfoModule.cpp +++ b/src/modules/NodeInfoModule.cpp @@ -5,6 +5,7 @@ #include "NodeStatus.h" #include "Router.h" #include "TransmitHistory.h" +#include "UptimeClock.h" #include "configuration.h" #include "gps/RTC.h" #include "main.h" diff --git a/src/modules/Telemetry/HealthTelemetry.cpp b/src/modules/Telemetry/HealthTelemetry.cpp index 944bc4db413..dc6d2e8d0ee 100644 --- a/src/modules/Telemetry/HealthTelemetry.cpp +++ b/src/modules/Telemetry/HealthTelemetry.cpp @@ -132,8 +132,13 @@ void HealthTelemetryModule::drawFrame(OLEDDisplay *display, OLEDDisplayUiState * } // Display "Health From: ..." on its own + char agoStr[16]; + if (agoSecs == SINCE_UNKNOWN) + snprintf(agoStr, sizeof(agoStr), "?"); // no trustworthy arrival time to age against + else + snprintf(agoStr, sizeof(agoStr), "%us", (unsigned)agoSecs); char headerStr[64]; - snprintf(headerStr, sizeof(headerStr), "Health From: %s(%ds)", lastSender, (int)agoSecs); + snprintf(headerStr, sizeof(headerStr), "Health From: %s(%s)", lastSender, agoStr); display->drawString(x, y, headerStr); char last_temp[16]; diff --git a/src/modules/Telemetry/PowerTelemetry.cpp b/src/modules/Telemetry/PowerTelemetry.cpp index 23ef56ba8c5..4ec1adb1c49 100644 --- a/src/modules/Telemetry/PowerTelemetry.cpp +++ b/src/modules/Telemetry/PowerTelemetry.cpp @@ -154,8 +154,13 @@ void PowerTelemetryModule::drawFrame(OLEDDisplay *display, OLEDDisplayUiState *s } // Display "Pow. From: ..." + char agoStr[16]; + if (agoSecs == SINCE_UNKNOWN) + snprintf(agoStr, sizeof(agoStr), "?"); // no trustworthy arrival time to age against + else + snprintf(agoStr, sizeof(agoStr), "%us", (unsigned)agoSecs); char fromStr[64]; - snprintf(fromStr, sizeof(fromStr), "Pow. From: %s (%us)", lastSender, agoSecs); + snprintf(fromStr, sizeof(fromStr), "Pow. From: %s (%s)", lastSender, agoStr); display->drawString(x, graphics::getTextPositions(display)[line++], fromStr); // Display current and voltage based on ...power_metrics.has_[channel/voltage/current]... flags diff --git a/test/test_stream_api/test_main.cpp b/test/test_stream_api/test_main.cpp index b410c1e51b1..630102dbc5a 100644 --- a/test/test_stream_api/test_main.cpp +++ b/test/test_stream_api/test_main.cpp @@ -1,7 +1,7 @@ #include "MeshTypes.h" #include "SerialConsole.h" #include "TestUtil.h" -#include "Time.h" +#include "UptimeClock.h" #include "configuration.h" #include "gps/RTC.h" #include "mesh-pb-constants.h" @@ -617,9 +617,8 @@ static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packe PhoneAPITestShim api; startHandshake(api); - // rx_time is proto3 optional: with has_rx_time false, the field is omitted from the wire - // entirely (not just flagged invalid), so the decoded copy reads back 0, not the in-memory - // placeholder - the placeholder itself never left the device. + // rx_time is proto3 optional, so has_rx_time false omits it from the wire entirely: the + // decoded copy reads back 0 and the placeholder itself never left the device. meshtastic_MeshPacket delivered; TEST_ASSERT_TRUE_MESSAGE(drainHandshakeForPacketFrom(api, sender, delivered), "queued packet was not delivered during the handshake"); diff --git a/variants/native/portduino/platformio.ini b/variants/native/portduino/platformio.ini index 9d878d5f0c1..006a4d0b286 100644 --- a/variants/native/portduino/platformio.ini +++ b/variants/native/portduino/platformio.ini @@ -423,7 +423,7 @@ build_src_filter = + + + + + + + + - + + + + + + + + + + + + + + + + + + + + + From 2cc646ede30df4c23224c6c16cbfc809e45498c1 Mon Sep 17 00:00:00 2001 From: nomdetom Date: Wed, 29 Jul 2026 01:45:28 +0100 Subject: [PATCH 9/9] more test fixes --- test/test_stream_api/test_main.cpp | 41 ++++++++++++++++++------------ 1 file changed, 25 insertions(+), 16 deletions(-) diff --git a/test/test_stream_api/test_main.cpp b/test/test_stream_api/test_main.cpp index 630102dbc5a..5075fe461fb 100644 --- a/test/test_stream_api/test_main.cpp +++ b/test/test_stream_api/test_main.cpp @@ -566,16 +566,35 @@ static bool drainHandshakeForPacketFrom(PhoneAPITestShim &api, NodeNum from, mes return false; } +/// Swaps in a scratch NodeDB and the injected clock, restoring both plus the RTC on destruction. +/// Unity's TEST_ASSERT longjmps out on failure, so cleanup must not live at the end of the test. +class ScopedTimeFixture +{ + public: + ScopedTimeFixture(uint32_t startMillis) : previous(nodeDB) + { + resetRTCStateForTests(); + nodeDB = &instance; + Time::setTestMillis(startMillis); + } + ~ScopedTimeFixture() + { + nodeDB = previous; + Time::useRealClock(); + resetRTCStateForTests(); + } + + private: + NodeDB instance; + NodeDB *previous; +}; + // Time given at the start of the handshake, before the queued packet is drained: reconciliation // (fired by the RTC quality crossing hook in RTC.cpp) rewrites the placeholder in place. static void test_time_given_at_handshake_start_reconciles_queued_packet(void) { - resetRTCStateForTests(); ScopedMeshService scopedService; - NodeDB testNodeDB; - NodeDB *const savedNodeDB = nodeDB; - nodeDB = &testNodeDB; - Time::setTestMillis(5000); + ScopedTimeFixture timeFixture(5000); const NodeNum sender = 0x12345678; queuePendingTimePlaceholderPacket(sender, 2000); // "received" 3s before the test's current millis() @@ -595,21 +614,14 @@ static void test_time_given_at_handshake_start_reconciles_queued_packet(void) TEST_ASSERT_UINT32_WITHIN(2, (uint32_t)networkTime.tv_sec - 3, delivered.rx_time); api.close(); - nodeDB = savedNodeDB; - Time::useRealClock(); - resetRTCStateForTests(); } // Time given at the end - after the queued packet already left via the handshake: the delivered // copy keeps its unresolved placeholder, since reconciliation can only rewrite what's still queued. static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packet(void) { - resetRTCStateForTests(); ScopedMeshService scopedService; - NodeDB testNodeDB; - NodeDB *const savedNodeDB = nodeDB; - nodeDB = &testNodeDB; - Time::setTestMillis(5000); + ScopedTimeFixture timeFixture(5000); const NodeNum sender = 0x12345678; queuePendingTimePlaceholderPacket(sender, 2000); @@ -636,9 +648,6 @@ static void test_time_given_at_handshake_end_does_not_rewrite_already_sent_packe TEST_ASSERT_EQUAL_UINT32(0u, delivered.rx_time); api.close(); - nodeDB = savedNodeDB; - Time::useRealClock(); - resetRTCStateForTests(); } /// Unity per-test setup; fixtures are local to each test.