From 0d70256d2ea97a784a6900a19a1dee4450cfd334 Mon Sep 17 00:00:00 2001 From: liquidraver <504870+liquidraver@users.noreply.github.com> Date: Sat, 11 Jul 2026 21:20:44 +0200 Subject: [PATCH] vcontact p2 --- zephcore/ARCHITECTURE.md | 23 ++++++- zephcore/app/CompanionMesh.cpp | 103 +++++++++++++++++++++++++++----- zephcore/app/CompanionMesh.h | 15 ++++- zephcore/src/main_companion.cpp | 44 ++++++++++---- 4 files changed, 159 insertions(+), 26 deletions(-) diff --git a/zephcore/ARCHITECTURE.md b/zephcore/ARCHITECTURE.md index 0a36cb5..e428927 100644 --- a/zephcore/ARCHITECTURE.md +++ b/zephcore/ARCHITECTURE.md @@ -483,7 +483,8 @@ contact named `v` that exists only toward the connected BLE/USB app. Chatting with it runs the same text CLI as the USB serial sideband; the reply comes back as normal chat messages. The firmware also uses it to emit unsolicited notices: a one-shot low-battery alert and a restart-reason message -(SOFTWARE/WATCHDOG/LOCKUP/BROWNOUT causes only — plain power-on is log-only). +(all causes: PIN/SOFTWARE/BROWNOUT/POR/WATCHDOG/LOCKUP — offline-queue only, +so routine power-on "noise" costs nothing over the air). **Identity**: pubkey = `SHA256("zc-vcontact" || self_pubkey)` — stable per node, unique per device, and deliberately **not a real keypair**: no private @@ -509,6 +510,26 @@ delete (`CMD_REMOVE_CONTACT`) turns the feature off. Send/ack choreography is synthesized (SENT + immediate SEND_CONFIRMED, trip time 0). CLI replies are chunked at ≤150 chars on line breaks (offline-queue frames cap at 172 bytes). +**Clock gating (no 1970 timestamps)**: while the RTC has never been synced +(time < firmware build epoch) the v-contact is *deferred* — withheld from +contact sync and adverts, and notices are buffered in a small RAM slot +(`_vcontact_pending`) instead of queued with an epoch-0 timestamp. +`vcontactClockSynced()` activates it and flushes the buffer; hooked at +`CMD_APP_START` (covers hardware-RTC boards, already valid), successful +`CMD_SET_DEVICE_TIME` (typical app connect flow), and GPS time sync. + +**Resend dedupe**: app retry attempts reuse the message timestamp (only the +attempt byte changes); `_vcontact_last_ts` suppresses re-execution — a dupe +gets the full ack choreography but the CLI does not run twice. Side effect: +sending the identical command twice within the same wall-clock second only +executes once (same app-side timestamp). Synthesized `est_timeout` is 3 s so +the app's retry timer doesn't race the loopback confirmation. + +**Stats**: `CompanionCLICallbacks` overrides +`formatStatsReply`/`formatRadioStatsReply`/`formatPacketStatsReply` with the +repeater's `StatsFormatHelper` JSON, so `stats-core`/`stats-radio`/ +`stats-packets` return real data over USB and the v-contact. + **Notices ride the offline queue** — emitted while nothing is connected, they are delivered on the first app connect/sync. RAM-backed: lost on reboot (the restart-reason message partially compensates) and bounded by diff --git a/zephcore/app/CompanionMesh.cpp b/zephcore/app/CompanionMesh.cpp index 4aa4ed9..e42510d 100644 --- a/zephcore/app/CompanionMesh.cpp +++ b/zephcore/app/CompanionMesh.cpp @@ -212,6 +212,9 @@ CompanionMesh::CompanionMesh(mesh::Radio &radio, mesh::MillisecondClock &ms, mes _vcontact_cli_cb = nullptr; memset(_vcontact_pubkey, 0, sizeof(_vcontact_pubkey)); _vcontact_lastmod = 0; + _vcontact_last_ts = 0; + memset(_vcontact_pending, 0, sizeof(_vcontact_pending)); + _vcontact_pending_count = 0; memset(&prefs, 0, sizeof(prefs)); prefs.node_lat = 0; prefs.node_lon = 0; @@ -228,7 +231,12 @@ void CompanionMesh::begin() mesh::Utils::sha256(_vcontact_pubkey, PUB_KEY_SIZE, (const uint8_t *)vc_salt, sizeof(vc_salt) - 1, self_id.pub_key, PUB_KEY_SIZE); - _vcontact_lastmod = (uint32_t)getRTCClock()->getCurrentTime(); + /* Stamp lastmod only if a time source already ran (hardware RTC restore + * happens before begin()). Otherwise stay deferred (lastmod = 0) until + * vcontactClockSynced() — an advert stamped now would show as 1970. */ + if (vcontactClockValid()) { + _vcontact_lastmod = (uint32_t)getRTCClock()->getCurrentTime(); + } #ifdef CONFIG_ZEPHCORE_APC _power_ctrl.setSF(prefs.sf); _power_ctrl.setTargetMargin(prefs.apc_margin); @@ -616,8 +624,10 @@ bool CompanionMesh::continueContactIteration() _contact_iter_idx++; return true; } else if (_contact_iter_idx == getNumContacts()) { - // Virtual tail entry: the v-contact (never in the real table) - if (isVContactEnabled() && _vcontact_lastmod > _contact_iter_since) { + // Virtual tail entry: the v-contact (never in the real table). + // vcontactReady() implies lastmod != 0 — deferred (clock-invalid) + // state is excluded so the app never sees a 1970 timestamp. + if (vcontactReady() && _vcontact_lastmod > _contact_iter_since) { if (_vcontact_lastmod > _contact_iter_lastmod) { _contact_iter_lastmod = _vcontact_lastmod; } @@ -880,6 +890,30 @@ bool CompanionMesh::isVContactKey(const uint8_t *key, int prefix_len) const return memcmp(key, _vcontact_pubkey, prefix_len) == 0; } +bool CompanionMesh::vcontactClockValid() +{ + /* Anything before the firmware build epoch is a never-synced clock. */ + return (uint32_t)getRTCClock()->getCurrentTime() >= (uint32_t)FIRMWARE_BUILD_EPOCH; +} + +void CompanionMesh::vcontactClockSynced() +{ + if (!isVContactEnabled() || !vcontactClockValid()) { + return; + } + if (_vcontact_lastmod == 0) { + /* Deferred activation: first valid time source — stamp and announce. + * From here the contact also appears in CMD_GET_CONTACTS syncs. */ + vcontactPushAdvert(); + } + /* Flush notices buffered while the clock was invalid; queueing them now + * gives them real timestamps instead of 1970. */ + for (uint8_t i = 0; i < _vcontact_pending_count; i++) { + vcontactQueueText(_vcontact_pending[i]); + } + _vcontact_pending_count = 0; +} + void CompanionMesh::vcontactQueueText(const char *text) { /* Offline-queue frames cap at 172 bytes and the V3 header takes 16, so @@ -924,12 +958,33 @@ void CompanionMesh::vcontactNotify(const char *text) { if (!isVContactEnabled() || !text || !text[0]) return; LOG_INF("vcontact notify: %s", text); + if (!vcontactClockValid()) { + /* Clock never synced — a message queued now would show as 1970. + * Buffer it; vcontactClockSynced() flushes with a real timestamp. + * Drop-oldest when full (restart reason + battery is the whole + * expected population). */ + if (_vcontact_pending_count >= (uint8_t)ARRAY_SIZE(_vcontact_pending)) { + memmove(_vcontact_pending[0], _vcontact_pending[1], + sizeof(_vcontact_pending[0]) * (ARRAY_SIZE(_vcontact_pending) - 1)); + _vcontact_pending_count = ARRAY_SIZE(_vcontact_pending) - 1; + } + strncpy(_vcontact_pending[_vcontact_pending_count], text, + sizeof(_vcontact_pending[0]) - 1); + _vcontact_pending[_vcontact_pending_count][sizeof(_vcontact_pending[0]) - 1] = '\0'; + _vcontact_pending_count++; + return; + } vcontactQueueText(text); } void CompanionMesh::vcontactPushAdvert() { if (!isVContactEnabled()) return; + if (!vcontactClockValid()) { + /* Defer — an advert stamped now would carry a 1970 timestamp. + * vcontactClockSynced() re-runs this once a time source arrives. */ + return; + } /* Bump lastmod so incremental contact syncs (since > 0) pick up the * rename/re-enable. */ _vcontact_lastmod = (uint32_t)getRTCClock()->getCurrentTime(); @@ -959,19 +1014,31 @@ bool CompanionMesh::vcontactHandleFrame(const uint8_t *data, size_t len) sendPacketError(ERR_UNSUPPORTED); return true; } - char line[MAX_TEXT_LEN + 1]; - size_t text_len = len - 13; - if (text_len > MAX_TEXT_LEN) text_len = MAX_TEXT_LEN; - memcpy(line, &data[13], text_len); - line[text_len] = '\0'; - LOG_INF("vcontact CLI: '%s'", line); + /* Dedupe app resends: retry attempts of the same message reuse + * its timestamp (only the attempt byte changes). Without this a + * retry re-executes the CLI line → duplicate responses. Dupes + * still get the full ack choreography so the app settles. */ + uint32_t msg_timestamp = get_le32(&data[3]); + bool dup = (msg_timestamp != 0 && msg_timestamp == _vcontact_last_ts); + _vcontact_last_ts = msg_timestamp; char reply[VCONTACT_CLI_REPLY_SIZE]; reply[0] = '\0'; - if (_vcontact_cli_cb) { - _vcontact_cli_cb(line, reply); + if (!dup) { + char line[MAX_TEXT_LEN + 1]; + size_t text_len = len - 13; + if (text_len > MAX_TEXT_LEN) text_len = MAX_TEXT_LEN; + memcpy(line, &data[13], text_len); + line[text_len] = '\0'; + LOG_INF("vcontact CLI: '%s'", line); + + if (_vcontact_cli_cb) { + _vcontact_cli_cb(line, reply); + } else { + strcpy(reply, "CLI not available"); + } } else { - strcpy(reply, "CLI not available"); + LOG_DBG("vcontact CLI: dup ts=%u, re-ack only", msg_timestamp); } /* Synthesize the normal send/ack choreography: SENT response, @@ -979,7 +1046,7 @@ bool CompanionMesh::vcontactHandleFrame(const uint8_t *data, size_t len) uint32_t ack = 0; getRNG()->random((uint8_t *)&ack, 4); if (ack == 0) ack = 1; - sendPacketSent(MSG_SEND_SENT_DIRECT, ack, 100); + sendPacketSent(MSG_SEND_SENT_DIRECT, ack, 3000); uint8_t ack_push[8]; memcpy(ack_push, &ack, 4); memset(&ack_push[4], 0, 4); /* trip time: 0 ms */ @@ -1890,6 +1957,10 @@ bool CompanionMesh::handleProtocolFrame(const uint8_t *data, size_t len) cancelSyncPending(); cleanupSignState(); + /* If a time source already ran (hardware RTC, GPS), activate the + * deferred v-contact and flush buffered notices for this session. */ + vcontactClockSynced(); + // Return SELF_INFO uint8_t rsp[90]; // 58 fixed + up to 32 bytes name size_t i = 0; @@ -1936,7 +2007,7 @@ bool CompanionMesh::handleProtocolFrame(const uint8_t *data, size_t len) ContactInfo c; if (getContactByIdx(i, c) && c.type != ADV_TYPE_NONE) total++; } - if (isVContactEnabled()) total++; /* virtual tail entry */ + if (vcontactReady()) total++; /* virtual tail entry (post time sync) */ uint8_t rsp[5]; rsp[0] = PACKET_CONTACT_START; put_le32(&rsp[1], total); @@ -2470,6 +2541,7 @@ bool CompanionMesh::handleProtocolFrame(const uint8_t *data, size_t len) if (gps_has_time_sync()) { LOG_DBG("Ignoring phone time sync - GPS time sync active"); sendPacketOk(); + vcontactClockSynced(); /* GPS time counts as valid too */ return true; } @@ -2482,6 +2554,9 @@ bool CompanionMesh::handleProtocolFrame(const uint8_t *data, size_t len) zephcore_rtc_save(secs); /* persist to hardware RTC */ _timesync.noteManualSync((uint32_t)(k_uptime_get() / 1000)); sendPacketOk(); + /* App just gave us wall time — activate the deferred + * v-contact and flush buffered notices. */ + vcontactClockSynced(); } else { sendPacketError(ERR_ILLEGAL_ARG); } diff --git a/zephcore/app/CompanionMesh.h b/zephcore/app/CompanionMesh.h index e60fe1d..f99e509 100644 --- a/zephcore/app/CompanionMesh.h +++ b/zephcore/app/CompanionMesh.h @@ -177,6 +177,11 @@ public: void vcontactPushAdvert(); /** Push CONTACT_DELETED for the v-contact (call after runtime disable). */ void vcontactPushDeleted(); + /** Clock became (or may have become) valid — activate the v-contact if it + * was deferred (no more 1970 adverts) and flush buffered notices so they + * carry sane timestamps. Self-gating; safe to call speculatively. Hooked + * at CMD_APP_START, CMD_SET_DEVICE_TIME, and GPS time sync. */ + void vcontactClockSynced(); #ifdef CONFIG_ZEPHCORE_APC /* Adaptive Power Control hooks used by the USB text CLI. */ @@ -490,10 +495,18 @@ private: void queueContactMessage(const ContactInfo &contact, mesh::Packet *pkt, uint8_t txt_type, uint32_t sender_timestamp, const uint8_t *extra, int extra_len, const char *text); - /* V-contact internals */ + /* V-contact internals. _vcontact_lastmod == 0 means "not yet activated": + * the clock was invalid (pre-1970s epoch) when we would have stamped it, + * so the contact is withheld from sync/adverts until a time source + * arrives — otherwise the app shows a 1970 last-heard timestamp. */ VContactCLICallback _vcontact_cli_cb; uint8_t _vcontact_pubkey[PUB_KEY_SIZE]; uint32_t _vcontact_lastmod; + uint32_t _vcontact_last_ts; /* dedupe: app resends carry the same msg timestamp */ + char _vcontact_pending[2][64]; /* notices buffered while the clock is invalid */ + uint8_t _vcontact_pending_count; + bool vcontactClockValid(); + bool vcontactReady() { return isVContactEnabled() && _vcontact_lastmod != 0; } void buildVContact(ContactInfo &c) const; bool isVContactKey(const uint8_t *key, int prefix_len) const; /** Intercept protocol frames addressed to the v-contact. Returns true when diff --git a/zephcore/src/main_companion.cpp b/zephcore/src/main_companion.cpp index bb67313..8a13509 100644 --- a/zephcore/src/main_companion.cpp +++ b/zephcore/src/main_companion.cpp @@ -62,6 +62,7 @@ LOG_MODULE_REGISTER(zephcore_main, CONFIG_ZEPHCORE_MAIN_LOG_LEVEL); #include #include #include +#include #include #endif @@ -559,9 +560,11 @@ static void mesh_event_loop(void) if (events & MESH_EVENT_RTC_SAVE) { zephcore_rtc_save((uint32_t)atomic_get(&pending_rtc_epoch)); #ifdef ZEPHCORE_LORA - /* GPS just set the clock — arm the mesh time-sync drift envelope. */ + /* GPS just set the clock — arm the mesh time-sync drift envelope + * and activate the deferred v-contact / flush buffered notices. */ if (companion_mesh_ptr) { companion_mesh_ptr->noteGPSTimeSync(); + companion_mesh_ptr->vcontactClockSynced(); } #endif } @@ -785,6 +788,23 @@ public: state, gsi.satellites); } } + + /* Stats — same JSON format as the repeater CLI (StatsFormatHelper), so + * `stats-core` / `stats-radio` / `stats-packets` work over USB and the + * v-contact chat instead of the base-class "not available" stubs. */ + void formatStatsReply(char* reply) override { + StatsFormatHelper::formatCoreStats(reply, zephyr_board, ms_clock, + companion_mesh.getErrFlags(), &packet_mgr); + } + void formatRadioStatsReply(char* reply) override { + StatsFormatHelper::formatRadioStats(reply, &lora_radio, lora_radio, + companion_mesh.getTotalAirTime(), companion_mesh.getReceiveAirTime()); + } + void formatPacketStatsReply(char* reply) override { + StatsFormatHelper::formatPacketStats(reply, lora_radio, + companion_mesh.getNumSentFlood(), companion_mesh.getNumSentDirect(), + companion_mesh.getNumRecvFlood(), companion_mesh.getNumRecvDirect()); + } }; static CompanionCLICallbacks companion_cli_cbs; @@ -1187,7 +1207,7 @@ int main(void) LOG_INF("=== ZephCore starting ==="); /* Log reset reason so we can diagnose random reboots */ - char boot_cause_msg[64]; + char boot_cause_msg[96]; /* fits "Restarted:" + all six cause labels */ boot_cause_msg[0] = '\0'; { uint32_t cause; @@ -1200,17 +1220,21 @@ int main(void) (cause & RESET_WATCHDOG) ? " WATCHDOG" : "", (cause & RESET_CPU_LOCKUP)? " LOCKUP" : ""); hwinfo_clear_reset_cause(); - /* Informative causes become a v-contact message once the - * mesh is up (queued below, after RTC restore + prefs load). - * Plain POR/PIN — the user just powered the device on — is - * noise and stays log-only. A deliberate CLI/app reboot shows - * as SOFTWARE, doubling as a "reboot completed" confirmation. */ - if (cause & (RESET_SOFTWARE | RESET_BROWNOUT | - RESET_WATCHDOG | RESET_CPU_LOCKUP)) { + /* Every known cause becomes a v-contact message once the mesh + * is up (queued below, after RTC restore + prefs load) — the + * message rides the offline queue only, so the "noise" of a + * routine power-on costs nothing over the air and doubles as + * a power-integrity breadcrumb (dead battery, loose contact). + * A deliberate CLI/app reboot shows as SOFTWARE, doubling as + * a "reboot completed" confirmation. */ + if (cause & (RESET_PIN | RESET_SOFTWARE | RESET_BROWNOUT | + RESET_POR | RESET_WATCHDOG | RESET_CPU_LOCKUP)) { snprintf(boot_cause_msg, sizeof(boot_cause_msg), - "Restarted:%s%s%s%s", + "Restarted:%s%s%s%s%s%s", + (cause & RESET_PIN) ? " PIN(reset button)" : "", (cause & RESET_SOFTWARE) ? " SOFTWARE" : "", (cause & RESET_BROWNOUT) ? " BROWNOUT" : "", + (cause & RESET_POR) ? " POR(power-on)" : "", (cause & RESET_WATCHDOG) ? " WATCHDOG" : "", (cause & RESET_CPU_LOCKUP) ? " LOCKUP" : ""); }