Fix TransmitHistory to improve epoch handling (#10017)

* Fix TransmitHistory to improve epoch handling

* Enable epoch handling in unit tests

* Improve comments and test handling for epoch persistence in TransmitHistory

* Add boot-relative timestamp handling and unit tests for TransmitHistory

* loadFromDisk should handle legacy entries and clean up old v1 files after migration

* Revert "loadFromDisk should handle legacy entries and clean up old v1 files after migration"

This reverts commit eb7e5c7acfa4ac077fe50980be752e4b42a739b8.

* Add NodeInfoModule integration for RTC quality changes and trigger immediate checks

* Update test conditions for RTC quality checks
This commit is contained in:
Ben Meadors
2026-03-27 15:38:41 -05:00
committed by GitHub
co-authored by GitHub
parent 068f5af4d8
commit 99abfebc4a
8 changed files with 344 additions and 62 deletions
+28
View File
@@ -2,6 +2,7 @@
#include "configuration.h"
#include "detect/ScanI2C.h"
#include "main.h"
#include "modules/NodeInfoModule.h"
#include <Throttle.h>
#include <sys/time.h>
#include <time.h>
@@ -12,6 +13,14 @@ 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)
{
if (oldQuality == RTCQualityNone && newQuality > RTCQualityNone && nodeInfoModule) {
LOG_DEBUG("Time source acquired (%s -> %s), triggering NodeInfo recheck", RtcName(oldQuality), RtcName(newQuality));
nodeInfoModule->triggerImmediateNodeInfoCheck();
}
}
RTCQuality getRTCQuality()
{
return currentQuality;
@@ -61,9 +70,11 @@ RTCSetResult readFromRTC()
LOG_DEBUG("Read RTC time from RV3028 getTime as %02d-%02d-%02d %02d:%02d:%02d (%ld)", t.tm_year + 1900, t.tm_mon + 1,
t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec, printableEpoch);
if (currentQuality == RTCQualityNone) {
RTCQuality oldQuality = currentQuality;
timeStartMsec = now;
zeroOffsetSecs = tv.tv_sec;
currentQuality = RTCQualityDevice;
triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality);
}
return RTCSetResultSuccess;
} else {
@@ -105,9 +116,11 @@ RTCSetResult readFromRTC()
LOG_DEBUG("Read RTC time from %s getDateTime as %02d-%02d-%02d %02d:%02d:%02d (%ld)", rtc.getChipName(), t.tm_year + 1900,
t.tm_mon + 1, t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec, printableEpoch);
if (currentQuality == RTCQualityNone) {
RTCQuality oldQuality = currentQuality;
timeStartMsec = now;
zeroOffsetSecs = tv.tv_sec;
currentQuality = RTCQualityDevice;
triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality);
}
return RTCSetResultSuccess;
} else {
@@ -139,9 +152,11 @@ RTCSetResult readFromRTC()
}
#endif
if (currentQuality == RTCQualityNone) {
RTCQuality oldQuality = currentQuality;
timeStartMsec = now;
zeroOffsetSecs = tv.tv_sec;
currentQuality = RTCQualityDevice;
triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality);
}
return RTCSetResultSuccess;
}
@@ -214,6 +229,7 @@ RTCSetResult perhapsSetRTC(RTCQuality q, const struct timeval *tv, bool forceUpd
}
if (shouldSet) {
RTCQuality oldQuality = currentQuality;
currentQuality = q;
lastSetMsec = now;
if (currentQuality >= RTCQualityNTP) {
@@ -281,6 +297,7 @@ RTCSetResult perhapsSetRTC(RTCQuality q, const struct timeval *tv, bool forceUpd
#endif
readFromRTC();
triggerNodeInfoCheckOnTimeSource(oldQuality, currentQuality);
return RTCSetResultSuccess;
} else {
return RTCSetResultNotSet; // RTC was already set with a higher quality time
@@ -397,6 +414,17 @@ uint32_t getValidTime(RTCQuality minQuality, bool local)
return (currentQuality >= minQuality) ? getTime(local) : 0;
}
#ifdef PIO_UNIT_TESTING
void setBootRelativeTimeForUnitTest(uint32_t secondsSinceBoot)
{
currentQuality = RTCQualityNone;
zeroOffsetSecs = 0;
timeStartMsec = millis() - (secondsSinceBoot * 1000);
lastSetFromPhoneNtpOrGps = 0;
lastTimeValidationWarning = 0;
}
#endif
time_t gm_mktime(const struct tm *tm)
{
#if !MESHTASTIC_EXCLUDE_TZ
+4
View File
@@ -54,6 +54,10 @@ uint32_t getValidTime(RTCQuality minQuality, bool local = false);
RTCSetResult readFromRTC();
#ifdef PIO_UNIT_TESTING
void setBootRelativeTimeForUnitTest(uint32_t secondsSinceBoot);
#endif
time_t gm_mktime(const struct tm *tm);
#define SEC_PER_DAY 86400
+2 -1
View File
@@ -31,5 +31,6 @@ bool Throttle::execute(uint32_t *lastExecutionMs, uint32_t minumumIntervalMs, vo
/// @param timeSpanMs The interval in milliseconds of the timespan
bool Throttle::isWithinTimespanMs(uint32_t lastExecutionMs, uint32_t timeSpanMs)
{
return (millis() - lastExecutionMs) < timeSpanMs;
uint32_t now = millis();
return (now - lastExecutionMs) < timeSpanMs;
}
+127 -36
View File
@@ -16,6 +16,20 @@ TransmitHistory *TransmitHistory::getInstance()
return transmitHistory;
}
TransmitHistory::StoredTimestamp TransmitHistory::makeStoredTimestamp(uint32_t seconds, uint8_t flags)
{
StoredTimestamp stored;
stored.seconds = seconds;
stored.flags = flags;
return stored;
}
TransmitHistory::StoredTimestamp TransmitHistory::decodeLegacyTimestamp(uint32_t seconds)
{
const bool isProbablyBootRelative = seconds > 0 && seconds <= LEGACY_BOOT_RELATIVE_MAX_SEC;
return makeStoredTimestamp(seconds, isProbablyBootRelative ? ENTRY_FLAG_BOOT_RELATIVE : ENTRY_FLAG_NONE);
}
void TransmitHistory::loadFromDisk()
{
spiLock->lock();
@@ -23,16 +37,33 @@ void TransmitHistory::loadFromDisk()
if (file) {
FileHeader header{};
if (file.read((uint8_t *)&header, sizeof(header)) == sizeof(header) && header.magic == MAGIC &&
header.version == VERSION && header.count <= MAX_ENTRIES) {
(header.version == 1 || header.version == VERSION) && header.count <= MAX_ENTRIES) {
for (uint8_t i = 0; i < header.count; i++) {
Entry entry{};
if (file.read((uint8_t *)&entry, sizeof(entry)) == sizeof(entry)) {
if (entry.epochSeconds > 0) {
history[entry.key] = entry.epochSeconds;
// Seed in-memory millis so throttle works even without RTC/GPS.
// Treating stored entries as "just sent" is safe — worst case the
// node waits one full interval before its first broadcast.
lastMillis[entry.key] = millis();
if (header.version == 1) {
LegacyEntry entry{};
if (file.read((uint8_t *)&entry, sizeof(entry)) == sizeof(entry) && entry.epochSeconds > 0) {
history[entry.key] = decodeLegacyTimestamp(entry.epochSeconds);
}
} else {
Entry entry{};
if (file.read((uint8_t *)&entry, sizeof(entry)) == sizeof(entry) && entry.epochSeconds > 0) {
history[entry.key] = makeStoredTimestamp(entry.epochSeconds, entry.flags);
// Do NOT seed lastMillis here.
//
// getLastSentToMeshMillis() reconstructs a millis()-relative value
// from the stored epoch, and Throttle::isWithinTimespanMs() uses
// the same unsigned subtraction pattern. Once getTime() has a valid
// wall-clock epoch comparable to stored values, recent reboots still
// throttle correctly while long power-off periods no longer look like
// "just sent" and incorrectly suppress the first send.
//
// Before RTC/NTP/GPS time is valid, persisted absolute epochs do not
// contribute, but boot-relative entries still suppress near-term reboot
// chatter via a narrow recovery window.
//
// If we seeded lastMillis to millis() here, every loaded entry would
// appear to have been sent at boot time, regardless of the true age
// of the last transmission. That was the regression behind #9901.
}
}
}
@@ -53,7 +84,8 @@ void TransmitHistory::setLastSentToMesh(uint16_t key)
lastMillis[key] = millis();
uint32_t now = getTime();
if (now >= 2) {
history[key] = now;
const uint8_t flags = (getRTCQuality() == RTCQualityNone) ? ENTRY_FLAG_BOOT_RELATIVE : ENTRY_FLAG_NONE;
history[key] = makeStoredTimestamp(now, flags);
dirty = true;
// Don't flush to disk on every transmit — flash has limited write endurance.
// The in-memory lastMillis map handles throttle during normal operation.
@@ -68,15 +100,84 @@ void TransmitHistory::setLastSentToMesh(uint16_t key)
}
}
#ifdef PIO_UNIT_TESTING
void TransmitHistory::setLastSentAtEpoch(uint16_t key, uint32_t epochSeconds)
{
if (epochSeconds > 0) {
history[key] = makeStoredTimestamp(epochSeconds, ENTRY_FLAG_NONE);
dirty = true;
} else {
history.erase(key);
lastMillis.erase(key);
}
}
void TransmitHistory::setLastSentAtBootRelative(uint16_t key, uint32_t secondsSinceBoot)
{
if (secondsSinceBoot > 0) {
history[key] = makeStoredTimestamp(secondsSinceBoot, ENTRY_FLAG_BOOT_RELATIVE);
dirty = true;
} else {
history.erase(key);
lastMillis.erase(key);
}
}
#endif
uint32_t TransmitHistory::getLastSentToMeshEpoch(uint16_t key) const
{
auto it = history.find(key);
if (it != history.end()) {
return it->second;
return it->second.seconds;
}
return 0;
}
uint32_t TransmitHistory::getLastSentAbsoluteMillis(uint32_t storedEpoch) const
{
uint32_t now = getTime();
if (now < 2) {
return 0;
}
if (storedEpoch > now) {
return 0;
}
uint32_t secondsAgo = now - storedEpoch;
uint32_t msAgo = secondsAgo * 1000;
if (secondsAgo > 86400 || msAgo / 1000 != secondsAgo) {
return 0;
}
return millis() - msAgo;
}
uint32_t TransmitHistory::getLastSentBootRelativeMillis(uint32_t storedSeconds) const
{
if (getRTCQuality() != RTCQualityNone) {
return 0;
}
uint32_t now = getTime();
if (storedSeconds <= now) {
uint32_t secondsAgo = now - storedSeconds;
if (secondsAgo > BOOT_RELATIVE_RECOVERY_WINDOW_SEC) {
return 0;
}
return millis() - (secondsAgo * 1000);
}
uint32_t secondsAhead = storedSeconds - now;
if (secondsAhead > BOOT_RELATIVE_RECOVERY_WINDOW_SEC) {
return 0;
}
return millis();
}
uint32_t TransmitHistory::getLastSentToMeshMillis(uint16_t key) const
{
// Prefer runtime millis value (accurate within this boot)
@@ -86,34 +187,23 @@ uint32_t TransmitHistory::getLastSentToMeshMillis(uint16_t key) const
}
// Fall back to epoch conversion (loaded from disk after reboot)
uint32_t storedEpoch = getLastSentToMeshEpoch(key);
if (storedEpoch == 0) {
auto it = history.find(key);
if (it == history.end() || it->second.seconds == 0) {
return 0; // No stored time — module has never sent
}
uint32_t now = getTime();
if (now < 2) {
// No valid RTC time yet — can't convert to millis. Return 0 so throttle doesn't block.
return 0;
// Convert to a millis()-relative timestamp: millis() - msAgo.
//
// The result may wrap if msAgo is larger than the current uptime, and that is
// intentional. Throttle::isWithinTimespanMs() also uses unsigned subtraction,
// so the reconstructed age is preserved across wraparound:
// - recent reboot, 5 min ago -> (millis() - lastMs) == 300000, still throttled
// - long reboot, 30 min ago -> (millis() - lastMs) == 1800000, allowed
if ((it->second.flags & ENTRY_FLAG_BOOT_RELATIVE) != 0) {
return getLastSentBootRelativeMillis(it->second.seconds);
}
if (storedEpoch > now) {
// Stored time is in the future (clock went backwards?) — treat as stale
return 0;
}
uint32_t secondsAgo = now - storedEpoch;
uint32_t msAgo = secondsAgo * 1000;
// Guard against overflow: if the transmit was very long ago, just return 0 (won't throttle)
if (secondsAgo > 86400 || msAgo / 1000 != secondsAgo) {
return 0;
}
// Convert to a millis()-relative timestamp: millis() - msAgo
// This gives a value that, when passed to Throttle::isWithinTimespanMs(value, interval),
// correctly reports whether the transmit was within interval ms.
return millis() - msAgo;
return getLastSentAbsoluteMillis(it->second.seconds);
}
bool TransmitHistory::saveToDisk()
@@ -141,12 +231,13 @@ bool TransmitHistory::saveToDisk()
file.write((uint8_t *)&header, sizeof(header));
uint8_t written = 0;
for (const auto &[key, epochSeconds] : history) {
for (const auto &[key, stored] : history) {
if (written >= MAX_ENTRIES)
break;
Entry entry{};
entry.key = key;
entry.epochSeconds = epochSeconds;
entry.epochSeconds = stored.seconds;
entry.flags = stored.flags;
file.write((uint8_t *)&entry, sizeof(entry));
written++;
}
+44 -4
View File
@@ -35,8 +35,25 @@ class TransmitHistory
*/
void setLastSentToMesh(uint16_t key);
#ifdef PIO_UNIT_TESTING
/**
* Get the last transmit epoch seconds for a given key, or 0 if unknown.
* Directly set the stored epoch for a key without touching the runtime lastMillis map.
* Intended for testing purposes: lets tests simulate "the last broadcast happened N
* seconds ago" without needing to fake the system clock.
*/
void setLastSentAtEpoch(uint16_t key, uint32_t epochSeconds);
/**
* Directly set a boot-relative timestamp (seconds since boot) for testing.
*/
void setLastSentAtBootRelative(uint16_t key, uint32_t secondsSinceBoot);
#endif
/**
* Get the raw persisted timestamp seconds for a given key, or 0 if unknown.
*
* The returned value is an absolute epoch when persisted with valid RTC/NTP/GPS time,
* or boot-relative seconds when ENTRY_FLAG_BOOT_RELATIVE is set.
*/
uint32_t getLastSentToMeshEpoch(uint16_t key) const;
@@ -64,13 +81,31 @@ class TransmitHistory
static constexpr const char *FILENAME = "/prefs/transmit_history.dat";
static constexpr uint32_t MAGIC = 0x54485354; // "THST"
static constexpr uint8_t VERSION = 1;
static constexpr uint8_t VERSION = 2;
static constexpr uint8_t MAX_ENTRIES = 16;
static constexpr uint32_t SAVE_INTERVAL_MS = 5 * 60 * 1000; // 5 minutes
static constexpr uint32_t BOOT_RELATIVE_RECOVERY_WINDOW_SEC = 2 * 60;
static constexpr uint32_t LEGACY_BOOT_RELATIVE_MAX_SEC = 365UL * 24 * 60 * 60;
enum EntryFlags : uint8_t {
ENTRY_FLAG_NONE = 0,
ENTRY_FLAG_BOOT_RELATIVE = 0x01,
};
struct StoredTimestamp {
uint32_t seconds = 0;
uint8_t flags = ENTRY_FLAG_NONE;
};
struct __attribute__((packed)) Entry {
uint16_t key;
uint32_t epochSeconds;
uint8_t flags;
};
struct __attribute__((packed)) LegacyEntry {
uint16_t key;
uint32_t epochSeconds;
};
struct __attribute__((packed)) FileHeader {
@@ -79,8 +114,13 @@ class TransmitHistory
uint8_t count;
};
std::map<uint16_t, uint32_t> history; // key -> epoch seconds (for disk persistence)
std::map<uint16_t, uint32_t> lastMillis; // key -> millis() value (for runtime throttle)
uint32_t getLastSentAbsoluteMillis(uint32_t storedEpoch) const;
uint32_t getLastSentBootRelativeMillis(uint32_t storedSeconds) const;
static StoredTimestamp makeStoredTimestamp(uint32_t seconds, uint8_t flags = ENTRY_FLAG_NONE);
static StoredTimestamp decodeLegacyTimestamp(uint32_t seconds);
std::map<uint16_t, StoredTimestamp> history; // key -> persisted transmit time
std::map<uint16_t, uint32_t> lastMillis; // key -> millis() value (for runtime throttle)
bool dirty = false;
uint32_t lastDiskSave = 0; // millis() of last disk flush
};
+6
View File
@@ -118,6 +118,12 @@ void NodeInfoModule::sendOurNodeInfo(NodeNum dest, bool wantReplies, uint8_t cha
}
}
void NodeInfoModule::triggerImmediateNodeInfoCheck()
{
LOG_DEBUG("NodeInfo: scheduling immediate periodic check");
setIntervalFromNow(0);
}
meshtastic_MeshPacket *NodeInfoModule::allocReply()
{
// Only apply suppression when actually replying to someone else's request, not for periodic broadcasts.
+6
View File
@@ -24,6 +24,12 @@ class NodeInfoModule : public ProtobufModule<meshtastic_User>, private concurren
void sendOurNodeInfo(NodeNum dest = NODENUM_BROADCAST, bool wantReplies = false, uint8_t channel = 0,
bool _shorterTimeout = false);
/**
* Schedule an immediate NodeInfo periodic check.
* Used when external conditions change (for example time source quality).
*/
void triggerImmediateNodeInfoCheck();
protected:
/** Called to handle a particular incoming message