From 2024bb8384bdc60778d2fcf253e6b8aa22cfb311 Mon Sep 17 00:00:00 2001 From: Tom <116762865+NomDeTom@users.noreply.github.com> Date: Wed, 29 Jul 2026 15:03:25 +0100 Subject: [PATCH] Arrival time fix perhaps (#11274) * 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. * 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. * 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. * 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. * 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(). * 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. * tryfix CI * post review fixes * more test fixes --- protobufs | 2 +- src/UptimeClock.cpp | 33 +++++ src/UptimeClock.h | 46 +++++++ src/gps/RTC.cpp | 17 ++- src/mesh/MeshService.cpp | 43 +++++- src/mesh/MeshService.h | 5 + src/mesh/NodeDB.cpp | 8 +- src/mesh/NodeDB.h | 7 +- src/mesh/PhoneAPI.cpp | 19 +++ src/mesh/RadioInterface.cpp | 2 +- src/mesh/Router.cpp | 34 +++-- src/mesh/Router.h | 11 ++ src/mesh/generated/meshtastic/mesh.pb.h | 15 +- src/modules/MeshBeaconModule.cpp | 2 +- src/modules/NodeInfoModule.cpp | 5 +- src/modules/StoreForwardModule.cpp | 7 +- src/modules/StoreForwardModule.h | 2 + src/modules/Telemetry/HealthTelemetry.cpp | 7 +- src/modules/Telemetry/PowerTelemetry.cpp | 7 +- src/serialization/MeshPacketSerializer.cpp | 6 +- .../ports/test_timestamp.cpp | 37 +++++ .../test_meshpacket_serializer/test_helpers.h | 12 ++ .../test_serializer.cpp | 8 ++ test/test_stream_api/test_main.cpp | 130 ++++++++++++++++++ test/test_traffic_management/test_main.cpp | 1 + variants/native/portduino/platformio.ini | 2 +- 26 files changed, 436 insertions(+), 32 deletions(-) create mode 100644 src/UptimeClock.cpp create mode 100644 src/UptimeClock.h create mode 100644 test/test_meshpacket_serializer/ports/test_timestamp.cpp diff --git a/protobufs b/protobufs index 94cdec45a..cd290ba24 160000 --- a/protobufs +++ b/protobufs @@ -1 +1 @@ -Subproject commit 94cdec45ae729650d5a1b0cea356cad12747983b +Subproject commit cd290ba246fb5130cb449055248f7e22c15bcafb diff --git a/src/UptimeClock.cpp b/src/UptimeClock.cpp new file mode 100644 index 000000000..5f85f50ff --- /dev/null +++ b/src/UptimeClock.cpp @@ -0,0 +1,33 @@ +// See UptimeClock.h for the full contract. +#include "UptimeClock.h" +#include + +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(); +#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; + return (static_cast(highWord) << 32) | now; +} diff --git a/src/UptimeClock.h b/src/UptimeClock.h new file mode 100644 index 000000000..9329a7bf6 --- /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/gps/RTC.cpp b/src/gps/RTC.cpp index 94288529e..217bbb4c3 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,16 @@ uint32_t lastSetFromPhoneNtpOrGps = 0; static uint32_t lastTimeValidationWarning = 0; static const uint32_t TIME_VALIDATION_WARNING_INTERVAL_MS = 15000; // 15 seconds -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)); nodeInfoModule->triggerImmediateNodeInfoCheck(); } + if (oldQuality < RTCQualityFromNet && newQuality >= RTCQualityFromNet && service) { + LOG_DEBUG("RTC net quality reached (%s -> %s), reconciling rx_time", RtcName(oldQuality), RtcName(newQuality)); + service->reconcilePendingRxTimes(); + } } RTCQuality getRTCQuality() @@ -128,7 +133,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } else { @@ -174,7 +179,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } else { @@ -210,7 +215,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } @@ -235,7 +240,7 @@ RTCSetResult readFromRTC() timeStartMsec = now; zeroOffsetSecs = tv.tv_sec; currentQuality = RTCQualityDevice; - triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality); + onTimeSourceQualityChanged(oldQuality, currentQuality); } return RTCSetResultSuccess; } @@ -381,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 782b0dc73..2f3dbb1a5 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" @@ -180,6 +181,36 @@ NodeNum MeshService::getNodenumFromRequestId(uint32_t request_id) return nodenum; } +// 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); + if (nowEpoch == 0) // called before the clock was actually valid - nothing to reconcile against + return; + const uint32_t nowMillis = Time::getMillis(); + + // 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. + const uint32_t elapsedMs = nowMillis - p->rx_time; + p->rx_time = nowEpoch - (elapsedMs / 1000); + p->has_rx_time = true; + } + 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 + } + } +} + #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 +251,9 @@ void MeshService::injectAsReceived(meshtastic_MeshPacket &p) mp->rx_rssi = -40; mp->has_rx_rssi = true; } - mp->rx_time = getValidTime(RTCQualityFromNet); + // 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"); router->enqueueReceivedMessage(mp); @@ -258,7 +291,8 @@ 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. + 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 @@ -595,6 +629,11 @@ 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, and don't pass it off as "just now" either. + if (!mp->has_rx_time) + return SINCE_UNKNOWN; + uint32_t now = getTime(); uint32_t last_seen = mp->rx_time; diff --git a/src/mesh/MeshService.h b/src/mesh/MeshService.h index b529d2836..bae955969 100644 --- a/src/mesh/MeshService.h +++ b/src/mesh/MeshService.h @@ -137,6 +137,10 @@ class MeshService // search the queue for a request id and return the matching nodenum NodeNum getNodenumFromRequestId(uint32_t request_id); + // Rewrite any queued-for-phone packet still carrying a millis() rx_time placeholder into a + // real epoch, now that the wall clock is trustworthy. + void reconcilePendingRxTimes(); + // Release QueueStatus packet to pool void releaseQueueStatusToPool(meshtastic_QueueStatus *p) { queueStatusPool.release(p); } @@ -205,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 3c742e7ca..32e851d8b 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -3237,6 +3237,11 @@ 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, and don't pass it off as "just now" either. + if (!p->has_rx_time) + return SINCE_UNKNOWN; + uint32_t now = getTime(); int delta = (int)(now - p->rx_time); @@ -3633,7 +3638,8 @@ 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 + // 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; // Gate on the packet actually having been received over our own radio, not on rx_snr being diff --git a/src/mesh/NodeDB.h b/src/mesh/NodeDB.h index 5320c571b..152fdee1d 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 75385f03f..70d869bea 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,6 +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; + // 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); @@ -1285,6 +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; + // 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; @@ -1391,6 +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; + // 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; @@ -1456,6 +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; + // 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/RadioInterface.cpp b/src/mesh/RadioInterface.cpp index ec1b9c9cb..9c199f5a7 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 2ec9b43b3..cf0e05c9a 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" @@ -269,6 +270,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(); @@ -280,8 +294,8 @@ 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. + stampRxTime(p); return p; } @@ -1305,12 +1319,15 @@ 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. - const uint32_t rxTime = getValidTime(RTCQualityFromNet); - p->rx_time = rxTime; - if (p_encrypted) - p_encrypted->rx_time = rxTime; + // See computeRxTimeStamp() for the placeholder/has_rx_time semantics. + const RxTimeStamp rxStamp = computeRxTimeStamp(); + p->rx_time = rxStamp.time; + p->has_rx_time = rxStamp.valid; + if (p_encrypted) { + 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 auto decodedState = perhapsDecode(p); @@ -1443,7 +1460,8 @@ 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 before it's traced. + stampRxTime(p); LOG_TRACE("%s", MeshPacketSerializer::JsonSerializeEncrypted(p).c_str()); } #endif diff --git a/src/mesh/Router.h b/src/mesh/Router.h index 4a6356cb5..be686ee15 100644 --- a/src/mesh/Router.h +++ b/src/mesh/Router.h @@ -10,6 +10,17 @@ #include "concurrency/OSThread.h" #include +/// 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; +}; +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/mesh/generated/meshtastic/mesh.pb.h b/src/mesh/generated/meshtastic/mesh.pb.h index 637aae3ab..60d817d73 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 2e9d865a6..cc5c6e807 100644 --- a/src/modules/MeshBeaconModule.cpp +++ b/src/modules/MeshBeaconModule.cpp @@ -342,7 +342,7 @@ 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); + stampRxTime(p); }; // ── Packet type decisions ──────────────────────────────────────────────── diff --git a/src/modules/NodeInfoModule.cpp b/src/modules/NodeInfoModule.cpp index 5b8d46223..cf6180ca2 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" @@ -33,7 +34,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(); + // 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 3c6d2de7d..bd023716a 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); @@ -201,6 +204,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; @@ -257,9 +261,10 @@ 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; + 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 = 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 77565b22c..82406b70a 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; @@ -21,6 +22,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; diff --git a/src/modules/Telemetry/HealthTelemetry.cpp b/src/modules/Telemetry/HealthTelemetry.cpp index 944bc4db4..dc6d2e8d0 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 23ef56ba8..4ec1adb1c 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/src/serialization/MeshPacketSerializer.cpp b/src/serialization/MeshPacketSerializer.cpp index 88d134496..f889c4f3c 100644 --- a/src/serialization/MeshPacketSerializer.cpp +++ b/src/serialization/MeshPacketSerializer.cpp @@ -420,7 +420,8 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, } jsonObj["id"] = (Json::UInt)mp->id; - jsonObj["timestamp"] = (Json::UInt)mp->rx_time; + // 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; jsonObj["channel"] = (Json::UInt)mp->channel; @@ -452,7 +453,8 @@ 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; + // 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; jsonObj["channel"] = (Json::UInt)mp->channel; 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 000000000..333945f80 --- /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 da8c89fff..2dc06cec7 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; @@ -62,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 484db8d74..58483ff91 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 1fbd370a0..5075fe461 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 "UptimeClock.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,131 @@ 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; +} + +/// 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) +{ + ScopedMeshService scopedService; + ScopedTimeFixture timeFixture(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(); +} + +// 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) +{ + ScopedMeshService scopedService; + ScopedTimeFixture timeFixture(5000); + + const NodeNum sender = 0x12345678; + queuePendingTimePlaceholderPacket(sender, 2000); + + PhoneAPITestShim api; + startHandshake(api); + + // 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"); + 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(); +} + /// Unity per-test setup; fixtures are local to each test. void setUp(void) {} /// Unity per-test teardown; fixtures clean themselves up. @@ -544,6 +672,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()); diff --git a/test/test_traffic_management/test_main.cpp b/test/test_traffic_management/test_main.cpp index afdcb9646..34f5a5456 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)); diff --git a/variants/native/portduino/platformio.ini b/variants/native/portduino/platformio.ini index 22fb6223c..006a4d0b2 100644 --- a/variants/native/portduino/platformio.ini +++ b/variants/native/portduino/platformio.ini @@ -423,7 +423,7 @@ build_src_filter = + + + + + + + + - + + + + + + + + + + + + + + + + + + + +