diff --git a/docs/cli_commands.md b/docs/cli_commands.md index b27cd3213..eeb3f9ded 100644 --- a/docs/cli_commands.md +++ b/docs/cli_commands.md @@ -856,6 +856,20 @@ battery packet overlaps its predecessor by 34.5 hours. Packets are paced two seconds apart. A queue failure is retried after 30 minutes only for the packet that did not queue; successfully queued packets are not duplicated. +`get telemetry.tx` includes the source ID, path, and age of this node's last +completed telemetry transmission: + +```text +> on 2d id=0123456789ABCDEF i2c=0 last=30m p=direct +``` + +`last` uses seconds, minutes, or hours (`30s`, `30m`, `2h`; two days is `48h`). +It counts completed sends and retries of this node's `TTB1`, `TVB1`, `IVB1`, +`N1B1`, or `N2B1` packets, including manual sends while the schedule is off. +Queue acceptance and relayed telemetry do not update it, and it does not confirm +observer receipt. It shows `last=never` until the first completed send after a +reboot. The age uses uptime, so clock corrections do not affect it. + `send telemetry.tx now` is an administrator-only test action. It queues temperature and battery-voltage snapshots plus the available I2C voltage chunks over the configured path. It also queues one main-radio `N1B1` packet diff --git a/docs/telemetry_decoder.md b/docs/telemetry_decoder.md index 35902064c..b1669df96 100644 --- a/docs/telemetry_decoder.md +++ b/docs/telemetry_decoder.md @@ -71,6 +71,14 @@ can be Missing; failed measurements do not silently shorten the timeline. The existing automatic transmission cadence is unchanged. Recording a new noise-floor position every 15 minutes does not transmit a packet every 15 minutes. +Use `get telemetry.tx` to see the source ID, path, and `last=30s`, `last=30m`, +or `last=2h` for the age of this node's latest completed telemetry transmission. +The age includes completed retries and manual sends while the schedule is off, +but excludes queue acceptance and relayed packets; it does not confirm observer +receipt. It shows `last=never` until the first completed send after each reboot. +The age uses uptime rather than the clock, and durations of a day or more remain +in hours, such as `last=48h`. + Schedule changes are saved transactionally; a failed write does not truncate the previous preferences. A legacy route must be successfully migrated into `data.tx` before its schedule can run. Corrupt, unreadable, or ambiguously diff --git a/examples/simple_repeater/MyMesh.cpp b/examples/simple_repeater/MyMesh.cpp index ad4b2198f..3796dd4d3 100644 --- a/examples/simple_repeater/MyMesh.cpp +++ b/examples/simple_repeater/MyMesh.cpp @@ -1289,6 +1289,9 @@ void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { } void MyMesh::logTx(mesh::Packet *pkt, int len) { +#if MESH_ENABLE_TELEMETRY_HISTORY + recordTelemetryHistoryTx(pkt); +#endif #ifdef WITH_UDP_BRIDGE if (_prefs.bridge_pkt_src == 0 && isUDPBridgeRunning()) udp_bridge->sendPacket(pkt); #endif @@ -3742,6 +3745,7 @@ MyMesh::MyMesh(mesh::MainBoard &board, mesh::Radio &radio, mesh::MillisecondCloc telemetry_history_tx_external_chunk = 0; telemetry_history_next_tx_uptime = 0; telemetry_history_tx_resume_uptime = 0; + telemetry_history_last_tx_uptime = UINT64_MAX; #endif #if MAX_NEIGHBOURS @@ -12434,7 +12438,7 @@ void MyMesh::handleCommand(uint32_t sender_timestamp, ClientInfo* sender, char * if (sender != NULL && !sender->isAdmin()) { strcpy(reply, "Err - not permitted"); } else { - formatTelemetryHistoryTxStatus(reply, 160); + formatTelemetryHistoryTxStatus(reply, prefixed_reply ? 157 : 160); } return; } @@ -13341,6 +13345,15 @@ bool MyMesh::saveTelemetryHistoryTxPrefs() { return success; } +void MyMesh::recordTelemetryHistoryTx(const mesh::Packet* packet) { + if (packet->getPayloadType() != PAYLOAD_TYPE_RAW_CUSTOM || packet->forwarded + || !isTelemetryHistoryPayload(packet) + || memcmp(packet->payload + 4, self_id.pub_key, + mesh::TelemetryHistory::BINARY_SOURCE_ID_SIZE) != 0) return; + telemetry_history_last_tx_uptime = + uptime_millis + (uint32_t)(millis() - last_millis); +} + void MyMesh::formatTelemetryHistoryTxStatus(char* reply, size_t reply_size) const { char source_id[mesh::TelemetryHistory::BINARY_SOURCE_ID_SIZE * 2U + 1U]; @@ -13352,11 +13365,18 @@ void MyMesh::formatTelemetryHistoryTxStatus(char* reply, char path_reply[132]; formatPathReply(data_path, have_path ? data_path_len : OUT_PATH_UNKNOWN, path_reply, sizeof(path_reply)); - snprintf(reply, reply_size, "> %s%ud id=%s i2c=%u%s p=%s", + char last[16] = "never"; + if (telemetry_history_last_tx_uptime != UINT64_MAX) { + const uint64_t now = uptime_millis + (uint32_t)(millis() - last_millis); + mesh::cli::formatRecentRepeaterAge(last, sizeof(last), + (uint32_t)((now - telemetry_history_last_tx_uptime) / 1000U)); + } + snprintf(reply, reply_size, "> %s%ud id=%s i2c=%u last=%s%s p=%s", telemetry_history_tx_enabled ? "on " : "off ", (unsigned)telemetry_history_tx_interval_days, source_id, (unsigned)external_voltage_history.populatedChannelCount(), + last, telemetry_history_tx_prefs_healthy ? "" : " fault=prefs", path_reply[0] == '>' && path_reply[1] == ' ' ? path_reply + 2 : path_reply); diff --git a/examples/simple_repeater/MyMesh.h b/examples/simple_repeater/MyMesh.h index 15450ac99..0bb4aea4f 100644 --- a/examples/simple_repeater/MyMesh.h +++ b/examples/simple_repeater/MyMesh.h @@ -595,6 +595,7 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks uint8_t telemetry_history_tx_external_chunk; uint64_t telemetry_history_next_tx_uptime; uint64_t telemetry_history_tx_resume_uptime; + uint64_t telemetry_history_last_tx_uptime; #endif unsigned long _ota_update_at = 0; // deferred `ota update` fire time (0 = none scheduled) float active_bw; // live BW, including temporary radio overrides @@ -883,6 +884,7 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks bool sendExternalVoltageHistorySnapshot(uint8_t channel_index, uint8_t chunk_index); void formatTelemetryHistoryTxStatus(char* reply, size_t reply_size) const; + void recordTelemetryHistoryTx(const mesh::Packet* packet); #endif void sendSelfAdvertisementNow(uint32_t delay_millis, bool flood); bool sendRepeatersFloodText(const char* text, const TransportKey* scope = nullptr, diff --git a/src/Mesh.cpp b/src/Mesh.cpp index c77c2419a..b64a5fafc 100644 --- a/src/Mesh.cpp +++ b/src/Mesh.cpp @@ -58,7 +58,7 @@ static bool hasValidEncryptedPayloadLength(uint16_t payload_len, uint16_t clear_ return ((payload_len - overhead) % CIPHER_BLOCK_SIZE) == 0; } -static bool isTelemetryHistoryPayload(const Packet* packet) { +bool Mesh::isTelemetryHistoryPayload(const Packet* packet) { const uint8_t* data = packet->payload; const uint16_t length = packet->payload_len; if ((uint16_t)(length - 20U) > MAX_PACKET_PAYLOAD - 20U diff --git a/src/Mesh.h b/src/Mesh.h index ea293cce1..fc93fe85b 100644 --- a/src/Mesh.h +++ b/src/Mesh.h @@ -219,6 +219,8 @@ class Mesh : public Dispatcher { DispatcherAction forwardMultipartDirect(Packet* pkt, uint32_t delay_millis); protected: + static bool isTelemetryHistoryPayload(const Packet* packet); + // Roles with lazily persisted state can veto an OTA reset until that state // is durable. The OTA apply remains armed and is retried later. virtual bool prepareForOtaReboot() { return true; } diff --git a/test/fixtures/telemetry_tx_persistence/fixture.cpp b/test/fixtures/telemetry_tx_persistence/fixture.cpp index 5d260c61d..d5e338039 100644 --- a/test/fixtures/telemetry_tx_persistence/fixture.cpp +++ b/test/fixtures/telemetry_tx_persistence/fixture.cpp @@ -11,12 +11,15 @@ #include #include #include +#include #include #include #include #include #define MAX_PATH_SIZE 64 +#define MAX_PACKET_PAYLOAD 184 +#define PAYLOAD_TYPE_RAW_CUSTOM 15 #define OUT_PATH_UNKNOWN 0xff #define OUT_PATH_FORCE_FLOOD 0xfe #define MESH_DEBUG_PRINTLN(...) do {} while (0) @@ -39,10 +42,17 @@ struct Packet { uint8_t payload[184] = {}; size_t payload_len = 0; uint8_t path_len = 0, path[MAX_PATH_SIZE] = {}; + uint8_t payload_type = PAYLOAD_TYPE_RAW_CUSTOM; + bool forwarded = false; + uint8_t getPayloadType() const { return payload_type; } static bool isValidPathLen(uint8_t); static size_t writePath(uint8_t*, const uint8_t*, uint8_t); static uint8_t copyPath(uint8_t*, const uint8_t*, uint8_t); }; +class Mesh { +protected: + static bool isTelemetryHistoryPayload(const Packet*); +}; struct Utils { static void toHex(char*, const uint8_t*, size_t); }; struct DataRouteState; } @@ -75,7 +85,7 @@ public: } }; struct ClientInfo { bool admin = true; bool isAdmin() const { return admin; } }; -class MyMesh { +class MyMesh : public mesh::Mesh { public: FILESYSTEM* _fs; CommonCLI _cli; @@ -94,6 +104,7 @@ public: uint8_t telemetry_history_tx_external_chunk = 0; uint64_t telemetry_history_next_tx_uptime = 0; uint64_t telemetry_history_tx_resume_uptime = 0; + uint64_t telemetry_history_last_tx_uptime = UINT64_MAX; uint64_t uptime_millis = 0; uint32_t last_millis = 0; std::vector packets; @@ -108,6 +119,7 @@ public: bool sendExternalVoltageHistorySnapshot(uint8_t, uint8_t); bool sendNoiseFloorHistorySnapshot(uint8_t); void formatTelemetryHistoryTxStatus(char*, size_t) const; + void recordTelemetryHistoryTx(const mesh::Packet*); void handle(char*, char*, ClientInfo*); // Radio queue boundary. Payload formatting and producer scheduling are real. mesh::Packet* createRawData(const uint8_t* data, size_t size) { @@ -670,6 +682,158 @@ static void checkNoiseHistoryRetries() { assert(disabled.node.packets.size() == 3); } +static std::string txStatus(const MyMesh& node) { + char reply[160]; + node.formatTelemetryHistoryTxStatus(reply, sizeof(reply)); + return reply; +} + +static void expectLastTx(const MyMesh& node, const char* age) { + assert(txStatus(node).find(std::string(" last=") + age + " ") != std::string::npos); +} + +static std::vector historyPackets(Fixture& f) { + f.history(); f.noiseHistory(); + const uint8_t channel = 7; + assert(f.node.external_voltage_history.configure(&channel, 1)); + const mesh::ExternalVoltageHistory::Reading reading = {channel, 12.5f, true}; + f.node.external_voltage_history.record(1000000, &reading, 1); + assert(f.node.sendTelemetryHistorySnapshot(mesh::TelemetryHistory::SERIES_TEMPERATURE)); + assert(f.node.sendTelemetryHistorySnapshot(mesh::TelemetryHistory::SERIES_VOLTAGE)); + assert(f.node.sendExternalVoltageHistorySnapshot(0, 0)); + assert(f.node.sendNoiseFloorHistorySnapshot(0)); + assert(f.node.sendNoiseFloorHistorySnapshot(1)); + assert(f.node.packets.size() == 5); + return f.node.packets; +} + +static void checkLastTxCompletionAndOwnership() { + Fixture f; f.boot(); + for (unsigned i = 0; i < 8; ++i) f.node.self_id.pub_key[i] = uint8_t(0x90 + i); + expectLastTx(f.node, "never"); + const auto packets = historyPackets(f); + expectLastTx(f.node, "never"); // queue acceptance is not a completed RF send + for (const auto& packet : packets) { + f.node.uptime_millis += 1000; + f.node.last_millis = test_millis; + f.node.recordTelemetryHistoryTx(&packet); + assert(f.node.telemetry_history_last_tx_uptime == f.node.uptime_millis); + expectLastTx(f.node, "0s"); + } + + const uint64_t completed = f.node.telemetry_history_last_tx_uptime; + f.node.uptime_millis += 30000; + for (const auto& valid : packets) { + auto other = valid; + other.payload_type = 5; + f.node.recordTelemetryHistoryTx(&other); + other = valid; other.forwarded = true; + f.node.recordTelemetryHistoryTx(&other); + other = valid; other.payload[4] ^= 1; + f.node.recordTelemetryHistoryTx(&other); + for (const unsigned offset : {2U, 3U, 16U, 18U}) { + other = valid; + if (offset == 16) other.payload[16] = other.payload[17] = 0; + else other.payload[offset] = 0; + f.node.recordTelemetryHistoryTx(&other); + } + other = valid; --other.payload_len; + f.node.recordTelemetryHistoryTx(&other); + other = valid; other.payload_len = 0; + f.node.recordTelemetryHistoryTx(&other); + other = valid; other.payload_len = MAX_PACKET_PAYLOAD + 1; + f.node.recordTelemetryHistoryTx(&other); + assert(f.node.telemetry_history_last_tx_uptime == completed); + } + expectLastTx(f.node, "30s"); + + f.node.reject_magic = "TTB1"; f.node.rejected_sends = 1; + assert(!f.node.sendTelemetryHistorySnapshot(mesh::TelemetryHistory::SERIES_TEMPERATURE)); + assert(f.node.telemetry_history_last_tx_uptime == completed); + expectLastTx(f.node, "30s"); + // A completed echo retry is another RF transmission and refreshes the age. + f.node.recordTelemetryHistoryTx(&packets.front()); + expectLastTx(f.node, "0s"); + assert(f.node.telemetry_history_last_tx_uptime == completed + 30000); +} + +static void checkLastTxAgeAndClockWrap() { + Fixture f; f.boot(); + const auto packets = historyPackets(f); + f.node.uptime_millis = 100000; + f.node.last_millis = test_millis; + f.node.recordTelemetryHistoryTx(&packets.front()); + struct AgeCase { uint32_t seconds; const char* text; }; + for (const auto& age : {AgeCase{0, "0s"}, {30, "30s"}, {59, "59s"}, + {60, "1m"}, {1800, "30m"}, {3600, "1h"}, + {7200, "2h"}, {172800, "48h"}}) { + f.node.uptime_millis = 100000 + uint64_t(age.seconds) * 1000; + expectLastTx(f.node, age.text); + } + + // Account for the time since the main loop last sampled millis(), across + // its 32-bit wrap, using the accumulated boot uptime rather than RTC time. + f.node.uptime_millis = (uint64_t(1) << 32) + 4000; + f.node.last_millis = UINT32_MAX - 999; + test_millis = 500; + const uint64_t sent = f.node.uptime_millis + 1500; + f.node.recordTelemetryHistoryTx(&packets[1]); + assert(f.node.telemetry_history_last_tx_uptime == sent); + expectLastTx(f.node, "0s"); + test_millis += 30000; + expectLastTx(f.node, "30s"); + + // RTC jumps clear/rebuild the sample histories without changing the age. + f.node.telemetry_history.record(2000000000, 21, true, 3750, 0, 0, false); + f.node.telemetry_history.record(1000000, 21, true, 3750, 0, 0, false); + f.node.noise_floor_history.advance(2000000000); + f.node.noise_floor_history.advance(1000000); + expectLastTx(f.node, "30s"); + f.node.uptime_millis = sent + 172800000; + f.node.last_millis = test_millis; + expectLastTx(f.node, "48h"); + test_millis = 0; +} + +static void checkLastTxSurvivesScheduleAndStatusTruncation() { + Fixture f; f.boot(); + const auto packets = historyPackets(f); + f.node.uptime_millis = 1000; + f.node.last_millis = test_millis; + f.node.recordTelemetryHistoryTx(&packets.front()); + const uint64_t sent = f.node.telemetry_history_last_tx_uptime; + for (const char* command : {"set telemetry.tx schedule 1d", "set telemetry.tx schedule off"}) { + assert(f.node.command(command).find("OK - telemetry.tx schedule=") == 0); + assert(f.node.telemetry_history_last_tx_uptime == sent); + f.boot(); + assert(f.node.telemetry_history_last_tx_uptime == sent); + } + assert(f.node.command("send telemetry.tx now").find("OK - telemetry.tx queued") == 0); + assert(f.node.telemetry_history_last_tx_uptime == sent); + f.fs.fail_read_open.insert(target); + f.node.loadTelemetryHistoryTxPrefs(); + assert(!f.node.telemetry_history_tx_prefs_healthy); + f.node.uptime_millis += 1800000; + expectLastTx(f.node, "30m"); + assert(txStatus(f.node).find("last=30m fault=prefs p=") != std::string::npos); + + f.fs.clearFaults(); f.boot(); + f.route.path_len = 63; + memset(f.route.path, 0xab, sizeof(f.route.path)); + const auto reply = txStatus(f.node); + assert(reply.size() == 159); // longest learned route exceeds the CLI reply + assert(reply.find("last=30m") < reply.find(" p=")); + assert(reply.find("last=30m p=ABAB") != std::string::npos); + char prefixed[161]; + memset(prefixed, '#', sizeof(prefixed)); + memcpy(prefixed, " > ", 3); + f.node.formatTelemetryHistoryTxStatus(prefixed + 3, 157); + assert(prefixed[159] == 0 && prefixed[160] == '#'); + assert(strstr(prefixed, "last=30m p=ABAB")); + Fixture restarted; restarted.fs.files = f.fs.files; restarted.boot(); + expectLastTx(restarted.node, "never"); // boot-local; do not invent a timestamp +} + int main() { checkFreshAndValid(); checkLoadFailures(); @@ -681,5 +845,8 @@ int main() { checkRouteReadbackAndRetry(); checkNoiseHistoryTransmission(); checkNoiseHistoryRetries(); + checkLastTxCompletionAndOwnership(); + checkLastTxAgeAndClockWrap(); + checkLastTxSurvivesScheduleAndStatusTruncation(); puts("telemetry persistence checks passed"); } diff --git a/test/test_telemetry_tx_persistence.py b/test/test_telemetry_tx_persistence.py index 1dae05714..bb5068eb6 100644 --- a/test/test_telemetry_tx_persistence.py +++ b/test/test_telemetry_tx_persistence.py @@ -19,10 +19,12 @@ class TelemetryPersistenceTests(unittest.TestCase): source = (ROOT / "examples/simple_repeater/MyMesh.cpp").read_text(encoding="ascii") common = (ROOT / "src/helpers/CommonCLI_Management.cpp").read_text(encoding="ascii") packet = (ROOT / "src/Packet.cpp").read_text(encoding="ascii") + mesh = (ROOT / "src/Mesh.cpp").read_text(encoding="ascii") utils = (ROOT / "src/Utils.cpp").read_text(encoding="ascii") state = common[common.index("static constexpr char DATA_ROUTE_FILE[]"): common.index("static uint32_t readRoute32(")] generated = "namespace mesh {\n" + state + "\n" + generated += extract_braced(mesh, "bool Mesh::isTelemetryHistoryPayload(") + "\n" generated += "\n".join(extract_braced(packet, signature) for signature in ( "bool Packet::isValidPathLen(", "size_t Packet::writePath(", "uint8_t Packet::copyPath(")) + "\n" @@ -46,6 +48,7 @@ class TelemetryPersistenceTests(unittest.TestCase): "static bool recoverTelemetryHistoryTxPrefs(", "static bool readTelemetryHistoryTxPrefsImage(", "void MyMesh::loadTelemetryHistoryTxPrefs(", "bool MyMesh::saveTelemetryHistoryTxPrefs(", "bool MyMesh::sendTelemetryHistorySnapshot(", + "void MyMesh::recordTelemetryHistoryTx(", "bool MyMesh::sendNoiseFloorHistorySnapshot(", "bool MyMesh::sendExternalVoltageHistorySnapshot(", "void MyMesh::serviceTelemetryHistoryTx(", "void MyMesh::formatTelemetryHistoryTxStatus(", "static char* trimSpaces(")) + "\n" @@ -81,6 +84,20 @@ class TelemetryPersistenceTests(unittest.TestCase): self.assertEqual(executed.returncode, 0, executed.stdout + executed.stderr) self.assertIn("telemetry persistence checks passed", executed.stdout) + def test_last_tx_only_uses_the_successful_radio_hook(self): + source = (ROOT / "examples/simple_repeater/MyMesh.cpp").read_text(encoding="ascii") + completed = extract_braced(source, "void MyMesh::logTx(") + self.assertRegex(completed, r"#if MESH_ENABLE_TELEMETRY_HISTORY\s+" + r"recordTelemetryHistoryTx\(pkt\);\s+#endif") + self.assertNotIn("recordTelemetryHistoryTx(", + extract_braced(source, "void MyMesh::onSendComplete(")) + # Echo delivery may invoke onSendComplete without another RF send. + self.assertEqual(source.count("recordTelemetryHistoryTx(pkt);"), 1) + constructor = extract_braced(source, "MyMesh::MyMesh(") + self.assertIn("telemetry_history_last_tx_uptime = UINT64_MAX;", constructor) + loader = extract_braced(source, "void MyMesh::loadTelemetryHistoryTxPrefs(") + self.assertNotIn("telemetry_history_last_tx_uptime", loader) + if __name__ == "__main__": unittest.main()