Add opt-in bounded ESP32 radio timing capture

This commit is contained in:
mikecarper committed 2026-10-22 03:46:43 -07:00
1 parent 23e46c1f5d
commit 9b70827d03
12 files changed
+1548 -11

No files matched your search

+2
View File
@@ -342,6 +342,8 @@ jobs:
python3 -B test/test_drv2605_power.py -v
python3 -B test/test_radio_interrupt_recovery.py -v
python3 -B test/test_radio_rx_activity_epoch.py -v
python3 -B test/test_esp32_radio_trace.py -v
python3 -B test/test_esp32_radio_trace_cli.py -v
python3 -B test/test_forwarding_profile_timing.py -v
python3 -B test/test_clock_transit_profile_timing.py -v
python3 -B test/test_bridge_recovery.py -v
@@ -460,8 +460,8 @@ The immutable receipt is `v4-a5293fa5-awake-completed.private.json` (SHA-256
The stale-IRQ regression proves a receive-path bug and the new guard repairs
that case. This physical sample does not establish which historical misses
encountered it or show that all scanning losses are fixed. A controlled
two-transmitter overlap diagnostic is pending; no result or cause is claimed
for that experiment here.
two-transmitter overlap diagnostic is recorded below; it does not establish a
cause for these historical misses.
### Receive activity across RX restarts
@@ -485,19 +485,93 @@ ASan/UBSan variants, including reset-removal controls that reproduce the
retune over a new packet for all six handlers. All 19 affected host-fixture
tests and 26 interrupt-recovery, receive-contract and receive-retry checks
pass. The new suite runs in the required unit-test workflow. Physical RF
validation remains pending; this proof does not attribute historical missing
nonces or establish a complete RF pass. The installed versions and packet
counts above remain unchanged.
results on the new image are recorded below. The host proof does not attribute
historical missing nonces or establish a complete RF pass.
## RX-restart installation and overlap diagnostic
The V4 image built from pushed source
[`e4119a120`](https://github.com/mikecarper/MeshCore/commit/e4119a1206efefc0506c12ebe529883b966784f5)
passes its capability and memory gates at 2,558,984 application bytes. Its
application SHA-256 is
`fc1a835c45ebc5e7a9fec95c757d8606e145bbc92fa8d365ba62d96a7930286d`.
The application-only installation passed full readback and checked
configuration preservation. The receipt is
`flash-v4-e4119a12-completed.private.json` (SHA-256
`b06d8b6ef8d9df9aa881d6d1ca2f6096d19c8bcc6d4cbb2873fb20d47a9f85c5`).
Two overlap conditions completed on this image at 80 MHz with manual CPU sleep
off. Each condition sent 20 unique primary/secondary pairs; all 40 sends
reached TX_DONE once, with zero retries or duplicate deliveries and zero SDK
counters in both conditions.
| Condition | Primary received | Secondary received |
| --- | --- | --- |
| Radio2 scanning | 16/20 | 2/20 |
| Fixed 916 MHz, radio2 off | 0/20 (outside receive frequency) | 20/20 |
All 20 scanner timing bounds were inconclusive. The nominal 140 ms secondary
write occurred 227.239-263.257 ms after the primary write (median 244.363 ms),
while the first counter reply confirming primary TX_DONE arrived
523.533-903.982 ms after that write. That reply bounds completion; it does not
timestamp the RF event. The controller synchronously saved the report before
the secondary write and after each counter reply, widening these bounds.
The analysis uses 101-byte wire airtimes of 397.824/652.288 ms, a complete
148.480 ms secondary preamble and a 2 ms margin. No pair proves that the whole
secondary preamble fell inside the primary payload reception. The timings
do not exclude desense or attribute historical misses. The ordinary
alternating-profile check is recorded below.
Three earlier setup attempts sent no RF: the first two stopped before
mutation; the third encountered a pending lease, with separate V3 automatic
cleanup recovery passing. The overlap experiment completed with an
inconclusive status: neither condition has a qualified timing pair, so masking
was not demonstrated. Full restoration of all three boards passed without
errors, and a fresh MQTT PUBACK verified recovery. The final host receipt is
`/home/mesh/hwtest/esp32-radio2-pson-v3-v4-20261021/overlap-v4-e4119a12-completed.private.json`
(SHA-256
`c1aee5132b447734df3fe9c663f4f3ae7a8b980f3165de43f96c2653d05200e1`).
No firmware qualification pass is claimed.
## Ordinary awake check after both receive fixes
The predeclared `e4119a120` check sent 20 new packets per profile, once each,
with the ordinary alternating schedule and no deliberate overlapping sender.
It received **17/20 primary and 18/20 secondary packets**. All 40 sends reached
TX_DONE once; duplicates, RF retries and SDK sleep calls were zero. The strict
RF result remains failed. The physical counters recorded 120 successful raw
receives: 35 owned direct packets and 85 ambient floods, with seven separate
receive errors. These totals do not identify the cause of each missing nonce.
The immutable receipt is `v4-e4119a12-awake-completed.private.json` (SHA-256
`9f2f8acecc634ebaf7b9e9aa21e51079b9872316e571a886d3866bfedabab558`).
That receipt also retains a cleanup failure: restoring automatic radio2
permission was rejected while the temporary primary restore was still pending.
Fresh MQTT recovery passed. A separate guarded operation subsequently restored
automatic permission with one setter and no RF transmissions, then verified
the checked settings, credentials and channel semantics against the baseline.
Its receipt is `v4-auto-restoration-after-e411-awake.private.json` (SHA-256
`4dbf10eeac81e8897c8a4f9fa4d7b62ac20e74c91b467a501f31fa3a1d8bd0ec`).
Both receive defects remain proven by executed host regressions, but the
physical results show that additional losses remain. The next diagnostic
records bounded activity and transmission times on the radios themselves.
It must distinguish other-profile ownership, unresolved preamble activity,
read/rearm gaps and delays between scanner calls without treating host counter
replies as RF timestamps. No arbitrary preamble or CPU-sleep setting change
or replacement packet was used to turn a failed result into a pass.
## Final handback and limits
V3 currently runs `7d0709bf0`; V4 runs `a5293fa50`, and the peer remains on
`ebb59d48`. The completed V3 campaign and V4 scanning controls, including the
new awake run, restored their checked radio, RX power-saving,
V3 currently runs `7d0709bf0`; V4 runs `e4119a120`, and the peer remains on
`ebb59d48`. The completed earlier V3 campaign and V4 scanning controls,
including the `a5293fa50` awake run, restored their checked radio, RX power-saving,
Bluetooth, WiFi, MQTT, logging, diagnostics and USB-watchdog settings, including
credential digests, original radio2 automatic permission and peer power/channel
state. Fresh MQTT PUBACK increases verified recovery. The fixed-tuple cleanup
power failure is retained, with the later peer recovery verified separately.
Full overlap restoration is verified. The ordinary run's original cleanup
failure is retained, with its separate automatic-permission recovery verified.
No nRF52 board, hub power or other firmware was changed in this task.
The Bluetooth hardware checks pass. SDK light-sleep calls are observed without
+6
View File
@@ -30,6 +30,9 @@
#if defined(MESH_SOAK_DIAGNOSTICS)
#include "../../tools/hil/S3SoakDiagnostics.h"
#endif
#if defined(ESP32_PLATFORM) && defined(MESH_HIL_RADIO_TRACE) && MESH_HIL_RADIO_TRACE
#include <helpers/radiolib/ESP32RadioTraceCLI.h>
#endif
#include <Arduino.h> // needed for PlatformIO
#include <ctype.h>
@@ -10645,6 +10648,9 @@ bool MyMesh::handleDirectCommand(const char* command, char* reply, size_t reply_
#if defined(MESH_SOAK_DIAGNOSTICS)
if (mesh::hil::handleSoakCommand(command, reply, reply_size)) return true;
#endif
#if defined(ESP32_PLATFORM) && defined(MESH_HIL_RADIO_TRACE) && MESH_HIL_RADIO_TRACE
if (mesh::radiotrace::handleTraceCommand(command, reply, reply_size)) return true;
#endif
#if MESH_ENABLE_ONE_KEY_DM
if (strcmp(command, "get dm.one_key") == 0) {
snprintf(reply, reply_size, "> %s", _prefs.one_key_dm_enabled == 1 ? "on" : "off");
+130 -2
View File
@@ -7,6 +7,7 @@
#include "RXPowerSaving.h"
#include "SX1262ProfileSwitchState.h"
#include "SX126xMorseRssi.h"
#include "ESP32RadioTrace.h"
#if defined(STATION_G3_ESP32)
#include <StationG3RadioSlot.h>
#endif
@@ -46,6 +47,12 @@
#endif
class CustomSX1262 : public SX1262 {
#if MESH_RADIO_TRACE_ENABLED
void traceOperation(mesh::radiotrace::Reason reason) {
if (mesh::radiotrace::trace().pending())
mesh::radiotrace::trace().operation(static_cast<PhysicalLayer*>(this), mesh::radiotrace::nowUs(), reason);
}
#endif
#if defined(SX126X_USE_REGULATOR_LDO) && SX126X_USE_REGULATOR_LDO
mesh::power::RadioRegulatorState _regulator{mesh::power::REGULATOR_LDO, mesh::power::RegulatorMode::Ldo};
#else
@@ -139,6 +146,9 @@ class CustomSX1262 : public SX1262 {
}
int16_t standby() override {
#if MESH_RADIO_TRACE_ENABLED
traceOperation(mesh::radiotrace::Reconfigure);
#endif
const bool alreadyAwake = !_coldStandby && _profileSwitch.active && _profileSwitch.rxValid;
if (!alreadyAwake) _profileSwitch.invalidate();
int16_t rc;
@@ -163,6 +173,9 @@ class CustomSX1262 : public SX1262 {
return rc;
}
int16_t standby(uint8_t mode) override {
#if MESH_RADIO_TRACE_ENABLED
traceOperation(mesh::radiotrace::Reconfigure);
#endif
_profileSwitch.invalidate();
int16_t rc = SX1262::standby(mode);
if (rc == RADIOLIB_ERR_NONE) rc = restoreTcxoAfterSleep();
@@ -175,14 +188,26 @@ class CustomSX1262 : public SX1262 {
// retaining the requested warm policy for subsequent established RX.
int16_t sleep() override { return sleep(true); }
int16_t sleep(bool retainConfig) {
#if MESH_RADIO_TRACE_ENABLED
traceOperation(mesh::radiotrace::Recovery);
#endif
_profileSwitch.invalidate();
_coldStandby = true;
const int16_t rc = SX1262::standby(RADIOLIB_SX126X_STANDBY_RC);
_tcxoWakePending = tcxoVoltage > 0.0f;
return rc == RADIOLIB_ERR_NONE ? SX1262::sleep(retainConfig) : rc;
}
int16_t reset(bool verify = true) { _profileSwitch.invalidate(); _coldStandby = true; _tcxoWakePending = false; return SX1262::reset(verify); }
int16_t reset(bool verify = true) {
#if MESH_RADIO_TRACE_ENABLED
traceOperation(mesh::radiotrace::Recovery);
#endif
_profileSwitch.invalidate(); _coldStandby = true; _tcxoWakePending = false;
return SX1262::reset(verify);
}
int16_t stageMode(RadioModeType_t mode, RadioModeConfig_t* cfg) override {
#if MESH_RADIO_TRACE_ENABLED
traceOperation(mode == RADIOLIB_RADIO_MODE_TX ? mesh::radiotrace::Transmit : mesh::radiotrace::Rearm);
#endif
// All ordinary RX/TX staging rebuilds hardware state. In particular TX
// changes IRQ mapping, packet length and buffer contents/base settings.
_profileSwitch.invalidate();
@@ -541,6 +566,11 @@ class CustomSX1262 : public SX1262 {
int16_t startReceiveDutyCycle(uint32_t rxPeriod, uint32_t sleepPeriod,
RadioLibIrqFlags_t irqFlags = RADIOLIB_IRQ_RX_DEFAULT_FLAGS,
RadioLibIrqFlags_t irqMask = RADIOLIB_IRQ_RX_DEFAULT_MASK) {
#if MESH_RADIO_TRACE_ENABLED
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t trace_before = tracing ? mesh::radiotrace::nowUs() : 0;
if (tracing) traceOperation(mesh::radiotrace::Rearm);
#endif
_profileSwitch.invalidate();
_coldStandby = true;
int16_t state = SX1262::startReceiveDutyCycle(rxPeriod, sleepPeriod, irqFlags, irqMask);
@@ -554,6 +584,10 @@ class CustomSX1262 : public SX1262 {
_activityAt = 0;
_headerSeen = false;
}
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().receiveEntry(static_cast<PhysicalLayer*>(this),
trace_before, mesh::radiotrace::nowUs(), state);
#endif
return state;
}
@@ -619,8 +653,20 @@ class CustomSX1262 : public SX1262 {
}
this->mod->setRfSwitchState(this->txMode);
#if MESH_RADIO_TRACE_ENABLED
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t trace_before = tracing ? mesh::radiotrace::nowUs() : 0;
if (tracing) mesh::radiotrace::trace().transmitLaunchBegin(static_cast<PhysicalLayer*>(this), trace_before);
#endif
int16_t state = this->setTx(RADIOLIB_SX126X_TX_TIMEOUT_NONE);
#if MESH_RADIO_TRACE_ENABLED
const uint64_t trace_after = tracing ? mesh::radiotrace::nowUs() : 0;
#endif
if (state != RADIOLIB_ERR_NONE) {
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().transmitLaunch(static_cast<PhysicalLayer*>(this),
trace_before, trace_after, 0, state);
#endif
this->stagedMode = RADIOLIB_RADIO_MODE_NONE;
return state;
}
@@ -629,11 +675,21 @@ class CustomSX1262 : public SX1262 {
while (isChipBusy()) {
this->mod->hal->yield();
if (this->mod->hal->millis() - started >= SX126X_TX_BUSY_TIMEOUT_MS) {
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().transmitLaunch(static_cast<PhysicalLayer*>(this),
trace_before, trace_after, 0, RADIOLIB_ERR_SPI_CMD_TIMEOUT);
#endif
this->stagedMode = RADIOLIB_RADIO_MODE_NONE;
return RADIOLIB_ERR_SPI_CMD_TIMEOUT;
}
}
#if MESH_RADIO_TRACE_ENABLED
if (tracing) {
const uint64_t after = mesh::radiotrace::nowUs();
mesh::radiotrace::trace().transmitLaunch(static_cast<PhysicalLayer*>(this), trace_before, trace_after, after, RADIOLIB_ERR_NONE);
}
#endif
this->stagedMode = RADIOLIB_RADIO_MODE_NONE;
return RADIOLIB_ERR_NONE;
}
@@ -671,6 +727,11 @@ class CustomSX1262 : public SX1262 {
#endif
int16_t startReceive() override {
#if MESH_RADIO_TRACE_ENABLED
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t trace_before = tracing ? mesh::radiotrace::nowUs() : 0;
if (tracing) traceOperation(mesh::radiotrace::Rearm);
#endif
if (_profileSwitch.canResumeFast()) {
// Existing continuous RX already established buffer bases and the
// MeshCore IRQ map (including preamble detection). No TX/CAD/sleep/
@@ -723,6 +784,10 @@ class CustomSX1262 : public SX1262 {
}
_coldStandby = rc != RADIOLIB_ERR_NONE;
_profileSwitch.rxResult(rc, true);
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().receiveEntry(static_cast<PhysicalLayer*>(this),
trace_before, mesh::radiotrace::nowUs(), rc);
#endif
return rc;
}
// Make preamble detection visible to CAD while retaining RadioLib's
@@ -745,11 +810,46 @@ class CustomSX1262 : public SX1262 {
_profileSwitch.packetResult(rc, preambleLengthLoRa, crcTypeLoRa,
implicitLen, headerType, invertIQEnabled);
}
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().receiveEntry(static_cast<PhysicalLayer*>(this),
trace_before, mesh::radiotrace::nowUs(), rc);
#endif
return rc;
}
#if MESH_RADIO_TRACE_ENABLED
uint32_t getIrqFlags() override {
// Preserve the existing transaction and return bytes, including its
// legacy error behavior. Only the trace retains the checked SPI result;
// an unverified zero must never become an event-time lower bound.
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t before = tracing ? mesh::radiotrace::nowUs() : 0;
uint8_t data[] = {0, 0};
const int16_t result = this->mod->SPIreadStream(RADIOLIB_SX126X_CMD_GET_IRQ_STATUS, data, 2);
const uint32_t irq = (uint32_t(data[0]) << 8) | data[1];
if (tracing) mesh::radiotrace::trace().irq(static_cast<PhysicalLayer*>(this),
before, mesh::radiotrace::nowUs(), result, irq);
return irq;
}
#endif
bool isReceiving() {
if (isChipBusy()) return false; // asleep, cannot be mid-receive
#if MESH_RADIO_TRACE_ENABLED
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t trace_before = tracing ? mesh::radiotrace::nowUs() : 0;
const auto observed = [this, tracing, trace_before](bool held, bool header, mesh::radiotrace::Reason reason) {
if (tracing) mesh::radiotrace::trace().activity(static_cast<PhysicalLayer*>(this),
trace_before, mesh::radiotrace::nowUs(), held, header, reason);
return held;
};
#endif
if (isChipBusy()) {
#if MESH_RADIO_TRACE_ENABLED
return observed(false, false, mesh::radiotrace::FlagsCleared);
#else
return false; // asleep, cannot be mid-receive
#endif
}
uint32_t irq = getIrqFlags();
bool preamble = irq & RADIOLIB_SX126X_IRQ_PREAMBLE_DETECTED; // bit 2
@@ -760,13 +860,21 @@ class CustomSX1262 : public SX1262 {
clearIrqFlags(RADIOLIB_SX126X_IRQ_PREAMBLE_DETECTED | RADIOLIB_SX126X_IRQ_HEADER_VALID | RADIOLIB_SX126X_IRQ_HEADER_ERR | RADIOLIB_SX126X_IRQ_SYNC_WORD_VALID);
_activityAt = 0;
_headerSeen = false;
#if MESH_RADIO_TRACE_ENABLED
return observed(false, false, mesh::radiotrace::HeaderError);
#else
return false;
#endif
}
if (!header && _headerSeen) {
// Another path consumed the header IRQ; reset only our local timer.
_activityAt = 0;
_headerSeen = false;
#if MESH_RADIO_TRACE_ENABLED
return observed(false, false, mesh::radiotrace::FlagsCleared);
#else
return false;
#endif
}
if (header) {
if (!_headerSeen) { _headerSeen = true; _activityAt = now; };
@@ -774,9 +882,17 @@ class CustomSX1262 : public SX1262 {
MESH_DEBUG_PRINTLN("Clearing header IRQ after %ums", _maxPayloadMillis);
clearIrqFlags(RADIOLIB_SX126X_IRQ_PREAMBLE_DETECTED | RADIOLIB_SX126X_IRQ_HEADER_VALID | RADIOLIB_SX126X_IRQ_HEADER_ERR | RADIOLIB_SX126X_IRQ_SYNC_WORD_VALID);
_activityAt = 0; _headerSeen = false;
#if MESH_RADIO_TRACE_ENABLED
return observed(false, true, mesh::radiotrace::PayloadExpired);
#else
return false;
#endif
}
#if MESH_RADIO_TRACE_ENABLED
return observed(true, true, mesh::radiotrace::None);
#else
return true;
#endif
}
if (preamble) {
@@ -786,12 +902,24 @@ class CustomSX1262 : public SX1262 {
_activityAt = 0;
MESH_DEBUG_PRINTLN("Clearing preamble IRQ after %ums", _preambleMillis);
#if MESH_RADIO_TRACE_ENABLED
return observed(false, false, mesh::radiotrace::PreambleExpired);
#else
return false;
#endif
}
#if MESH_RADIO_TRACE_ENABLED
return observed(true, false, mesh::radiotrace::None);
#else
return true;
#endif
}
_activityAt = 0; _headerSeen = false;
#if MESH_RADIO_TRACE_ENABLED
return observed(false, false, mesh::radiotrace::FlagsCleared);
#else
return false;
#endif
}
bool canUseRxPowerSavingDutyCycle(uint32_t rx_us, uint32_t sleep_us) const {
+29
View File
@@ -0,0 +1,29 @@
#include "ESP32RadioTrace.h"
#if MESH_RADIO_TRACE_ENABLED
#include <esp_timer.h>
#include <Utils.h>
namespace mesh {
namespace radiotrace {
Trace& trace() {
static Trace value;
return value;
}
uint64_t nowUs() { return static_cast<uint64_t>(esp_timer_get_time()); }
uint64_t fingerprint(const uint8_t* bytes, size_t length) {
uint8_t hash[8];
mesh::Utils::sha256(hash, sizeof(hash), bytes, static_cast<int>(length));
// The schema is an integer rendered as 16 hex digits, independent of host
// endianness. It hashes complete wire bytes, including the route header.
uint64_t result = 0;
for (uint8_t value : hash) result = (result << 8) | value;
return result;
}
} // namespace radiotrace
} // namespace mesh
#endif
+372
View File
@@ -0,0 +1,372 @@
#pragma once
#if defined(ESP32_PLATFORM) && defined(MESH_HIL_RADIO_TRACE) && MESH_HIL_RADIO_TRACE
#define MESH_RADIO_TRACE_ENABLED 1
#include <stddef.h>
#include <stdint.h>
namespace mesh {
namespace radiotrace {
// Explicit lab builds only. No I/O, allocation, extra radio polling, or policy
// decisions occur here. Times are microseconds relative to a bounded capture.
enum class State : uint8_t { Off = 0, Armed = 1, Capturing = 2, Frozen = 3 };
enum Reason : uint8_t {
None = 0, HeaderError = 1, PreambleExpired = 2, PayloadExpired = 3,
FlagsCleared = 4, Reconfigure = 5, ReceiveRead = 6, Rearm = 7,
Transmit = 8, Recovery = 9, CaptureEnded = 10, SpiFailure = 11,
};
enum Flag : uint8_t {
Invalid = 1, SpiError = 2, MissingBound = 4, Interrupted = 8,
Clipped = 16, NotConfirmed = 32, RearmFailed = 64, ReadError = 128,
};
static constexpr uint32_t MaxCaptureMs = 180000;
static constexpr uint32_t MaxDelayMs = 180000;
static constexpr uint32_t BucketWidthUs = 3000000;
static constexpr uint16_t NoIndex = UINT16_MAX;
static constexpr uint32_t NoTime = UINT32_MAX;
#if defined(MESH_HIL_RADIO_TRACE_TX_ONLY) && MESH_HIL_RADIO_TRACE_TX_ONLY
static constexpr size_t SpanCapacity = 0, RxCapacity = 0, BucketCapacity = 0;
static constexpr const char* Marker = "MCRFTRACE1:TXONLY40";
#else
static constexpr size_t SpanCapacity = 192, RxCapacity = 192, BucketCapacity = 64;
static constexpr const char* Marker = "MCRFTRACE1:RX192:TX40";
#endif
static constexpr size_t TxCapacity = 40;
struct Span {
uint32_t begin_us, header_us, end_us;
uint16_t rx_index;
uint8_t profile, reason;
};
struct RxRecord {
uint32_t done_lo_us, done_hi_us, read_begin_us, rearm_end_us;
uint64_t hash64;
uint16_t len, span_index;
uint8_t profile, flags;
uint16_t reserved;
};
struct TxRecord {
uint64_t hash64;
uint32_t launch_lo_us, launch_hi_us, busy_low_us;
uint32_t done_lo_us, done_hi_us, toa_us;
uint16_t len;
uint8_t profile, flags;
uint32_t spi_errors;
};
struct Bucket {
uint32_t start_us, max_scan_gap_us, max_visit_overdue_us;
uint32_t max_scan_gap_end_us, max_visit_overdue_end_us;
};
static_assert(sizeof(Span) == 16, "Radio trace span layout changed");
static_assert(sizeof(RxRecord) == 32, "Radio trace RX layout changed");
static_assert(sizeof(TxRecord) == 40, "Radio trace TX layout changed");
class Trace {
const void* _phy = nullptr;
uint8_t _profile = 0;
uint32_t _generation = 0;
uint32_t _seen_generation[2] = {};
uint8_t _seen_profiles = 0;
uint16_t _hold = NoIndex, _reading = NoIndex, _sending = NoIndex;
uint16_t _last_hold = NoIndex;
bool _rx_mode = false, _rx_lo_valid = false, _rx_done = false;
bool _tx_lo_valid = false, _tx_done = false;
uint32_t _rx_lo = 0, _rx_hi = 0, _tx_lo = 0, _last_scan = NoTime;
bool owner(const void* phy) const { return phy != nullptr && phy == _phy; }
uint32_t relative(uint64_t now) const {
return now <= epoch_us ? 0 : static_cast<uint32_t>(now - epoch_us);
}
void resetCounters() {
span_count = rx_count = tx_count = bucket_count = 0;
span_dropped = rx_dropped = tx_dropped = spi_errors = invalidations = 0;
context_errors = max_scan_gap_us = max_visit_overdue_us = max_blackout_us = 0;
flags = 0;
_hold = _reading = _sending = _last_hold = NoIndex;
_rx_mode = false;
_rx_lo_valid = _rx_done = _tx_lo_valid = _tx_done = false;
_last_scan = NoTime;
_seen_profiles = 0;
}
void invalidate(uint8_t detail) {
++invalidations;
flags |= uint32_t(Invalid | detail);
if (_reading != NoIndex) rx[_reading].flags |= uint8_t(Invalid | detail);
if (_sending != NoIndex) tx[_sending].flags |= uint8_t(Invalid | detail);
}
void closeHold(uint32_t when, Reason reason) {
if (_hold == NoIndex) return;
Span& span = spans[_hold];
span.end_us = when < span.begin_us ? span.begin_us : when;
span.reason = reason;
_last_hold = _hold;
_hold = NoIndex;
}
void freeze(uint64_t when) {
const uint32_t stamp = relative(when > end_us ? end_us : when);
closeHold(stamp, CaptureEnded);
if (_sending != NoIndex) {
tx[_sending].flags |= uint8_t(Invalid | Clipped | NotConfirmed);
_sending = NoIndex;
invalidate(Clipped);
}
if (_reading != NoIndex) {
rx[_reading].flags |= uint8_t(Invalid | Clipped);
_reading = NoIndex;
invalidate(Clipped);
}
state = State::Frozen;
}
public:
State state = State::Off;
uint32_t session = 0;
uint64_t epoch_us = 0, end_us = 0;
uint32_t span_count = 0, rx_count = 0, tx_count = 0, bucket_count = 0;
uint32_t span_dropped = 0, rx_dropped = 0, tx_dropped = 0;
uint32_t spi_errors = 0, invalidations = 0, context_errors = 0;
uint32_t max_scan_gap_us = 0, max_visit_overdue_us = 0, max_blackout_us = 0;
uint32_t flags = 0;
Span spans[SpanCapacity ? SpanCapacity : 1] = {};
RxRecord rx[RxCapacity ? RxCapacity : 1] = {};
TxRecord tx[TxCapacity] = {};
Bucket buckets[BucketCapacity ? BucketCapacity : 1] = {};
bool pending() const { return state == State::Armed || state == State::Capturing; }
bool arm(uint64_t now, uint32_t delay_ms, uint32_t duration_ms) {
if (pending() || delay_ms > MaxDelayMs || !duration_ms || duration_ms > MaxCaptureMs)
return false;
resetCounters();
++session;
if (!session) ++session;
epoch_us = now + uint64_t(delay_ms) * 1000;
end_us = epoch_us + uint64_t(duration_ms) * 1000;
state = State::Armed;
return true;
}
void stop(uint64_t now) { if (pending()) freeze(now); }
bool tick(uint64_t now) {
if (!pending()) return false;
if (now >= end_us) { freeze(end_us); return false; }
if (now < epoch_us) return false;
if (state == State::Armed) {
state = State::Capturing;
// Existing activity at the boundary has no observed beginning. Subsequent
// true polls can establish a conservative, shorter ownership span.
_rx_lo_valid = _rx_done = _tx_lo_valid = _tx_done = false;
}
return true;
}
void context(const void* phy, uint8_t profile, uint32_t generation) {
if (!_phy || !pending()) _phy = phy;
if (!owner(phy)) {
if (pending()) { ++context_errors; invalidate(Interrupted); }
return;
}
if (profile > 1) {
if (pending()) { ++context_errors; invalidate(Interrupted); }
return;
}
if (pending()) {
const uint8_t bit = uint8_t(1U << profile);
// The sender-only experiment deliberately replaces its single physical
// tuple between completed transmissions. Receiver captures require a
// stable pair; neither mode permits changing an in-flight TX epoch.
if (RxCapacity && state == State::Capturing && (_seen_profiles & bit)
&& _seen_generation[profile] != generation) invalidate(Interrupted);
_seen_generation[profile] = generation;
_seen_profiles |= bit;
}
if (state == State::Capturing && (profile != _profile || generation != _generation)) {
if (_hold != NoIndex) invalidate(Interrupted);
if (_sending != NoIndex) {
invalidate(Interrupted);
_tx_lo_valid = _tx_done = false;
}
closeHold(_last_scan == NoTime ? 0 : _last_scan, Reconfigure);
_rx_lo_valid = _rx_done = false;
}
_profile = profile;
_generation = generation;
}
void operation(const void* phy, uint64_t now, Reason reason) {
if (!owner(phy) || !pending()) return;
const bool capturing = tick(now);
_rx_mode = false;
_rx_lo_valid = _rx_done = false;
if (capturing) closeHold(relative(now), reason);
}
void receiveEntry(const void* phy, uint64_t before, uint64_t after, int16_t result) {
if (!owner(phy) || !pending()) return;
const bool capturing = tick(after);
_rx_mode = result == 0;
_rx_lo_valid = _rx_done = false;
if (!capturing) return;
closeHold(relative(before), Rearm);
if (_reading != NoIndex) {
RxRecord& record = rx[_reading];
record.rearm_end_us = relative(after);
const uint32_t elapsed = record.rearm_end_us - record.read_begin_us;
if (elapsed > max_blackout_us) max_blackout_us = elapsed;
if (result != 0) record.flags |= uint8_t(Invalid | RearmFailed);
}
}
void dio(const void* phy, uint64_t before, uint64_t after, bool high) {
if (!owner(phy) || !tick(after) || high || before < epoch_us) return;
if (_sending != NoIndex && tx[_sending].launch_lo_us != NoTime && !_tx_done) {
_tx_lo = relative(before); _tx_lo_valid = true;
}
if (_rx_mode && !_rx_done) { _rx_lo = relative(before); _rx_lo_valid = true; }
}
void irq(const void* phy, uint64_t before, uint64_t after, int16_t result, uint32_t irq) {
if (!owner(phy) || !tick(after)) return;
if (result != 0) {
++spi_errors;
invalidate(SpiError);
closeHold(relative(before), SpiFailure);
_rx_lo_valid = _tx_lo_valid = false;
return;
}
if (_sending != NoIndex && tx[_sending].launch_lo_us != NoTime && !_tx_done) {
if (irq & 1U) {
TxRecord& record = tx[_sending];
record.done_lo_us = _tx_lo;
record.done_hi_us = relative(after);
if (!_tx_lo_valid) record.flags |= MissingBound;
_tx_done = true;
} else if (before >= epoch_us) {
_tx_lo = relative(before);
_tx_lo_valid = true;
}
}
if (_rx_mode && !_rx_done) {
if (irq & 2U) { _rx_hi = relative(after); _rx_done = true; }
else if (before >= epoch_us) { _rx_lo = relative(before); _rx_lo_valid = true; }
}
}
void activity(const void* phy, uint64_t before, uint64_t after, bool held,
bool header, Reason reason) {
if (!owner(phy) || !tick(after) || !SpanCapacity) return;
if (!held) { closeHold(relative(before), reason); return; }
if (_hold == NoIndex) {
if (span_count >= SpanCapacity) { ++span_dropped; invalidate(Clipped); return; }
_hold = static_cast<uint16_t>(span_count++);
spans[_hold] = {relative(after), header ? relative(after) : NoTime,
NoTime, NoIndex, _profile, None};
} else if (header && spans[_hold].header_us == NoTime) {
spans[_hold].header_us = relative(after);
}
}
uint16_t receiveRead(const void* phy, uint64_t now) {
if (!owner(phy) || !tick(now) || !RxCapacity) return NoIndex;
closeHold(relative(now), ReceiveRead);
if (rx_count >= RxCapacity) { ++rx_dropped; invalidate(Clipped); return NoIndex; }
if (_reading != NoIndex) { invalidate(Interrupted); _reading = NoIndex; }
const uint16_t index = static_cast<uint16_t>(rx_count++);
_reading = index;
const uint16_t span = _last_hold != NoIndex && spans[_last_hold].reason == ReceiveRead
? _last_hold : NoIndex;
rx[index] = {_rx_lo, _rx_hi, relative(now), NoTime, 0, 0, span, _profile, 0, 0};
if (!_rx_done || !_rx_lo_valid) rx[index].flags |= MissingBound;
if (_last_hold != NoIndex && spans[_last_hold].reason == ReceiveRead)
spans[_last_hold].rx_index = index;
_last_hold = NoIndex;
_rx_lo_valid = _rx_done = false;
return index;
}
void receiveFinish(const void* phy, uint16_t index, uint64_t now,
uint64_t hash, uint16_t length, bool good) {
if (!owner(phy) || !tick(now) || index == NoIndex || index >= rx_count) return;
RxRecord& record = rx[index];
record.hash64 = hash;
record.len = length;
if (!good) record.flags |= uint8_t(Invalid | ReadError);
if (record.rearm_end_us == NoTime) record.flags |= uint8_t(Invalid | RearmFailed);
if (_reading == index) _reading = NoIndex;
}
void transmitPrepare(const void* phy, uint64_t now, uint64_t hash,
uint16_t length, uint32_t toa) {
if (!owner(phy) || !tick(now)) return;
closeHold(relative(now), Transmit);
_rx_mode = _rx_lo_valid = _rx_done = false;
if (_sending != NoIndex) { invalidate(Interrupted); _sending = NoIndex; }
if (tx_count >= TxCapacity) { ++tx_dropped; invalidate(Clipped); return; }
_sending = static_cast<uint16_t>(tx_count++);
tx[_sending] = {hash, NoTime, NoTime, NoTime, NoTime, NoTime,
toa, length, _profile, NotConfirmed, spi_errors};
_tx_lo_valid = _tx_done = false;
}
void transmitLaunch(const void* phy, uint64_t before, uint64_t after,
uint64_t busy_low, int16_t result) {
if (!owner(phy) || !tick(busy_low > after ? busy_low : after) || _sending == NoIndex) return;
TxRecord& record = tx[_sending];
record.launch_lo_us = relative(before);
record.launch_hi_us = relative(after);
record.busy_low_us = busy_low ? relative(busy_low) : NoTime;
if (result != 0) record.flags |= uint8_t(Invalid | Interrupted);
}
void transmitLaunchBegin(const void* phy, uint64_t now) {
if (!owner(phy) || !tick(now) || _sending == NoIndex) return;
tx[_sending].launch_lo_us = relative(now);
_tx_lo_valid = _tx_done = false;
}
void transmitFinish(const void* phy, uint64_t now, bool confirmed) {
if (!owner(phy) || !tick(now) || _sending == NoIndex) return;
TxRecord& record = tx[_sending];
record.spi_errors = spi_errors - record.spi_errors;
if (confirmed && _tx_done) record.flags &= uint8_t(~NotConfirmed);
else record.flags |= uint8_t(Invalid | Interrupted | NotConfirmed);
if (!_tx_lo_valid || !_tx_done || record.launch_lo_us == NoTime
|| record.launch_hi_us == NoTime || record.busy_low_us == NoTime)
record.flags |= MissingBound;
_sending = NoIndex;
_tx_lo_valid = _tx_done = false;
}
void scan(const void* phy, uint64_t now, uint64_t visit_started, uint32_t visit_us,
bool gap_sample = true) {
if (!owner(phy) || !tick(now)) return;
const uint32_t stamp = relative(now);
const uint32_t gap = !gap_sample || _last_scan == NoTime ? 0 : stamp - _last_scan;
if (gap_sample) _last_scan = stamp;
const uint64_t elapsed = now >= visit_started ? now - visit_started : 0;
const uint64_t late = visit_us && elapsed > visit_us ? elapsed - visit_us : 0;
const uint32_t overdue = late > UINT32_MAX ? UINT32_MAX : static_cast<uint32_t>(late);
if (gap > max_scan_gap_us) max_scan_gap_us = gap;
if (overdue > max_visit_overdue_us) max_visit_overdue_us = overdue;
if (!BucketCapacity) return;
const uint32_t index = stamp / BucketWidthUs;
if (index >= BucketCapacity) { invalidate(Clipped); return; }
while (bucket_count <= index) {
buckets[bucket_count] = {bucket_count * BucketWidthUs, 0, 0, 0, 0};
++bucket_count;
}
Bucket& bucket = buckets[index];
if (gap > bucket.max_scan_gap_us) {
bucket.max_scan_gap_us = gap;
bucket.max_scan_gap_end_us = stamp;
}
if (overdue > bucket.max_visit_overdue_us) {
bucket.max_visit_overdue_us = overdue;
bucket.max_visit_overdue_end_us = stamp;
}
}
};
static_assert(sizeof(Trace) <= 12 * 1024, "Optional radio trace exceeded its RAM budget");
#if defined(MESH_HIL_RADIO_TRACE_TX_ONLY) && MESH_HIL_RADIO_TRACE_TX_ONLY
static_assert(sizeof(Trace) <= 3 * 1024, "Sender-only trace exceeded its RAM budget");
#endif
Trace& trace();
uint64_t nowUs();
uint64_t fingerprint(const uint8_t* bytes, size_t length);
} // namespace radiotrace
} // namespace mesh
#else
#define MESH_RADIO_TRACE_ENABLED 0
#endif
+177
View File
@@ -0,0 +1,177 @@
#pragma once
// Local, explicitly instrumented builds only. Never write asynchronous output.
#if defined(ESP32_PLATFORM) && defined(MESH_HIL_RADIO_TRACE) && MESH_HIL_RADIO_TRACE
#include "ESP32RadioTrace.h"
#include <esp_system.h>
#include <stdio.h>
#include <string.h>
namespace mesh { namespace radiotrace {
inline uint64_t bootToken() {
// A capture identity, not a security token. Initialize outside radio hot paths.
static const uint64_t value = (uint64_t(esp_random()) << 32) | esp_random();
return value;
}
inline const char* imageMarker() {
return Marker;
}
inline bool parseTraceNumber(const char*& value, uint32_t& out) {
if (*value < '0' || *value > '9') return false;
uint32_t result = 0;
while (*value >= '0' && *value <= '9') {
const uint32_t digit = *value++ - '0';
if (result > (UINT32_MAX - digit) / 10) return false;
result = result * 10 + digit;
}
out = result;
return true;
}
inline void formatTraceRecord(const Trace& capture, unsigned kind, uint32_t index,
char* reply, size_t capacity) {
const uint32_t counts[] = {capture.span_count, capture.rx_count,
capture.tx_count, capture.bucket_count};
const size_t limits[] = {SpanCapacity, RxCapacity, TxCapacity, BucketCapacity};
if (kind >= 4 || index >= counts[kind] || index >= limits[kind]) {
snprintf(reply, capacity, "Error: trace record unavailable");
return;
}
if (kind == 0) {
const Span& r = capture.spans[index];
snprintf(reply, capacity, "> span=%lu,%lu,%lu,%lu,%u,%u,%u",
(unsigned long)index, (unsigned long)r.begin_us, (unsigned long)r.header_us,
(unsigned long)r.end_us, (unsigned)r.rx_index, (unsigned)r.profile, (unsigned)r.reason);
} else if (kind == 1) {
const RxRecord& r = capture.rx[index];
snprintf(reply, capacity, "> rx=%lu,%lu,%lu,%lu,%lu,%016llx,%u,%u,%u,%u",
(unsigned long)index, (unsigned long)r.done_lo_us, (unsigned long)r.done_hi_us,
(unsigned long)r.read_begin_us, (unsigned long)r.rearm_end_us,
(unsigned long long)r.hash64, (unsigned)r.len, (unsigned)r.span_index,
(unsigned)r.profile, (unsigned)r.flags);
} else if (kind == 2) {
const TxRecord& r = capture.tx[index];
snprintf(reply, capacity, "> tx=%lu,%016llx,%lu,%lu,%lu,%lu,%lu,%lu,%u,%u,%u,%lu",
(unsigned long)index, (unsigned long long)r.hash64,
(unsigned long)r.launch_lo_us, (unsigned long)r.launch_hi_us,
(unsigned long)r.busy_low_us, (unsigned long)r.done_lo_us,
(unsigned long)r.done_hi_us, (unsigned long)r.toa_us,
(unsigned)r.len, (unsigned)r.profile, (unsigned)r.flags, (unsigned long)r.spi_errors);
} else {
const Bucket& r = capture.buckets[index];
snprintf(reply, capacity, "> bucket=%lu,%lu,%lu,%lu,%lu,%lu", (unsigned long)index,
(unsigned long)r.start_us, (unsigned long)r.max_scan_gap_us,
(unsigned long)r.max_visit_overdue_us, (unsigned long)r.max_scan_gap_end_us,
(unsigned long)r.max_visit_overdue_end_us);
}
}
inline bool handleTraceCommand(const char* command, char* reply, size_t capacity) {
if (!command || !reply || !capacity) return false;
const char* get = "get radio.trace";
const char* set = "set radio.trace";
const bool getter = !strncmp(command, get, strlen(get))
&& (command[strlen(get)] == 0 || command[strlen(get)] == ' ');
const bool setter = !strncmp(command, set, strlen(set))
&& (command[strlen(set)] == 0 || command[strlen(set)] == ' ');
if (!getter && !setter) return false;
const char* value = command + strlen(getter ? get : set);
if (*value == ' ') ++value;
Trace& capture = trace();
const uint64_t now = nowUs();
capture.tick(now);
if (getter && !*value) {
snprintf(reply, capacity,
"> rt=1 boot=%016llx session=%lu state=%u epoch=%llu end=%llu flags=%lu mode=%s",
(unsigned long long)bootToken(), (unsigned long)capture.session,
(unsigned)capture.state, (unsigned long long)capture.epoch_us,
(unsigned long long)capture.end_us, (unsigned long)capture.flags,
#if defined(MESH_HIL_RADIO_TRACE_TX_ONLY) && MESH_HIL_RADIO_TRACE_TX_ONLY
"tx");
#else
"rx");
#endif
return true;
}
if (getter && !strcmp(value, "marker")) {
snprintf(reply, capacity, "> %s", imageMarker());
return true;
}
if (getter && !strncmp(value, "clock ", 6)) {
const char* nonce = value + 6;
bool valid = strlen(nonce) == 16;
for (size_t i = 0; valid && i < 16; ++i) {
const char c = nonce[i];
valid = (c >= '0' && c <= '9') || (c >= 'a' && c <= 'f')
|| (c >= 'A' && c <= 'F');
}
if (valid) {
snprintf(reply, capacity, "> rt=1 boot=%016llx session=%lu nonce=%s us=%llu",
(unsigned long long)bootToken(), (unsigned long)capture.session, nonce,
(unsigned long long)now);
} else snprintf(reply, capacity, "Error: clock requires exactly 16 hex digits");
return true;
}
if (getter && !strcmp(value, "stats")) {
snprintf(reply, capacity,
"> spans=%lu rx=%lu tx=%lu buckets=%lu span_drop=%lu rx_drop=%lu tx_drop=%lu",
(unsigned long)capture.span_count, (unsigned long)capture.rx_count,
(unsigned long)capture.tx_count, (unsigned long)capture.bucket_count,
(unsigned long)capture.span_dropped, (unsigned long)capture.rx_dropped,
(unsigned long)capture.tx_dropped);
return true;
}
if (getter && !strcmp(value, "gaps")) {
snprintf(reply, capacity,
"> scan=%lu overdue=%lu blackout=%lu spi_err=%lu invalid=%lu context_err=%lu",
(unsigned long)capture.max_scan_gap_us, (unsigned long)capture.max_visit_overdue_us,
(unsigned long)capture.max_blackout_us, (unsigned long)capture.spi_errors,
(unsigned long)capture.invalidations, (unsigned long)capture.context_errors);
return true;
}
if (setter && !strcmp(value, "stop")) {
capture.stop(now);
snprintf(reply, capacity, "OK - radio trace frozen");
return true;
}
if (setter && !strncmp(value, "arm ", 4)) {
const char* argument = value + 4;
uint32_t delay = 0, duration = 0;
if (!parseTraceNumber(argument, delay) || *argument++ != ' '
|| !parseTraceNumber(argument, duration) || *argument
|| delay > MaxDelayMs || !duration || duration > MaxCaptureMs) {
snprintf(reply, capacity, "Error: arm requires delay 0..180000 and duration 1..180000 ms");
} else if (capture.state == State::Armed || capture.state == State::Capturing) {
snprintf(reply, capacity, "Error: stop the current trace before arming");
} else if (!capture.arm(now, delay, duration)) {
snprintf(reply, capacity, "Error: radio trace could not be armed");
} else snprintf(reply, capacity, "OK - radio trace armed session=%lu", (unsigned long)capture.session);
return true;
}
// Dump frozen RAM only, so reads cannot perturb an active capture or race it.
if (getter) {
const char* kinds[] = {"span ", "rx ", "tx ", "bucket "};
for (unsigned kind = 0; kind < 4; ++kind) {
if (strncmp(value, kinds[kind], strlen(kinds[kind]))) continue;
const char* argument = value + strlen(kinds[kind]);
uint32_t index = 0;
if (!parseTraceNumber(argument, index) || *argument) {
snprintf(reply, capacity, "Error: trace index must be an unsigned integer");
} else if (capture.state != State::Frozen) {
snprintf(reply, capacity, "Error: stop the trace before reading records");
} else {
// Record formatters below are intentionally bounded to one CLI frame.
formatTraceRecord(capture, kind, index, reply, capacity);
}
return true;
}
}
snprintf(reply, capacity, "Error: use get radio.trace [clock N|stats|gaps|marker|span N|rx N|tx N|bucket N] or set radio.trace arm D T|stop");
return true;
}
} }
#endif
+72 -1
View File
@@ -191,7 +191,15 @@ bool RadioLibWrapper::hasAssertedRadioInterrupt() const {
// GPIO_IS_VALID_GPIO shifts by its argument on older IDF versions, so its
// mask check must follow the range check even for an invalid/NC module pin.
if (irq == RADIOLIB_NC || irq >= SOC_GPIO_PIN_COUNT || !GPIO_IS_VALID_GPIO(irq)) return false;
return module->hal->digitalRead(irq) == module->hal->GpioLevelHigh;
#if MESH_RADIO_TRACE_ENABLED
const bool tracing = mesh::radiotrace::trace().pending();
const uint64_t before = tracing ? mesh::radiotrace::nowUs() : 0;
#endif
const bool asserted = module->hal->digitalRead(irq) == module->hal->GpioLevelHigh;
#if MESH_RADIO_TRACE_ENABLED
if (tracing) mesh::radiotrace::trace().dio(_radio, before, mesh::radiotrace::nowUs(), asserted);
#endif
return asserted;
#else
return false;
#endif
@@ -212,6 +220,9 @@ bool RadioLibWrapper::claimRadioInterrupt() {
}
void RadioLibWrapper::begin() {
#if MESH_RADIO_TRACE_ENABLED
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
#endif
#if MESH_ENABLE_TX_BEACONS
if (_beacon_owned) return;
#endif
@@ -340,6 +351,9 @@ bool RadioLibWrapper::setTxPower(int8_t dbm) {
}
uint8_t RadioLibWrapper::beginReconfigure() {
#if MESH_RADIO_TRACE_ENABLED
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
#endif
#if MESH_ENABLE_TX_BEACONS
if (_beacon_owned && !_beacon_restoring) return 2;
#endif
@@ -610,6 +624,9 @@ mesh::RadioParamApplyResult RadioLibWrapper::tuneProfile(uint8_t profile) {
cacheParams(p.freq, p.bw, p.sf, p.cr);
_active_profile = profile;
_profile_generation = _profiles.generation[profile];
#if MESH_RADIO_TRACE_ENABLED
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
#endif
_profile_refresh_required = false;
_profile_repair_required = false;
endReconfigure(resume);
@@ -875,6 +892,12 @@ mesh::RadioParamApplyResult RadioLibWrapper::tryRestoreCodingRate(uint8_t cr) {
}
void RadioLibWrapper::serviceProfileScan() {
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending()) {
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
mesh::radiotrace::trace().scan(_radio, mesh::radiotrace::nowUs(), 0, 0);
}
#endif
#if defined(NRF52_PLATFORM)
_profile_idle_visit_ticks = 0; // Every deferred/restarted scan fails closed.
#endif
@@ -965,6 +988,10 @@ void RadioLibWrapper::serviceProfileScan() {
#if defined(ESP32_PLATFORM)
// Keep long visits and light-sleep elapsed time in the same 64-bit domain.
const uint64_t now_us = static_cast<uint64_t>(esp_timer_get_time());
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending())
mesh::radiotrace::trace().scan(_radio, now_us, _esp32_profile_visit_started_us, visit_us, false);
#endif
if (now_us < _esp32_profile_visit_started_us
|| now_us - _esp32_profile_visit_started_us >= visit_us) target ^= 1;
#else
@@ -2019,6 +2046,12 @@ bool RadioLibWrapper::serviceCarrierWave() {
#endif
void RadioLibWrapper::loop() {
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending()) {
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
mesh::radiotrace::trace().tick(mesh::radiotrace::nowUs());
}
#endif
#if MESH_ENABLE_TX_BEACONS
if (_beacon_owned) return;
#endif
@@ -2334,6 +2367,11 @@ bool RadioLibWrapper::setRxPowerSaving(bool enabled, uint32_t rx_us, uint32_t sl
}
int RadioLibWrapper::recvRaw(uint8_t* bytes, int sz) {
#if MESH_RADIO_TRACE_ENABLED
auto& radio_trace = mesh::radiotrace::trace();
uint16_t trace_rx = mesh::radiotrace::NoIndex;
radio_trace.context(_radio, _active_profile, _profile_generation);
#endif
#if MESH_ENABLE_TX_BEACONS
if (_beacon_owned) return 0;
#endif
@@ -2346,6 +2384,9 @@ int RadioLibWrapper::recvRaw(uint8_t* bytes, int sz) {
last_radio_interrupt_millis = millis(); // ISR fired -> radio hardware is alive
const bool packet_ready = isPacketReady();
if (packet_ready) {
#if MESH_RADIO_TRACE_ENABLED
if (radio_trace.pending()) trace_rx = radio_trace.receiveRead(_radio, mesh::radiotrace::nowUs());
#endif
#if defined(USE_LR2021)
// The LR2021 base reader clears FIFO/IRQs while otherwise staying in
// continuous RX. Freeze reception before taking length/status/FIFO
@@ -2431,6 +2472,11 @@ int RadioLibWrapper::recvRaw(uint8_t* bytes, int sz) {
_rx_retry_pending = true;
MESH_DEBUG_PRINTLN("RadioLibWrapper: error: startReceive after packet (%d)", err);
}
#if MESH_RADIO_TRACE_ENABLED
if (trace_rx != mesh::radiotrace::NoIndex)
radio_trace.receiveFinish(_radio, trace_rx, mesh::radiotrace::nowUs(),
mesh::radiotrace::fingerprint(bytes, len), static_cast<uint16_t>(len), true);
#endif
return len;
}
@@ -2448,6 +2494,12 @@ int RadioLibWrapper::recvRaw(uint8_t* bytes, int sz) {
}
startRecv();
}
#if MESH_RADIO_TRACE_ENABLED
if (trace_rx != mesh::radiotrace::NoIndex)
radio_trace.receiveFinish(_radio, trace_rx, mesh::radiotrace::nowUs(),
len > 0 ? mesh::radiotrace::fingerprint(bytes, len) : 0,
static_cast<uint16_t>(len), len > 0);
#endif
return len;
}
@@ -2528,12 +2580,23 @@ bool RadioLibWrapper::startSendRaw(const uint8_t* bytes, int len) {
return false;
}
_irq_probe_failures = 0;
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending()) {
mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation);
mesh::radiotrace::trace().transmitPrepare(_radio, mesh::radiotrace::nowUs(),
mesh::radiotrace::fingerprint(bytes, len), static_cast<uint16_t>(len), _radio->getTimeOnAir(len));
}
#endif
int err = _radio->startTransmit((uint8_t *) bytes, len);
if (err == RADIOLIB_ERR_NONE) {
state = STATE_TX_WAIT;
return true;
}
MESH_DEBUG_PRINTLN("RadioLibWrapper: error: startTransmit(%d)", err);
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending())
mesh::radiotrace::trace().transmitFinish(_radio, mesh::radiotrace::nowUs(), false);
#endif
idle(); // trigger another startRecv()
_board->onAfterTransmit();
if (err == RADIOLIB_ERR_SPI_CMD_TIMEOUT) {
@@ -2556,12 +2619,20 @@ bool RadioLibWrapper::isSendComplete() {
_irq_probe_failures = 0;
state = STATE_IDLE;
n_sent++;
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending())
mesh::radiotrace::trace().transmitFinish(_radio, mesh::radiotrace::nowUs(), true);
#endif
return true;
}
return false;
}
void RadioLibWrapper::onSendFinished() {
#if MESH_RADIO_TRACE_ENABLED
if (mesh::radiotrace::trace().pending())
mesh::radiotrace::trace().transmitFinish(_radio, mesh::radiotrace::nowUs(), false);
#endif
_radio->finishTransmit();
// Receive has not been rearmed yet: these are completion/probe events for
// the retired TX. They must not block the Dispatcher's timeout recovery.
+1
View File
@@ -10,6 +10,7 @@
#include "RadioAirtime.h"
#include "RXPowerSaving.h"
#include "HilTxFrequencyGuard.h"
#include "ESP32RadioTrace.h"
#if defined(STATION_G3_ESP32)
#include <StationG3RadioSlot.h>
#endif
+232
View File
@@ -0,0 +1,232 @@
#include <cassert>
#include <cstdint>
#include <cstdio>
#include <cstring>
#include <helpers/radiolib/ESP32RadioTrace.h>
using namespace mesh::radiotrace;
static int radio;
static constexpr uint64_t Base = UINT64_C(0x100000000) + 100000;
static void begin(Trace& t) {
t.context(&radio, 0, 7);
assert(t.arm(Base, 0, MaxCaptureMs));
assert(t.tick(Base));
}
static void lifetime() {
Trace t;
assert(!t.pending() && !t.tick(Base));
assert(!t.arm(Base, 0, 0));
assert(!t.arm(Base, MaxDelayMs + 1, 1));
assert(!t.arm(Base, 0, MaxCaptureMs + 1));
assert(t.arm(Base, 10, 20));
assert(t.session == 1 && t.state == State::Armed);
assert(!t.arm(Base, 0, 1));
assert(!t.tick(Base + 9999));
assert(t.tick(Base + 10000));
assert(t.state == State::Capturing);
assert(!t.tick(Base + 30000));
assert(t.state == State::Frozen && !t.pending());
assert(t.arm(Base + 40000, 0, 1) && t.session == 2);
t.stop(Base + 40500);
assert(t.state == State::Frozen);
assert(t.arm(Base, 10, 10));
t.stop(Base);
assert(t.state == State::Frozen && !t.span_count && !t.flags);
}
static void holdsAndReceipts() {
Trace t; begin(t);
t.receiveEntry(&radio, Base, Base + 1, 0);
t.irq(&radio, Base + 10, Base + 11, 0, 0);
t.activity(&radio, Base + 20, Base + 21, true, false, None);
t.activity(&radio, Base + 30, Base + 31, true, false, None);
t.activity(&radio, Base + 40, Base + 41, true, true, None);
t.activity(&radio, Base + 50, Base + 51, true, true, None);
assert(t.span_count == 1 && t.spans[0].begin_us == 21);
assert(t.spans[0].header_us == 41 && t.spans[0].end_us == NoTime);
t.irq(&radio, Base + 60, Base + 61, 0, 2);
auto i = t.receiveRead(&radio, Base + 70);
assert(i == 0 && t.rx_count == 1);
assert(t.rx[0].done_lo_us == 10 && t.rx[0].done_hi_us == 61);
assert(t.rx[0].span_index == 0 && t.spans[0].rx_index == 0);
assert(t.spans[0].end_us == 70 && t.spans[0].reason == ReceiveRead);
t.operation(&radio, Base + 80, Rearm);
t.receiveEntry(&radio, Base + 80, Base + 90, 0);
t.receiveFinish(&radio, i, Base + 100, UINT64_C(0xaabbccddeeff1234), 101, true);
assert(t.rx[0].hash64 == UINT64_C(0xaabbccddeeff1234));
assert(t.rx[0].len == 101 && !t.rx[0].flags);
assert(t.rx[0].rearm_end_us == 90 && t.max_blackout_us == 20);
t.activity(&radio, Base + 110, Base + 111, true, false, None);
t.activity(&radio, Base + 210, Base + 211, false, false, PreambleExpired);
assert(t.spans[1].header_us == NoTime && t.spans[1].end_us == 210);
assert(t.spans[1].reason == PreambleExpired);
t.irq(&radio, Base + 220, Base + 221, 0, 2);
i = t.receiveRead(&radio, Base + 230);
assert(t.rx[i].span_index == NoIndex); // no stale abandoned-span link
t.receiveEntry(&radio, Base + 231, Base + 235, -1);
t.receiveFinish(&radio, i, Base + 240, 0, 0, false);
assert((t.rx[i].flags & (Invalid | RearmFailed | ReadError)) == (Invalid | RearmFailed | ReadError));
}
static void transmitBounds() {
Trace t; begin(t);
t.transmitPrepare(&radio, Base + 10, 0x1234, 101, 397824);
t.transmitLaunch(&radio, Base + 20, Base + 30, Base + 30, 0);
t.dio(&radio, Base + 400000, Base + 400001, false);
t.irq(&radio, Base + 400010, Base + 400020, 0, 0);
t.irq(&radio, Base + 400030, Base + 400040, 0, 1);
t.dio(&radio, Base + 400050, Base + 400051, false); // cannot move a latched bound
t.irq(&radio, Base + 400060, Base + 400070, 0, 1); // retain first positive
t.transmitFinish(&radio, Base + 400080, true);
auto& r = t.tx[0];
assert(t.tx_count == 1 && !r.flags && r.hash64 == 0x1234);
assert(r.done_lo_us == 400010 && r.done_hi_us == 400040);
assert(r.launch_lo_us == 20 && r.launch_hi_us == 30 && r.busy_low_us == 30);
assert(r.toa_us == 397824 && !r.spi_errors);
t.transmitFinish(&radio, Base + 400090, false); // normal finish cleanup is inert
assert(!r.flags);
t.transmitPrepare(&radio, Base + 500000, 0x5678, 101, 652288);
t.transmitLaunch(&radio, Base + 500001, Base + 500002, Base + 500003, 0);
t.irq(&radio, Base + 500010, Base + 500020, 0, 1);
t.transmitFinish(&radio, Base + 500030, true);
assert(t.tx[1].flags == MissingBound); // old TX cannot donate its lower bound
}
static void spiFailure() {
Trace t; begin(t);
t.transmitPrepare(&radio, Base + 10, 1, 101, 100);
t.transmitLaunch(&radio, Base + 11, Base + 12, Base + 13, 0);
t.irq(&radio, Base + 20, Base + 21, -707, 0);
t.irq(&radio, Base + 30, Base + 31, 0, 1);
t.transmitFinish(&radio, Base + 40, true);
assert(t.spi_errors == 1 && t.invalidations == 1);
assert((t.tx[0].flags & (Invalid | SpiError | MissingBound)) == (Invalid | SpiError | MissingBound));
assert(t.tx[0].spi_errors == 1);
Trace r; begin(r);
r.receiveEntry(&radio, Base, Base + 1, 0);
r.activity(&radio, Base + 10, Base + 11, true, false, None);
r.irq(&radio, Base + 20, Base + 21, -707, 0);
assert(r.spans[0].reason == SpiFailure && r.spans[0].end_us == 20);
r.irq(&radio, Base + 30, Base + 31, 0, 2);
auto i = r.receiveRead(&radio, Base + 40);
assert(r.rx[i].flags & MissingBound);
}
static void interruptionsAndFreeze() {
Trace t; begin(t);
t.activity(&radio, Base + 10, Base + 11, true, true, None);
t.operation(&radio, Base + 20, Reconfigure);
assert(t.spans[0].end_us == 20 && t.spans[0].reason == Reconfigure);
t.transmitPrepare(&radio, Base + 30, 1, 101, 100);
t.stop(Base + 40);
assert(t.state == State::Frozen && (t.flags & Invalid));
assert((t.tx[0].flags & (Invalid | Clipped | NotConfirmed)) == (Invalid | Clipped | NotConfirmed));
const auto frozen = t;
t.activity(&radio, Base + 50, Base + 51, true, false, None);
t.irq(&radio, Base + 60, Base + 61, 0, 1);
t.transmitFinish(&radio, Base + 70, true);
assert(!std::memcmp(&frozen, &t, sizeof(t)));
Trace r; begin(r);
r.receiveEntry(&radio, Base, Base + 1, 0);
r.irq(&radio, Base + 10, Base + 11, 0, 2);
r.receiveRead(&radio, Base + 20);
r.tick(r.end_us);
assert(r.state == State::Frozen && (r.rx[0].flags & Clipped));
}
static void overflowAndOwnership() {
Trace t; begin(t);
for (size_t i = 0; i < SpanCapacity + 2; ++i) {
t.activity(&radio, Base + i * 10 + 1, Base + i * 10 + 2, true, false, None);
t.activity(&radio, Base + i * 10 + 3, Base + i * 10 + 4, false, false, HeaderError);
}
assert(t.span_count == SpanCapacity && t.span_dropped == 2);
assert(t.spans[0].begin_us == 2 && (t.flags & Invalid));
Trace r; begin(r);
for (size_t i = 0; i < RxCapacity + 1; ++i) {
const auto record = r.receiveRead(&radio, Base + i * 10 + 1);
r.receiveEntry(&radio, Base + i * 10 + 2, Base + i * 10 + 3, 0);
r.receiveFinish(&radio, record, Base + i * 10 + 4, i, 101, true);
}
assert(r.rx_count == RxCapacity && r.rx_dropped == 1);
Trace s; begin(s);
for (size_t i = 0; i < TxCapacity + 1; ++i) {
s.transmitPrepare(&radio, Base + i * 10 + 1, i, 101, 100);
s.transmitFinish(&radio, Base + i * 10 + 2, false);
}
assert(s.tx_count == TxCapacity && s.tx_dropped == 1);
int other;
s.context(&other, 1, 9);
assert(s.context_errors == 1);
const auto count = s.tx_count;
s.transmitPrepare(&other, Base + 10000, 0, 101, 100);
assert(s.tx_count == count);
}
static void scanTiming() {
Trace t; begin(t);
t.scan(&radio, Base + 10, Base, 100);
t.scan(&radio, Base + 1000, Base, 100, false);
t.scan(&radio, Base + 2010, Base + 2000, 100);
assert(t.max_scan_gap_us == 2000 && t.max_visit_overdue_us == 900);
assert(t.buckets[0].max_scan_gap_us == 2000);
assert(t.buckets[0].max_scan_gap_end_us == 2010);
assert(t.buckets[0].max_visit_overdue_end_us == 1000);
t.scan(&radio, Base + BucketWidthUs + 10, Base + BucketWidthUs, 100);
assert(t.bucket_count == 2 && t.buckets[1].start_us == BucketWidthUs);
assert(t.buckets[0].max_scan_gap_end_us == 2010);
// Expiry is exclusive, so the final valid bucket is 59 for 180 seconds.
t.scan(&radio, Base + uint64_t(MaxCaptureMs) * 1000 - 1, 0, 0);
assert(t.bucket_count == 60 && !(t.flags & Invalid));
}
static void epochsAndMissingLaunch() {
Trace t; begin(t);
t.transmitPrepare(&radio, Base + 10, 1, 101, 100);
t.dio(&radio, Base + 11, Base + 12, false);
t.irq(&radio, Base + 13, Base + 14, 0, 1); // previous epoch, before SetTx
t.transmitLaunchBegin(&radio, Base + 20);
t.transmitLaunch(&radio, Base + 20, Base + 21, Base + 22, 0);
t.irq(&radio, Base + 120, Base + 121, 0, 1);
t.transmitFinish(&radio, Base + 122, true);
assert(t.tx[0].done_hi_us == 121 && t.tx[0].flags == MissingBound);
t.transmitPrepare(&radio, Base + 200, 2, 101, 100);
t.irq(&radio, Base + 201, Base + 202, 0, 1);
t.transmitFinish(&radio, Base + 203, true);
assert((t.tx[1].flags & (Invalid | MissingBound | NotConfirmed)) == (Invalid | MissingBound | NotConfirmed));
Trace r;r.context(&radio,0,1);
assert(r.arm(Base,10,1000));
r.receiveEntry(&radio,Base+100,Base+101,0); // establish mode while armed
r.irq(&radio,Base+10010,Base+10011,0,0);
r.irq(&radio,Base+10020,Base+10021,0,2);
auto i=r.receiveRead(&radio,Base+10030);
assert(!(r.rx[i].flags&MissingBound));
r.receiveEntry(&radio,Base+10031,Base+10032,0);
r.receiveFinish(&radio,i,Base+10033,1,101,true);
r.stop(Base+10040);
assert(r.arm(Base+20000,0,1000)); // stale mode/bounds from old capture cannot survive
r.irq(&radio,Base+20010,Base+20011,0,0);
r.irq(&radio,Base+20020,Base+20021,0,2);
i=r.receiveRead(&radio,Base+20030);
assert(r.rx[i].flags&MissingBound);
Trace receiver;begin(receiver);
receiver.context(&radio,0,7);
receiver.context(&radio,0,8);
assert((receiver.flags&(Invalid|Interrupted))==(Invalid|Interrupted));
}
int main(int argc, char** argv) {
assert(argc == 2);
if (!std::strcmp(argv[1], "lifetime")) lifetime();
else if (!std::strcmp(argv[1], "holds")) holdsAndReceipts();
else if (!std::strcmp(argv[1], "tx")) transmitBounds();
else if (!std::strcmp(argv[1], "spi")) spiFailure();
else if (!std::strcmp(argv[1], "freeze")) interruptionsAndFreeze();
else if (!std::strcmp(argv[1], "overflow")) overflowAndOwnership();
else if (!std::strcmp(argv[1], "scan")) scanTiming();
else if (!std::strcmp(argv[1], "epochs")) epochsAndMissingLaunch();
else assert(false);
}
+271
View File
@@ -0,0 +1,271 @@
"""Execute bounded trace state and the real checked IRQ/activity hooks."""
from pathlib import Path
import os
import subprocess
import tempfile
import unittest
from cpp_source import body
ROOT = Path(__file__).resolve().parents[1]
def compile_cpp(folder, source, name="trace", flags=()):
cpp, binary = Path(folder) / (name + ".cpp"), Path(folder) / name
cpp.write_text(source, encoding="ascii")
command = [os.environ.get("CXX", "g++"), "-std=c++17", "-O1", "-g",
"-Wall", "-Wextra", "-Werror", "-fsanitize=address,undefined",
"-fno-sanitize-recover=all", "-fno-omit-frame-pointer", "-no-pie",
"-I", str(ROOT / "src"), *flags, str(cpp), "-o", str(binary)]
result = subprocess.run(command, capture_output=True, text=True)
if result.returncode:
raise AssertionError(result.stdout + result.stderr)
return binary
class RadioTraceTests(unittest.TestCase):
@classmethod
def setUpClass(cls):
cls.folder = tempfile.TemporaryDirectory(prefix="mc-radio-trace-")
cls.binary = compile_cpp(cls.folder.name,
(ROOT / "test/fixtures/esp32_radio_trace.cpp").read_text(),
flags=("-DESP32_PLATFORM", "-DMESH_HIL_RADIO_TRACE=1"))
@classmethod
def tearDownClass(cls):
cls.folder.cleanup()
def run_case(self, name):
result = subprocess.run([str(self.binary), name], capture_output=True, text=True)
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
def test_capture_lifetime_and_rearm(self): self.run_case("lifetime")
def test_conservative_holds_receipts_and_blackout(self): self.run_case("holds")
def test_checked_tx_event_bounds_and_first_positive(self): self.run_case("tx")
def test_failed_spi_zero_is_never_a_lower_bound(self): self.run_case("spi")
def test_clipping_and_frozen_immutability(self): self.run_case("freeze")
def test_overflow_never_overwrites_and_wrong_phy_fails_closed(self): self.run_case("overflow")
def test_scan_gap_has_an_exact_interval_and_separate_deadline(self): self.run_case("scan")
def test_capture_and_launch_epochs_cannot_reuse_old_bounds(self): self.run_case("epochs")
def test_disabled_object_has_no_buffer_clock_hash_or_sdk_dependencies(self):
# This compiles without ESP32 SDK include paths. Both absence of the
# flag and an explicit zero must remove all implementation/dependencies.
with tempfile.TemporaryDirectory(prefix="mc-radio-trace-off-") as folder:
for index, flags in enumerate(((), ("-DESP32_PLATFORM",),
("-DESP32_PLATFORM", "-DMESH_HIL_RADIO_TRACE=0"),
("-DNRF52_PLATFORM", "-DMESH_HIL_RADIO_TRACE=1"))):
obj = Path(folder) / (str(index) + ".o")
result = subprocess.run([os.environ.get("CXX", "g++"), "-std=c++11",
*flags, "-c", str(ROOT / "src/helpers/radiolib/ESP32RadioTrace.cpp"),
"-o", str(obj)], capture_output=True, text=True)
self.assertEqual(result.returncode, 0, result.stderr)
symbols = subprocess.check_output(["nm", "-C", str(obj)], text=True)
self.assertNotIn("radiotrace", symbols)
self.assertNotIn("esp_timer", symbols)
self.assertNotIn("sha256", symbols)
self.assertNotIn(" U ", symbols)
def test_tx_only_mode_has_no_receiver_capture_and_keeps_the_ram_reserve(self):
source = r'''
#include <cassert>
#include <helpers/radiolib/ESP32RadioTrace.h>
using namespace mesh::radiotrace;
int main() {
static_assert(SpanCapacity == 0 && RxCapacity == 0 && BucketCapacity == 0, "sender storage");
static_assert(sizeof(Trace) <= 2048, "sender reserve");
Trace t;int radio=0;t.context(&radio,0,1);assert(t.arm(100,0,1000));
t.activity(&radio,110,111,true,false,None);
assert(t.receiveRead(&radio,120)==NoIndex);
t.scan(&radio,130,100,20);
assert(!t.span_count && !t.rx_count && !t.bucket_count);
for(unsigned i=0;i<40;++i) {
t.context(&radio,0,i+2); // physical primary is retuned to each planned tuple
t.transmitPrepare(&radio,200+i*10,i,101,100);
t.transmitLaunch(&radio,200+i*10,200+i*10,200+i*10,0);
t.dio(&radio,201+i*10,202+i*10,false);
t.irq(&radio,203+i*10,204+i*10,0,1);
t.transmitFinish(&radio,205+i*10,true);
assert(!t.tx[i].flags);
}
assert(t.tx_count==40 && !t.tx_dropped && !t.flags);
Trace interrupted;interrupted.context(&radio,0,1);assert(interrupted.arm(100,0,1000));
interrupted.transmitPrepare(&radio,200,1,101,100);
interrupted.transmitLaunch(&radio,200,201,202,0);
interrupted.dio(&radio,203,204,false);
interrupted.context(&radio,0,2); // a live TX may never survive a tuple replacement
interrupted.irq(&radio,205,206,0,1);
interrupted.transmitFinish(&radio,207,true);
assert((interrupted.tx[0].flags&(Invalid|Interrupted|MissingBound))==(Invalid|Interrupted|MissingBound));
}
'''
with tempfile.TemporaryDirectory(prefix="mc-radio-trace-tx-") as folder:
binary = compile_cpp(folder, source, flags=("-DESP32_PLATFORM",
"-DMESH_HIL_RADIO_TRACE=1", "-DMESH_HIL_RADIO_TRACE_TX_ONLY=1"))
result = subprocess.run([str(binary)], capture_output=True, text=True)
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
def test_actual_irq_and_activity_hooks_preserve_transactions_and_returns(self):
chip = (ROOT / "src/helpers/radiolib/CustomSX1262.h").read_text()
irq = body(chip, "uint32_t getIrqFlags() override")
activity = body(chip, "bool isReceiving()")
source = r'''
#include <cassert>
#include <cstdint>
#include <helpers/radiolib/ESP32RadioTrace.h>
#define MESH_DEBUG_PRINTLN(...) ((void)0)
#define RADIOLIB_SX126X_CMD_GET_IRQ_STATUS 0x12
#define RADIOLIB_SX126X_IRQ_PREAMBLE_DETECTED 4U
#define RADIOLIB_SX126X_IRQ_HEADER_VALID 16U
#define RADIOLIB_SX126X_IRQ_HEADER_ERR 32U
#define RADIOLIB_SX126X_IRQ_SYNC_WORD_VALID 8U
static uint64_t clock_us=1000000;
static unsigned clock_reads=0;
uint32_t millis(){return clock_us/1000;}
namespace mesh {namespace radiotrace {
Trace& trace(){static Trace t;return t;}
uint64_t nowUs(){++clock_reads;return clock_us;}
}}
struct Module {
uint32_t irq=0;unsigned reads=0,clears=0;int16_t status=0;
int16_t SPIreadStream(uint8_t command,uint8_t* data,size_t length) {
assert(command==0x12 && length==2);++reads;
// A failing transfer may have returned either zero or partial bytes.
data[0]=uint8_t(irq>>8);data[1]=uint8_t(irq);return status;
}
};
struct PhysicalLayer {virtual uint32_t getIrqFlags()=0;virtual ~PhysicalLayer()=default;};
struct Chip : PhysicalLayer {
Module module;Module* mod=&module;
uint32_t _activityAt=0,_preambleMillis=99,_maxPayloadMillis=1456;
bool _headerSeen=false,busy=false;
bool isChipBusy(){return busy;}
void clearIrqFlags(uint32_t bits){++module.clears;module.irq&=~bits;}
@IRQ@
@ACTIVITY@
};
int main() {
using namespace mesh::radiotrace;
Chip c;trace().context(static_cast<PhysicalLayer*>(&c),0,1);
c.module.irq=4;assert(c.isReceiving());
c.module.irq=0;assert(!c.isReceiving());
assert(c.module.reads==2 && !clock_reads); // runtime-off evaluates no timer args
assert(trace().arm(clock_us,0,10000));
clock_us+=1000;c.module.irq=4;assert(c.isReceiving());
assert(trace().span_count==1);
clock_us+=99000;assert(c.isReceiving());
clock_us+=1000;assert(!c.isReceiving());
assert(trace().spans[0].reason==PreambleExpired);
assert(c.module.reads==5 && c.module.clears==1);
clock_us+=1000;c.module.irq=4;assert(c.isReceiving());
clock_us+=1000;c.module.irq=4|16;assert(c.isReceiving());
clock_us+=1457000;assert(!c.isReceiving());
assert(trace().spans[1].reason==PayloadExpired && c.module.clears==2);
clock_us+=1000;c.module.irq=4;assert(c.isReceiving());
clock_us+=1000;c.module.irq=4|32;assert(!c.isReceiving());
assert(trace().spans[2].reason==HeaderError && c.module.clears==3);
// Exactly one read occurs for the checked override, including failures,
// and its returned bytes remain the same as the legacy implementation.
auto before=c.module.reads;c.module.status=-707;c.module.irq=0x1234;
assert(c.getIrqFlags()==0x1234 && c.module.reads==before+1);
assert(trace().spi_errors==1 && (trace().flags&Invalid));
}
'''.replace("@IRQ@", irq).replace("@ACTIVITY@", activity)
with tempfile.TemporaryDirectory(prefix="mc-radio-trace-hooks-") as folder:
binary = compile_cpp(folder, source, flags=("-DESP32_PLATFORM", "-DMESH_HIL_RADIO_TRACE=1"))
result = subprocess.run([str(binary)], capture_output=True, text=True)
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
def test_actual_launch_success_failure_timeout_and_compiled_out_side_effects(self):
chip = (ROOT / "src/helpers/radiolib/CustomSX1262.h").read_text()
launch = body(chip, "int16_t launchMode() override")
source = r'''
#include <cassert>
#include <cstdint>
#include <helpers/radiolib/ESP32RadioTrace.h>
#define RADIOLIB_RADIO_MODE_TX 3
#define RADIOLIB_RADIO_MODE_NONE 0
#define RADIOLIB_SX126X_TX_TIMEOUT_NONE 0
#define RADIOLIB_ERR_NONE 0
#define RADIOLIB_ERR_SPI_CMD_TIMEOUT -707
#define SX126X_TX_BUSY_TIMEOUT_MS 3
using RadioLibTime_t=uint32_t;
static uint64_t clock_us=1000000;
static unsigned clock_reads=0;
#if MESH_RADIO_TRACE_ENABLED
namespace mesh {namespace radiotrace {
Trace& trace(){static Trace t;return t;}
uint64_t nowUs(){++clock_reads;return clock_us;}
}}
#endif
struct Hal {
unsigned yields=0;
uint32_t millis(){return clock_us/1000;}
void yield(){++yields;clock_us+=1000;}
};
struct Module {
Hal hal_value;Hal* hal=&hal_value;unsigned rf_calls=0;
void setRfSwitchState(int){++rf_calls;}
};
struct PhysicalLayer {virtual int16_t launchMode()=0;virtual ~PhysicalLayer()=default;};
struct SX1262 : PhysicalLayer {
unsigned base_calls=0;
int16_t launchMode()override{++base_calls;return 91;}
};
struct Chip : SX1262 {
Module module;Module* mod=&module;
int stagedMode=3,txMode=2;int16_t set_result=0;
unsigned set_calls=0,busy_reads=0,busy_loops=2;
int16_t setTx(int){++set_calls;clock_us+=37;return set_result;}
bool isChipBusy(){return ++busy_reads<=busy_loops;}
@LAUNCH@
};
int main() {
Chip off;assert(off.launchMode()==0);
assert(off.set_calls==1 && off.busy_reads==3 && off.module.rf_calls==1);
assert(off.module.hal->yields==2 && off.stagedMode==0 && !clock_reads);
Chip base;base.stagedMode=1;assert(base.launchMode()==91);
assert(base.base_calls==1 && !base.set_calls && !clock_reads);
#if MESH_RADIO_TRACE_ENABLED
using namespace mesh::radiotrace;
for (int test=0;test<3;++test) {
Chip c;if(test==1)c.set_result=-20;if(test==2)c.busy_loops=100;
trace().context(static_cast<PhysicalLayer*>(&c),0,1);
assert(trace().arm(clock_us,0,1000));
trace().transmitPrepare(static_cast<PhysicalLayer*>(&c),clock_us,1,101,100);
const auto expected=clock_us;
const int16_t result=c.launchMode();
auto& r=trace().tx[0];
assert(r.launch_lo_us==expected-trace().epoch_us && r.launch_hi_us-r.launch_lo_us==37);
assert(c.set_calls==1 && c.module.rf_calls==1 && c.stagedMode==0);
if(test==0) {
assert(result==0 && r.busy_low_us-r.launch_lo_us==2037);
assert(c.busy_reads==3 && c.module.hal->yields==2);
trace().dio(static_cast<PhysicalLayer*>(&c),clock_us+1,clock_us+2,false);
trace().irq(static_cast<PhysicalLayer*>(&c),clock_us+3,clock_us+4,0,1);
trace().transmitFinish(static_cast<PhysicalLayer*>(&c),clock_us+5,true);
assert(!r.flags);
} else {
assert(result==(test==1?-20:-707) && r.busy_low_us==NoTime);
assert(c.busy_reads==unsigned(test==1?0:3));
assert(c.module.hal->yields==unsigned(test==1?0:3));
trace().transmitFinish(static_cast<PhysicalLayer*>(&c),clock_us+5,false);
assert((r.flags&(Invalid|Interrupted|MissingBound))==(Invalid|Interrupted|MissingBound));
}
trace().stop(clock_us+6);clock_us+=10000;
}
#endif
}
'''.replace("@LAUNCH@", launch)
with tempfile.TemporaryDirectory(prefix="mc-radio-trace-launch-") as folder:
for value in (0, 1):
binary = compile_cpp(folder, source, name="launch" + str(value),
flags=("-DESP32_PLATFORM", "-DMESH_HIL_RADIO_TRACE=" + str(value)))
result = subprocess.run([str(binary)], capture_output=True, text=True)
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
if value == 0:
symbols = subprocess.check_output(["nm", "-C", str(binary)], text=True)
self.assertNotIn("radiotrace", symbols)
if __name__ == "__main__": unittest.main()
+174
View File
@@ -0,0 +1,174 @@
"""Execute the opt-in local radio trace CLI without radio, USB or PlatformIO."""
from pathlib import Path
import os
import re
import subprocess
import tempfile
import unittest
ROOT = Path(__file__).resolve().parents[1]
HEADER = "helpers/radiolib/ESP32RadioTraceCLI.h"
HARNESS = r'''
#include <cassert>
#include <cstdio>
#include <cstring>
#include <limits>
#include <helpers/radiolib/ESP32RadioTraceCLI.h>
static uint64_t clock_us=1234567890123ULL;
namespace mesh { namespace radiotrace {
Trace storage;
Trace& trace() { return storage; }
uint64_t nowUs() { return clock_us; }
} }
using namespace mesh::radiotrace;
static char reply[160];
[[maybe_unused]] static const char* command(const char* value) {
std::memset(reply,'?',sizeof(reply));
assert(handleTraceCommand(value,reply,sizeof(reply)));
assert(std::memchr(reply,0,sizeof(reply)));
return reply;
}
[[maybe_unused]] static void error(const char* value) {
assert(!std::strncmp(command(value),"Error:",6));
}
'''
class RadioTraceCliTests(unittest.TestCase):
def native(self, body, flags=("-DESP32_PLATFORM=1", "-DMESH_HIL_RADIO_TRACE=1"), harness=HARNESS):
with tempfile.TemporaryDirectory(prefix="radio-trace-cli-") as folder:
root = Path(folder)
(root / "esp_system.h").write_text(
"#include <stdint.h>\ninline uint32_t esp_random() { return 0x12345678; }\n", encoding="ascii")
cpp, binary = root / "test.cpp", root / "test"
cpp.write_text(harness + body, encoding="ascii")
built = subprocess.run([os.environ.get("CXX", "g++"), "-std=c++17", "-Wall", "-Wextra", "-Werror",
"-fsanitize=address,undefined", "-fno-sanitize-recover=all", "-fno-pie", "-no-pie",
*flags, "-I", str(root), "-I", str(ROOT / "src"), str(cpp), "-o", str(binary)],
capture_output=True, text=True, timeout=60)
self.assertEqual(built.returncode, 0, built.stdout + built.stderr)
ran = subprocess.run([str(binary)], capture_output=True, text=True, timeout=20)
self.assertEqual(ran.returncode, 0, ran.stdout + ran.stderr)
return subprocess.check_output(["nm", "-C", str(binary)], text=True)
def test_clock_nonce_boot_identity_and_strict_arm_lifecycle(self):
self.native(r'''
int main() {
assert(!std::strcmp(command("get radio.trace clock aBCd0123456789ef"),
"> rt=1 boot=1234567812345678 session=0 nonce=aBCd0123456789ef us=1234567890123"));
for(const char* invalid:{"", "-1", "0123456789abcde", "0123456789abcdef0", "0123456789abcdeg", "0123456789abcdef "}) {
char text[96];std::snprintf(text,sizeof(text),"get radio.trace clock %s",invalid);error(text);
}
assert(!std::strncmp(command("set radio.trace arm 50 1000"),"OK",2));
assert(storage.session==1 && storage.state==State::Armed);
assert(storage.epoch_us==clock_us+50000 && storage.end_us==clock_us+1050000);
error("set radio.trace arm 0 100");assert(storage.session==1);
clock_us+=50000;command("get radio.trace");assert(storage.state==State::Capturing);
error("get radio.trace tx 0");
command("set radio.trace stop");assert(storage.state==State::Frozen);
assert(!std::strncmp(command("set radio.trace arm 180000 180000"),"OK",2));
assert(storage.session==2);
clock_us=storage.end_us;command("get radio.trace");assert(storage.state==State::Frozen);
}
''', harness="#include <initializer_list>\n" + HARNESS)
def test_malformed_commands_do_not_arm_or_claim_unrelated_names(self):
self.native(r'''
int main() {
for(const char* text:{"set radio.trace", "set radio.trace arm", "set radio.trace arm -1 1",
"set radio.trace arm 0 0", "set radio.trace arm 180001 1", "set radio.trace arm 0 180001",
"set radio.trace arm 4294967296 1", "set radio.trace arm 1 4294967296",
"set radio.trace arm 1", "set radio.trace arm 1 1 x", "set radio.trace arm 1 1",
"set radio.trace arm 1 1", "get radio.trace rx -1", "get radio.trace rx 4294967296",
"get radio.trace rx 0 trailing", "get radio.trace tx", "get radio.trace stats "}) {
error(text);assert(storage.session==0 && storage.state==State::Off);
}
for(const char* text:{"get radio.tracex", "set radio.traceX", "get radio", "trace"})
assert(!handleTraceCommand(text,reply,sizeof(reply)));
assert(!handleTraceCommand(nullptr,reply,sizeof(reply)));
assert(!handleTraceCommand("get radio.trace",nullptr,sizeof(reply)));
assert(!handleTraceCommand("get radio.trace",reply,0));
}
''', harness="#include <initializer_list>\n" + HARNESS)
def test_frozen_record_schema_bounds_and_frame_capacity(self):
self.native(r'''
int main() {
storage.state=State::Frozen;storage.session=UINT32_MAX;
storage.epoch_us=storage.end_us=UINT64_MAX;storage.flags=UINT32_MAX;
assert(std::strlen(command("get radio.trace"))<sizeof(reply)-1);
assert(!std::strcmp(command("get radio.trace marker"),"> MCRFTRACE1:RX192:TX40"));
storage.span_count=storage.rx_count=storage.tx_count=storage.bucket_count=1;
storage.spans[0]={1,UINT32_MAX,3,UINT16_MAX,1,10};
storage.rx[0]={1,2,3,4,0xabcdef0123456789ULL,101,UINT16_MAX,1,4,0};
storage.tx[0]={0xabcdef0123456789ULL,1,2,3,4,5,652288,101,1,4,9};
storage.buckets[0]={3000000,12,34,56,78};
assert(!std::strcmp(command("get radio.trace span 0"),"> span=0,1,4294967295,3,65535,1,10"));
assert(!std::strcmp(command("get radio.trace rx 0"),"> rx=0,1,2,3,4,abcdef0123456789,101,65535,1,4"));
assert(!std::strcmp(command("get radio.trace tx 0"),"> tx=0,abcdef0123456789,1,2,3,4,5,652288,101,1,4,9"));
assert(!std::strcmp(command("get radio.trace bucket 0"),"> bucket=0,3000000,12,34,56,78"));
for(const char* kind:{"span","rx","tx","bucket"}) {
char text[64];std::snprintf(text,sizeof(text),"get radio.trace %s 1",kind);error(text);
}
std::memset(storage.tx,0xff,sizeof(storage.tx));command("get radio.trace tx 0");
assert(std::strlen(reply)<sizeof(reply)-1);
storage.span_count=storage.rx_count=storage.tx_count=storage.bucket_count=UINT32_MAX;
storage.span_dropped=storage.rx_dropped=storage.tx_dropped=UINT32_MAX;
storage.max_scan_gap_us=storage.max_visit_overdue_us=storage.max_blackout_us=UINT32_MAX;
storage.spi_errors=storage.invalidations=storage.context_errors=UINT32_MAX;
command("get radio.trace stats");assert(std::strlen(reply)<sizeof(reply)-1);
command("get radio.trace gaps");assert(std::strlen(reply)<sizeof(reply)-1);
error("get radio.trace tx 40");error("get radio.trace span 192");
char tiny[2]={'?', '?'};assert(handleTraceCommand("get radio.trace",tiny,sizeof(tiny)) && tiny[1]==0);
}
''', harness="#include <initializer_list>\n" + HARNESS)
def test_tx_only_has_no_receive_records_and_correct_marker(self):
self.native(r'''
int main() {
assert(SpanCapacity==0 && RxCapacity==0 && BucketCapacity==0 && TxCapacity==40);
assert(!std::strcmp(command("get radio.trace marker"),"> MCRFTRACE1:TXONLY40"));
storage.state=State::Frozen;storage.rx_count=storage.span_count=storage.bucket_count=1;
error("get radio.trace rx 0");error("get radio.trace span 0");error("get radio.trace bucket 0");
}
''', flags=("-DESP32_PLATFORM=1", "-DMESH_HIL_RADIO_TRACE=1", "-DMESH_HIL_RADIO_TRACE_TX_ONLY=1"))
def test_disabled_header_has_no_trace_state_or_formatter(self):
for flags in ((), ("-DESP32_PLATFORM=1", "-DMESH_HIL_RADIO_TRACE=0")):
symbols = self.native("int main() {return 0;}\n", flags=flags,
harness=f"#include <{HEADER}>\n")
self.assertNotIn("radiotrace", symbols)
def test_actual_direct_dispatch_excludes_lora_admin(self):
source = (ROOT / "examples/companion_radio/MyMesh.cpp").read_text()
start = source.index("bool MyMesh::handleDirectCommand(")
direct = source[start:source.index("#if MESH_ENABLE_ONE_KEY_DM", start)]
hook = re.search(r"#if defined\(ESP32_PLATFORM\) && defined\(MESH_HIL_RADIO_TRACE\) && MESH_HIL_RADIO_TRACE\n"
r" if \(mesh::radiotrace::handleTraceCommand\(command, reply, reply_size\)\) return true;\n#endif", direct)
self.assertIsNotNone(hook)
guard = re.search(r"if \(sender_timestamp == 0 && handleDirectCommand\([^\n]+", source)
self.assertIsNotNone(guard)
self.native(r'''
struct MyMesh {
bool handleDirectCommand(const char* command,char* reply,size_t reply_size) {
@HOOK@
return false;
}
bool handleCommand(const char* command,uint32_t sender_timestamp,char* reply) {
const size_t reply_capacity=160;
@GUARD@
return false;
}
};
int main() {
MyMesh mesh;
assert(!mesh.handleCommand("set radio.trace arm 0 1000",1,reply));
assert(storage.session==0);
assert(mesh.handleCommand("set radio.trace arm 0 1000",0,reply));
assert(storage.session==1);
}
'''.replace("@HOOK@", hook.group()).replace("@GUARD@", guard.group()))
if __name__ == "__main__":
unittest.main()