mirror of
https://github.com/meshtastic/firmware.git
synced 2026-09-12 22:29:00 -04:00
Serialise AirTime behind a lock, and stop handing out its buckets (#11362)
* Copy airtime reports into a caller buffer instead of exposing the array
airtimeReport() returned a pointer into the rotating bucket arrays, so the
caller held a handle to state that logAirtime() and every accessor mutate
underneath it. Copy into a caller-supplied buffer instead, and report failure
for a null buffer, a count past the log depth, or an unknown report type.
ContentHandler owns its buffer and hoists getPeriodsToLog() out of the three
calls that repeated it.
* Cover the AirTime report API and log-dispatch contract
Half of AirTime's surface had no tests: which store each report type feeds,
what airtimeReport() does when misused, how the first sync seeds itself, and
whether calling several entry points in one interval compounds the rotation.
Eighteen tests, asserted through the public API rather than the public bucket
arrays - those arrays are meant to become private, and a test that reads them
would have to be rewritten rather than pinning a contract.
Two of them state a convention that was never written down: the report arrays
are shift-ordered with slot 0 newest, and slot 0 covers only the time since the
last rotation. channelUtilization and utilizationTX use the opposite convention
- a modular ring indexed by uptime phase - and reading one as if it were the
other is a defect that has already happened once.
* Characterise AirTime window decay, TX gates, and sleep behaviour
Thirty-three tests in three kinds. Invariants must hold forever; boundaries pin
off-by-ones a refactor would move; five characterisations encode today's wrong
numbers, each tagged with the phase that will flip it.
Readings are asserted against an event-log oracle - airtime physically on air
inside (now - window, now], computed from a list of completed packets - rather
than against hand-worked constants, so a test states "this matches the
definition" instead of "this looked right when I wrote it".
The characterisations, all measured rather than assumed:
- the window covers (N-1)p + phase but divides by Np, so a steady 10% load
reads 8.33% right after a bucket boundary -> phase 5
- the same load sweeps across bucket phase instead of holding -> phase 5
- the hour window carries the same defect, 10x smaller -> phase 5
- a packet longer than its bucket is credited whole to the bucket
it completed in, so a saturated LONG_SLOW channel reads >100% -> phase 4b
- getSilentMinutes() reads a modular ring as if the index were an
age, so identical airtime gives different answers by phase -> phase 6
Two tests needed correcting during the write, both my expectations rather than
the code: a six-bucket ring sheds whole buckets, so a 30s gap drops three of
five survivors and not "half"; and the oracle sees 59 completions in a 60s
window, not 60, because the one on the lower edge is outside it.
Not written: the planned RX_LOG/RX_ALL_LOG disjointness test. That is a
property of the two radio drivers, which choose one or the other per packet -
it is not observable from AirTime, which records what it is told. The
AirTime-side half is already covered by the routing tests.
* Drop write-only and undefined AirTime members
None of this was reachable:
air_period_tx / air_period_rx file-scope mirrors of airtimes.periodTX/RX,
accumulated, rotated and memset in lockstep
with them but never read out or serialised.
Orphaned when #2552 re-pointed the writes at
bare globals instead of deleting them.
lastUtilPeriod, lastUtilPeriodTX written on every sync, read nowhere
airtimes.lastPeriodIndex written on every rotation, read nowhere
currentPeriodIndex() computes (secs / 3600) % 8 - a modular-ring
index for the one array that is shift-ordered
rather than a ring. Its only two uses were the
dead field above and a log line. It is the
fossil of the same confusion that makes
getSilentMinutes() wrong.
UtilizationPercentTX() declared, never defined
free logAirtime()/airtimeReport() declared, never defined; the latter still
carried the array-returning signature the
previous commit removed, so it actively misled
Also fixes the rotation log line, which read currentPeriodIndex() from inside
the loop although the index is advanced before it - on a multi-hour wake it
printed the same final value once per rotation. It now reports which of the
crossed hours is being rotated.
airtimeRotatePeriod() is kept: it has no caller in the tree either, but unlike
the above it is a defined public method, so out-of-tree callers are plausible.
Measured, not estimated: sizeof(AirTime) 464 -> 456 B, plus 64 B of globals, so
-72 B of static RAM. Padding accounts for the difference from the 66 B the plan
predicted by counting declared bytes.
The whole point of writing the tests first: the suite is green here with zero
test changes.
* Document what the AirTime figures measure and how they are stored
Comments only, but four of the things they replace were false.
The header's example analytics claimed RX_ALL_LOG was "all received lora
packets" and offered "RX_ALL_LOG - RX_LOG = other lora radios". Both radio
drivers pick exactly one of the two per packet, so they are disjoint: RX_ALL_LOG
is airtime we could not parse, the subtraction can go negative, and the total is
TX + RX + RX_ALL. Replaced with the actual contract - four inputs, eight
outputs, the window each spans, and the fact that the three thresholds are
hard-coded members rather than the settings they look like.
Names the two storage conventions on their declarations, because mixing them up
is what makes getSilentMinutes() wrong: channelUtilization and utilizationTX are
modular rings indexed by uptime phase, where the oldest bucket is (current + 1)
% N; airtimes.period* is shift-ordered with slot 0 newest, where the index IS an
age and slot 0 is a partial hour.
Defines the measurement as wall time rather than awake time, and says why: a
sleeping node still hears traffic, and per-node redefinition would make two
broadcast readings incomparable. Records that the 60s figure is published to the
mesh at >= 1h cadence, so what other nodes see is a snapshot - at LONG_FAST and
1% occupancy it reads exactly 0 in about 44% of reports - and that the contention
window it feeds moves in 20-percentage-point steps, so small errors never reach
the backoff.
Finally, states that rotation happens on access rather than on the scheduler
tick, names the test that enforces it, and leaves a TODO pointing at the plan
phases that fix the characterised accuracy defects.
* Serialise AirTime behind a lock proven by a private token
Two mechanisms solving different halves. A lock-free inner core (Windows) holds
all state and all logic; it has no lock and no way to reach one, so nesting is
impossible by construction. A private Held token takes the lock in its own
constructor and is the only thing that can be passed where a core method demands
one, so the lock cannot be forgotten either.
The rule is now uniform with no exceptions to remember: every public method
takes the lock once and delegates. In particular isTxAllowed*() lock like
everything else - before the split they could not, because they called the
public accessors and the lock is not recursive. That asymmetry was the foot-gun
the previous design documented in prose and hoped nobody would trip.
getPeriodsToLog()/getSecondsPerPeriod() still take no lock; they return
compile-time constants and touch no state.
channelUtilization[] and utilizationTX[] were public, so the lock was bypassable
at compile time. They move into the private core. Four test sites reached in;
all four now use logAirtime() plus the virtual clock, and no new test seam was
needed. Nothing in src/ was affected.
The re-entry assert is guarded on PIO_UNIT_TESTING, so it exists in test builds
only. The design sketched #ifdef DEBUG, but nothing in this tree defines DEBUG
or NDEBUG, so either spelling ships the assert to every board - and
nrf52_promicro_diy_tcxo has ~128 bytes of headroom under its 0xEA000 warm-store
cap, which the assert's strings and abort path overrun. It would have worked on
hardware, since the check runs in Held's owner initialiser and so precedes the
blocking take; the objection is that abort()ing a live mesh node is a poor trade
for a bug never seen in the field. Native tests are where it earns its keep
anyway: Portduino compiles Lock::lock() to an empty body, so a nested take there
succeeds silently and nothing else would notice.
Also comments out ScopedBusyAirTime in test_traffic_management. It is inert
twice over: the module holds no reference to airTime at all since hop exhaustion
was shelved, and the fixture never worked anyway - writing the buckets on a
fresh AirTime is undone by the first accessor call, which takes the firstTime
branch and memsets them. It reported 0%, not the 100% it claimed. Left in place,
commented, with both reasons recorded.
Cost on the tightest board in the tree, nrf52_promicro_diy_tcxo: the six phases
together add 96 bytes of flash, leaving it 32 bytes clear of the warm-store
guard. RAM is 72 bytes lower from the dead-state removal. Suite green at 47/47,
with test_airtime unedited apart from the added nesting test.
* Count rotations with the loop variable, not a separate tally
LOG_DEBUG compiles to nothing under DEBUG_MUTE, so the counter's only read
disappeared with it and the tally became write-only. It does not warn today -
this build has -Wunused-but-set-variable on, and it fires for other locals, but
not for one that is only initialised and never read - so it was latent rather
than broken: a stricter flag or -Werror would have failed muted builds only.
Using the loop variable removes the class of problem, since the loop condition
reads it, and drops the elapsedAirtimePeriods-- mutation as a side benefit.
Same iteration count, same output.
Found by compiling nrf52_promicro_diy_tcxo with -D DEBUG_MUTE, which is worth
recording for its own sake: muting logs takes that image from 802 784 to
673 416 bytes, 98.5% to 82.6% of flash. Logging is 16% of the largest nrf52
image, and its 32 bytes of warm-store headroom are a logging-verbosity question
rather than a code-size one.
* Tighten the comments added by this branch
Comment-only: with comments stripped, all five files are byte-identical to the
previous commit.
Removed the references to the planning notes. Those documents are working
material and will go stale; the code should not depend on them. The five
CHARACTERISATION tags now describe the defect they pin and stop there, and the
accuracy TODO names the four defects and points at the tests instead of a plan
file.
Also removed, as noise rather than information:
- comparisons against pre-#11291 behaviour, which nobody reading this needs
- a comment describing the lock restructure as future work, written before it
landed
- speculation ("plausible", "worth pinning so a future...")
- an aside arguing with an arithmetic slip made while writing the test
Kept the mechanical facts that are slow to re-derive: the two storage orderings
and which array uses which, RX_LOG/RX_ALL_LOG disjointness, the locking rule and
the addSpanned() constraint that protects it, why the re-entry assert is
test-only, and the concrete numbers - (N-1)p + phase, 14 164 ms, the 20 pp
contention-window steps.
Net 16 comment lines out of src/, 33 out of test/.
* Gate the AirTime re-entry check on the host, not on testing
PIO_UNIT_TESTING is injected by PlatformIO purely on BUILD_TYPE, with no
platform check, so it is defined on an on-target `pio test` run too. The
check arms before the lock is taken - a nested take blocks forever, so a
later check would never run - which under preemption false-positives on
legitimate contention and races on its own write.
Derive AIRTIME_REENTRY_CHECK once from PIO_UNIT_TESTING && !HAS_FREE_RTOS
and use it at all three sites. Had the three conditions ever diverged, an
on-target test build would fail to compile on a member the header no
longer declares.
* Log AirTime outside the lock it serialises
DEBUG_PORT.log() blocks on a UART write, and `lock` is a plain binary
semaphore with no priority inheritance, so holding it across a log call
lets the main thread stall the radio thread in getTxDelayMsec().
Move logAirtime()'s LOG_DEBUG into the shell, after the Held scope
closes; the shell already has both arguments, so nothing has to be
passed back out of the core. isTxAllowed{ChannelUtil,AirUtil} read into
a local under the lock and warn after it. The log bodies are braced
because LOG_DEBUG compiles away under DEBUG_MUTE and a bare `if (x) ;`
trips -Wempty-body.
Fold the two doubled index calls into `+=` while touching the lines.
* Give each airtime report its own buffer
handleReport() reused one array across the three airtimeReport() calls
and ignored the bool. A failed report would have left the previous
type's data in place and emitted it under the next type's key. Build
each through a lambda whose buffer is zeroed per call, so a failure
emits zeros.
Unreachable today - the count is always PERIODS_TO_LOG and the type is
always valid - but the old shape only read as correct by accident.
* Drop a stray semicolon from the inert-guard comment
* Address external review: name the race, tighten the claims and the tests
The header sold the lock as mechanism without naming a second thread, which
invites the reasonable objection that this is a cooperative OSThread codebase.
There is a real race and it is nRF52-only: NRF52Bluetooth registers its ToRadio
write callback with defer == false, so a phone's packet runs handleToRadio ->
sendToMesh -> Router::send on the Bluefruit BLE task, reading
utilizationTXPercent() and getSilentMinutes() while loopTask may be inside
logAirtime(). ESP32 hands BLE work to the main task and does not have it.
Three claims in the header were wrong or overstated:
- "nesting is impossible by construction" - Windows is a nested class with an
enclosing class's access rights, and `extern AirTime *airTime` is in the
same header, so airTime->anyPublicMethod() from inside it is well-formed
and would hang. Nothing does it; the assert is the backstop. Say that
instead, because the comment below instructs contributors to add helpers
to Windows on the strength of the guarantee.
- "every public method takes the lock exactly once" - two constant accessors
take none and isTxAllowedAirUtil() takes it zero or one times. State the
exceptions where the invariant is stated, not only at the definitions.
- "both radio drivers pick exactly one per packet" - five drop paths log
neither. At most one. Recorded against plan4 rather than fixed here: it
changes a telemetry value.
getPeriodsToLog()/getSecondsPerPeriod() become static constexpr, which removes
them from the locking claim structurally and lets ContentHandler size its
buffer and its count from one constant.
Tests:
- C14's saturated AirTime is installed by a helper and restored in tearDown.
Unity's TEST_ABORT() is longjmp and does not run destructors of automatic
objects, so the scoped guard it replaces would leave airTime dangling into
an abandoned frame on any assertion failure - and the same commit that
added it removed the tearDown reset that did cover that.
- test_getSilentMinutes_counts_minutes_until_enough_ages_out asserted only
`mins <= 60`, which neither return path can violate. The answer is 59.
- test_backwards_uptime_degrades_safely stepped 600s -> 60s, which leaves
elapsedAirtimePeriods at 0, so it never reached the hourly-report branch
its own comment describes. Step by the wrap instead and assert the exact
figures.
- test_airtime leaked EU_868 out of the duty-cycle case into every later one,
and the reentry test's isTxAllowedAirUtil() coverage depended on it.
Restore the region in tearDown and set it explicitly where it is wanted.
- Rename that test to what it can actually check: no single method takes the
lock twice. The calls are sequential, so it cannot catch two methods
nesting.
* trunk: suppress trufflehog/Lob false positives in test_airtime
* Address CodeRabbit review: the rotate trace, the cap warn, the backoff
Four findings from the CodeRabbit pass. Two were introduced by this branch,
one is a real inconsistency it inherited, one is a naming slip.
The rotate trace was the one that mattered. "Log AirTime outside the lock it
serialises" moved the per-packet lines and the two TX-gate warnings out to the
shell, but missed LOG_DEBUG("Rotate airtimes, crossed hour %u") because it does
not sit in the shell at all: it is inside Windows::syncNow(), the lock-free
core, which by construction only ever runs under Held. Nothing at that line
looks like a lock, which is why it survived.
The exposure is smaller than the review suggests - runOnce() syncs at 1 Hz, so
in steady state this is one line an hour, and the PERIODS_TO_LOG - 1 burst
needs an hour of light sleep with no intervening sync - but a UART write under
a plain binary semaphore with no priority inheritance is exactly what the
comment above logAirtime() says this code does not do. syncNow() now
accumulates crossings in rotationsPendingLog and runOnce() drains it inside the
Held scope, then logs after release. Any caller can cross an hour; only that
thread reports it, so a crossing raised elsewhere is traced at most one tick
late. The `if (rotations > 0)` guard keeps the drained value read under
DEBUG_MUTE, where LOG_DEBUG expands to nothing - the write-only tally that
"Count rotations with the loop variable" removed.
addFromContact()'s favorite fallback stamped silently when the protected cap
refused it. The stamp is new on this branch; the two sibling refusals (ignore,
verify) both emit PROTECTED_CAP_WARN_FMT, so the operator lost the only signal
that the cap was hit on the one path that has a fallback.
lfs_assert() mixed clocks: Throttle read Time::getMillis(), the remainder was
computed from a second, bare millis(). The review's stated failure mode - a
native test overriding the clock - cannot happen, since the hook is behind
PIO_UNIT_TESTING and this file is nRF52-only. The real defect is the second
read: a tick landing on the 20-minute boundary between the check and the
subtraction underflows the remainder into delay(~50 days), on a device that has
just found its flash corrupt. One read, clamped, and preFSBegin() stores from
the same clock.
The eviction test is renamed to
test_eviction_prefersCurrentBootStampOverPost2038Epoch. The finding is right
that it was snake_case, but the suggested testEvictionPrefers... does not match
this file either, which is test_<area>_<camelCase> throughout.
Not taken, both pre-existing and out of scope for a rollover branch:
- t5s3_epaper's touchResumeAtMs/suppressFromMs read an active suppression as
inactive if the wake lands in the 1 ms where millis() is 0. Consequence is
one skipped 150 ms touch-settle window per 49.7-day wrap.
- NRF52Bluetooth::onPairingPasskey() busy-waits 30 s in a BLE callback. Worth
saying plainly that this branch makes it more visible: the old
`millis() < start_time + 30000` overflowed at the wrap and cut the wait
short, so the correct Throttle form is what lets it run the full 30 s.
Reworking it into an OSThread is its own change.
Native suite GREEN, 48/48, 672 cases.
This commit is contained in:
10 files changed
+1496
-186
No files matched your search
@@ -158,6 +158,7 @@ lint:
|
||||
# 32-bit rollover.
|
||||
- linters: [trufflehog]
|
||||
paths:
|
||||
- test/test_airtime/test_main.cpp
|
||||
- test/test_throttle/test_main.cpp
|
||||
- test/test_uptime_clock/test_main.cpp
|
||||
runtimes:
|
||||
|
||||
+166
-99
@@ -2,62 +2,65 @@
|
||||
#include "NodeDB.h"
|
||||
#include "UptimeClock.h"
|
||||
#include "configuration.h"
|
||||
#include <assert.h>
|
||||
#include <string.h>
|
||||
|
||||
AirTime *airTime = NULL;
|
||||
|
||||
// Don't read out of this directly. Use the helper functions.
|
||||
AirTime *AirTime::Held::armReentryCheck(AirTime *a)
|
||||
{
|
||||
#ifdef AIRTIME_REENTRY_CHECK
|
||||
// Before the lock: a nested take blocks forever, so a later check would never run.
|
||||
assert(!a->reentryFlag);
|
||||
a->reentryFlag = true;
|
||||
#endif
|
||||
return a;
|
||||
}
|
||||
|
||||
uint32_t air_period_tx[PERIODS_TO_LOG];
|
||||
uint32_t air_period_rx[PERIODS_TO_LOG];
|
||||
AirTime::Held::~Held()
|
||||
{
|
||||
#ifdef AIRTIME_REENTRY_CHECK
|
||||
owner->reentryFlag = false;
|
||||
#else
|
||||
(void)owner;
|
||||
#endif
|
||||
}
|
||||
|
||||
void AirTime::logAirtime(reportTypes reportType, uint32_t airtime_ms)
|
||||
// --- the lock-free core -------------------------------------------------------------------------
|
||||
// Every method here requires the lock, and says so in its signature. None can take it: Windows has
|
||||
// no lock to reach.
|
||||
|
||||
void AirTime::Windows::logAirtime(reportTypes reportType, uint32_t airtime_ms, const Held &held)
|
||||
{
|
||||
// A packet may be logged immediately after waking from light sleep. Sync first so
|
||||
// the packet is counted in the current wall-time bucket, not a stale awake-time bucket.
|
||||
syncNow();
|
||||
syncNow(held);
|
||||
|
||||
// The caller logs, once the lock is released.
|
||||
if (reportType == TX_LOG) {
|
||||
LOG_DEBUG("Packet TX: %ums", airtime_ms);
|
||||
this->airtimes.periodTX[0] = this->airtimes.periodTX[0] + airtime_ms;
|
||||
air_period_tx[0] = air_period_tx[0] + airtime_ms;
|
||||
|
||||
this->utilizationTX[this->getPeriodUtilHour()] = this->utilizationTX[this->getPeriodUtilHour()] + airtime_ms;
|
||||
this->utilizationTX[this->getPeriodUtilHour(held)] += airtime_ms;
|
||||
} else if (reportType == RX_LOG) {
|
||||
LOG_DEBUG("Packet RX: %ums", airtime_ms);
|
||||
this->airtimes.periodRX[0] = this->airtimes.periodRX[0] + airtime_ms;
|
||||
air_period_rx[0] = air_period_rx[0] + airtime_ms;
|
||||
} else if (reportType == RX_ALL_LOG) {
|
||||
LOG_DEBUG("Packet RX (noise?) : %ums", airtime_ms);
|
||||
this->airtimes.periodRX_ALL[0] = this->airtimes.periodRX_ALL[0] + airtime_ms;
|
||||
}
|
||||
|
||||
// Log all airtime type for channel utilization
|
||||
this->channelUtilization[this->getPeriodUtilMinute()] = channelUtilization[this->getPeriodUtilMinute()] + airtime_ms;
|
||||
this->channelUtilization[this->getPeriodUtilMinute(held)] += airtime_ms;
|
||||
}
|
||||
|
||||
uint8_t AirTime::currentPeriodIndex()
|
||||
{
|
||||
return ((secSinceBoot / SECONDS_PER_PERIOD) % PERIODS_TO_LOG);
|
||||
}
|
||||
|
||||
uint8_t AirTime::getPeriodUtilMinute()
|
||||
uint8_t AirTime::Windows::getPeriodUtilMinute(const Held &)
|
||||
{
|
||||
return (secSinceBoot / 10) % CHANNEL_UTILIZATION_PERIODS;
|
||||
}
|
||||
|
||||
uint8_t AirTime::getPeriodUtilHour()
|
||||
uint8_t AirTime::Windows::getPeriodUtilHour(const Held &)
|
||||
{
|
||||
return (secSinceBoot / 60) % MINUTES_IN_HOUR;
|
||||
}
|
||||
|
||||
void AirTime::airtimeRotatePeriod()
|
||||
{
|
||||
// Preserve the public helper while keeping all rotation logic in one monotonic-time path.
|
||||
syncNow();
|
||||
}
|
||||
|
||||
void AirTime::syncNow()
|
||||
void AirTime::Windows::syncNow(const Held &)
|
||||
{
|
||||
// Monotonic uptime, not RTC/network time: a user, GPS, or NTP clock change must not move
|
||||
// airtime accounting. Pure read; the main loop publishes the wrap carry it derives from.
|
||||
@@ -69,13 +72,8 @@ void AirTime::syncNow()
|
||||
memset(this->airtimes.periodTX, 0, sizeof(this->airtimes.periodTX));
|
||||
memset(this->airtimes.periodRX, 0, sizeof(this->airtimes.periodRX));
|
||||
memset(this->airtimes.periodRX_ALL, 0, sizeof(this->airtimes.periodRX_ALL));
|
||||
memset(air_period_tx, 0, sizeof(air_period_tx));
|
||||
memset(air_period_rx, 0, sizeof(air_period_rx));
|
||||
|
||||
this->secSinceBoot = nowSecs;
|
||||
this->lastUtilPeriod = this->getPeriodUtilMinute();
|
||||
this->lastUtilPeriodTX = this->getPeriodUtilHour();
|
||||
this->airtimes.lastPeriodIndex = this->currentPeriodIndex();
|
||||
firstTime = false;
|
||||
return;
|
||||
}
|
||||
@@ -94,27 +92,22 @@ void AirTime::syncNow()
|
||||
memset(this->airtimes.periodTX, 0, sizeof(this->airtimes.periodTX));
|
||||
memset(this->airtimes.periodRX, 0, sizeof(this->airtimes.periodRX));
|
||||
memset(this->airtimes.periodRX_ALL, 0, sizeof(this->airtimes.periodRX_ALL));
|
||||
memset(air_period_tx, 0, sizeof(air_period_tx));
|
||||
memset(air_period_rx, 0, sizeof(air_period_rx));
|
||||
} else {
|
||||
while (elapsedAirtimePeriods-- > 0) {
|
||||
LOG_DEBUG("Rotate airtimes to a new period = %u", this->currentPeriodIndex());
|
||||
// Hand the count to runOnce() rather than tracing each crossing here: this runs under
|
||||
// the lock, and a UART write would stall every other caller waiting on it.
|
||||
this->rotationsPendingLog += elapsedAirtimePeriods;
|
||||
for (uint32_t h = 0; h < elapsedAirtimePeriods; h++) {
|
||||
for (int i = PERIODS_TO_LOG - 2; i >= 0; --i) {
|
||||
this->airtimes.periodTX[i + 1] = this->airtimes.periodTX[i];
|
||||
this->airtimes.periodRX[i + 1] = this->airtimes.periodRX[i];
|
||||
this->airtimes.periodRX_ALL[i + 1] = this->airtimes.periodRX_ALL[i];
|
||||
air_period_tx[i + 1] = this->airtimes.periodTX[i];
|
||||
air_period_rx[i + 1] = this->airtimes.periodRX[i];
|
||||
}
|
||||
|
||||
this->airtimes.periodTX[0] = 0;
|
||||
this->airtimes.periodRX[0] = 0;
|
||||
this->airtimes.periodRX_ALL[0] = 0;
|
||||
air_period_tx[0] = 0;
|
||||
air_period_rx[0] = 0;
|
||||
}
|
||||
}
|
||||
this->airtimes.lastPeriodIndex = this->currentPeriodIndex();
|
||||
|
||||
// Channel utilization is a rolling 60-second view split into six 10-second buckets.
|
||||
// Clear every bucket crossed while asleep so old airtime decays by real elapsed time.
|
||||
@@ -126,7 +119,6 @@ void AirTime::syncNow()
|
||||
this->channelUtilization[((oldSecSinceBoot / 10) + i) % CHANNEL_UTILIZATION_PERIODS] = 0;
|
||||
}
|
||||
}
|
||||
this->lastUtilPeriod = this->getPeriodUtilMinute();
|
||||
|
||||
// TX utilization is a rolling 60-minute view used by duty-cycle checks.
|
||||
uint32_t elapsedUtilTXPeriods = (this->secSinceBoot / 60) - (oldSecSinceBoot / 60);
|
||||
@@ -137,45 +129,35 @@ void AirTime::syncNow()
|
||||
this->utilizationTX[((oldSecSinceBoot / 60) + i) % MINUTES_IN_HOUR] = 0;
|
||||
}
|
||||
}
|
||||
this->lastUtilPeriodTX = this->getPeriodUtilHour();
|
||||
}
|
||||
|
||||
uint32_t *AirTime::airtimeReport(reportTypes reportType)
|
||||
bool AirTime::Windows::airtimeReport(reportTypes reportType, uint32_t *out, size_t count, const Held &held)
|
||||
{
|
||||
if (!out || count > PERIODS_TO_LOG)
|
||||
return false;
|
||||
|
||||
// Reports may be requested before runOnce() executes after wake.
|
||||
syncNow();
|
||||
syncNow(held);
|
||||
|
||||
const uint32_t *src = nullptr;
|
||||
if (reportType == TX_LOG) {
|
||||
return this->airtimes.periodTX;
|
||||
src = this->airtimes.periodTX;
|
||||
} else if (reportType == RX_LOG) {
|
||||
return this->airtimes.periodRX;
|
||||
src = this->airtimes.periodRX;
|
||||
} else if (reportType == RX_ALL_LOG) {
|
||||
return this->airtimes.periodRX_ALL;
|
||||
src = this->airtimes.periodRX_ALL;
|
||||
}
|
||||
return 0;
|
||||
if (!src)
|
||||
return false;
|
||||
|
||||
memcpy(out, src, count * sizeof(*out));
|
||||
return true;
|
||||
}
|
||||
|
||||
uint8_t AirTime::getPeriodsToLog()
|
||||
{
|
||||
return PERIODS_TO_LOG;
|
||||
}
|
||||
|
||||
uint32_t AirTime::getSecondsPerPeriod()
|
||||
{
|
||||
return SECONDS_PER_PERIOD;
|
||||
}
|
||||
|
||||
uint32_t AirTime::getSecondsSinceBoot()
|
||||
{
|
||||
// Keep HTTP/debug reporting aligned with the same monotonic clock used by the buckets.
|
||||
syncNow();
|
||||
return this->secSinceBoot;
|
||||
}
|
||||
|
||||
float AirTime::channelUtilizationPercent()
|
||||
float AirTime::Windows::channelUtilizationPercent(const Held &held)
|
||||
{
|
||||
// Gate decisions should see buckets that have decayed across light-sleep time.
|
||||
syncNow();
|
||||
syncNow(held);
|
||||
|
||||
uint32_t sum = 0;
|
||||
for (uint32_t i = 0; i < CHANNEL_UTILIZATION_PERIODS; i++) {
|
||||
@@ -185,10 +167,10 @@ float AirTime::channelUtilizationPercent()
|
||||
return (float(sum) / float(CHANNEL_UTILIZATION_PERIODS * 10 * 1000)) * 100;
|
||||
}
|
||||
|
||||
float AirTime::utilizationTXPercent()
|
||||
float AirTime::Windows::utilizationTXPercent(const Held &held)
|
||||
{
|
||||
// Duty-cycle checks use this value, so keep it current even outside the periodic thread.
|
||||
syncNow();
|
||||
syncNow(held);
|
||||
|
||||
uint32_t sum = 0;
|
||||
for (uint32_t i = 0; i < MINUTES_IN_HOUR; i++) {
|
||||
@@ -198,33 +180,9 @@ float AirTime::utilizationTXPercent()
|
||||
return (float(sum) / float(MS_IN_HOUR)) * 100;
|
||||
}
|
||||
|
||||
bool AirTime::isTxAllowedChannelUtil(bool polite)
|
||||
{
|
||||
uint8_t percentage = (polite ? polite_channel_util_percent : max_channel_util_percent);
|
||||
if (channelUtilizationPercent() < percentage) {
|
||||
return true;
|
||||
} else {
|
||||
LOG_WARN("Ch. util >%d%%. Skip send", percentage);
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
||||
bool AirTime::isTxAllowedAirUtil()
|
||||
{
|
||||
float effectiveDutyCycle = getEffectiveDutyCycle();
|
||||
if (!config.lora.override_duty_cycle && effectiveDutyCycle < 100) {
|
||||
if (utilizationTXPercent() < effectiveDutyCycle * polite_duty_cycle_percent / 100) {
|
||||
return true;
|
||||
} else {
|
||||
LOG_WARN("TX air util. >%f%%. Skip send", effectiveDutyCycle * polite_duty_cycle_percent / 100);
|
||||
return false;
|
||||
}
|
||||
}
|
||||
return true;
|
||||
}
|
||||
|
||||
// Get the amount of minutes we have to be silent before we can send again
|
||||
uint8_t AirTime::getSilentMinutes(float txPercent, float dutyCycle)
|
||||
// Minutes we must be silent before sending again. Does not sync, and walks the ring as if the index
|
||||
// were an age; both are wrong and both are pinned by characterisation tests. See airtime.h's TODO.
|
||||
uint8_t AirTime::Windows::getSilentMinutes(float txPercent, float dutyCycle, const Held &)
|
||||
{
|
||||
float newTxPercent = txPercent;
|
||||
for (int8_t i = MINUTES_IN_HOUR - 1; i >= 0; --i) {
|
||||
@@ -236,10 +194,119 @@ uint8_t AirTime::getSilentMinutes(float txPercent, float dutyCycle)
|
||||
return MINUTES_IN_HOUR;
|
||||
}
|
||||
|
||||
AirTime::AirTime() : concurrency::OSThread("AirTime"), airtimes({}) {}
|
||||
// --- the locking shell --------------------------------------------------------------------------
|
||||
// Each takes the lock exactly once and delegates. Nothing below calls another method on `this`.
|
||||
|
||||
void AirTime::logAirtime(reportTypes reportType, uint32_t airtime_ms)
|
||||
{
|
||||
{
|
||||
Held held(this);
|
||||
w.logAirtime(reportType, airtime_ms, held);
|
||||
}
|
||||
|
||||
// Outside the lock: DEBUG_PORT.log() blocks on a UART write, and `lock` is a plain binary
|
||||
// semaphore with no priority inheritance, so holding it here would stall the radio thread.
|
||||
if (reportType == TX_LOG) {
|
||||
LOG_DEBUG("Packet TX: %ums", airtime_ms);
|
||||
} else if (reportType == RX_LOG) {
|
||||
LOG_DEBUG("Packet RX: %ums", airtime_ms);
|
||||
} else if (reportType == RX_ALL_LOG) {
|
||||
LOG_DEBUG("Packet RX (noise?) : %ums", airtime_ms);
|
||||
}
|
||||
}
|
||||
|
||||
void AirTime::airtimeRotatePeriod()
|
||||
{
|
||||
// Preserve the public helper while keeping all rotation logic in one monotonic-time path.
|
||||
Held held(this);
|
||||
w.syncNow(held);
|
||||
}
|
||||
|
||||
bool AirTime::airtimeReport(reportTypes reportType, uint32_t *out, size_t count)
|
||||
{
|
||||
Held held(this);
|
||||
return w.airtimeReport(reportType, out, count, held);
|
||||
}
|
||||
|
||||
uint32_t AirTime::getSecondsSinceBoot()
|
||||
{
|
||||
// Keep HTTP/debug reporting aligned with the same monotonic clock used by the buckets.
|
||||
Held held(this);
|
||||
w.syncNow(held);
|
||||
return w.secSinceBoot;
|
||||
}
|
||||
|
||||
float AirTime::channelUtilizationPercent()
|
||||
{
|
||||
Held held(this);
|
||||
return w.channelUtilizationPercent(held);
|
||||
}
|
||||
|
||||
float AirTime::utilizationTXPercent()
|
||||
{
|
||||
Held held(this);
|
||||
return w.utilizationTXPercent(held);
|
||||
}
|
||||
|
||||
// These lock like everything else, because they call the core rather than the public accessors.
|
||||
// Both read under the lock and warn after it, for the reason logAirtime() does.
|
||||
bool AirTime::isTxAllowedChannelUtil(bool polite)
|
||||
{
|
||||
uint8_t percentage = (polite ? polite_channel_util_percent : max_channel_util_percent);
|
||||
float utilization;
|
||||
{
|
||||
Held held(this);
|
||||
utilization = w.channelUtilizationPercent(held);
|
||||
}
|
||||
|
||||
if (utilization < percentage)
|
||||
return true;
|
||||
LOG_WARN("Ch. util >%d%%. Skip send", percentage);
|
||||
return false;
|
||||
}
|
||||
|
||||
bool AirTime::isTxAllowedAirUtil()
|
||||
{
|
||||
float effectiveDutyCycle = getEffectiveDutyCycle();
|
||||
if (!config.lora.override_duty_cycle && effectiveDutyCycle < 100) {
|
||||
float limit = effectiveDutyCycle * polite_duty_cycle_percent / 100;
|
||||
float utilization;
|
||||
{
|
||||
Held held(this);
|
||||
utilization = w.utilizationTXPercent(held);
|
||||
}
|
||||
|
||||
if (utilization < limit)
|
||||
return true;
|
||||
LOG_WARN("TX air util. >%f%%. Skip send", limit);
|
||||
return false;
|
||||
}
|
||||
return true;
|
||||
}
|
||||
|
||||
uint8_t AirTime::getSilentMinutes(float txPercent, float dutyCycle)
|
||||
{
|
||||
Held held(this);
|
||||
return w.getSilentMinutes(txPercent, dutyCycle, held);
|
||||
}
|
||||
|
||||
AirTime::AirTime() : concurrency::OSThread("AirTime") {}
|
||||
|
||||
int32_t AirTime::runOnce()
|
||||
{
|
||||
syncNow();
|
||||
uint32_t rotations;
|
||||
{
|
||||
Held held(this);
|
||||
w.syncNow(held);
|
||||
rotations = w.rotationsPendingLog;
|
||||
w.rotationsPendingLog = 0;
|
||||
}
|
||||
|
||||
// Outside the lock, for the reason logAirtime() gives. Any caller can cross an hour, but only
|
||||
// this thread reports it, so a crossing raised elsewhere is traced at most one tick late.
|
||||
if (rotations > 0) {
|
||||
LOG_DEBUG("Rotate airtimes, crossed %u hour(s)", rotations);
|
||||
}
|
||||
|
||||
return (1000 * 1);
|
||||
}
|
||||
+164
-45
@@ -1,28 +1,79 @@
|
||||
#pragma once
|
||||
|
||||
#include "MeshRadio.h"
|
||||
#include "concurrency/Lock.h"
|
||||
#include "concurrency/LockGuard.h"
|
||||
#include "concurrency/OSThread.h"
|
||||
#include "configuration.h"
|
||||
#include <Arduino.h>
|
||||
#include <functional>
|
||||
|
||||
/*
|
||||
TX_LOG - Time on air this device has transmitted
|
||||
AirTime records how long the radio was busy and turns that into the two
|
||||
percentages the transmit gates and DeviceMetrics use.
|
||||
|
||||
RX_LOG - Time on air used by valid and routable mesh packets, does not include
|
||||
TX air time
|
||||
INPUTS - four events change this class's state:
|
||||
|
||||
RX_ALL_LOG - Time of all received lora packets. This includes packets that are not
|
||||
for meshtastic devices. Does not include TX air time.
|
||||
logAirtime(TX_LOG, ms) one per completed transmission, ours and relayed
|
||||
logAirtime(RX_LOG, ms) one per well-formed reception. The interface is
|
||||
promiscuous: this counts packets not addressed
|
||||
to us, and every duplicate relay copy.
|
||||
logAirtime(RX_ALL_LOG, ms) one per reception that could NOT be parsed -
|
||||
failed CRC, truncated, region unset, collision
|
||||
elapsed time Time::getUptimeSecs(), read by syncNow() on
|
||||
every public entry point. The only input that
|
||||
removes airtime.
|
||||
|
||||
Example analytics:
|
||||
RX_LOG and RX_ALL_LOG are DISJOINT, and a reception logs AT MOST one of them.
|
||||
RX_ALL_LOG is unparseable airtime, not a superset of RX_LOG, so the total is
|
||||
TX + RX + RX_ALL - but it under-counts: five drop paths log neither. A packet
|
||||
with from == 0 returns unlogged from handleReceiveInterrupt(), unlike every
|
||||
neighbouring drop, and SimRadio drops a collision during transmission plus
|
||||
three allocation failures. Pre-existing; see the TODO below.
|
||||
|
||||
TX_LOG + RX_LOG = Total air time for a particular meshtastic channel.
|
||||
OUTPUTS:
|
||||
|
||||
TX_LOG + RX_ALL_LOG = Total air time for a particular meshtastic channel, including
|
||||
other lora radios.
|
||||
channelUtilizationPercent() % of the last 60s busy, all three types
|
||||
utilizationTXPercent() % of the last hour we transmitted
|
||||
isTxAllowedChannelUtil() gate on the former, 40% or 25% "polite"
|
||||
isTxAllowedAirUtil() gate on the latter, at HALF the duty cycle
|
||||
getSilentMinutes() minutes until the TX figure clears a limit.
|
||||
Feeds a log line and a client notification; it
|
||||
gates nothing.
|
||||
airtimeReport() 8 x 1h of raw ms per type, for the HTTP report
|
||||
getSecondsSinceBoot() the clock the buckets are keyed to
|
||||
|
||||
RX_ALL_LOG - RX_LOG = Other lora radios on our frequency channel.
|
||||
The three thresholds are hard-coded members with no config binding.
|
||||
|
||||
STORAGE - two orderings, easily confused:
|
||||
|
||||
channelUtilization[], utilizationTX[]
|
||||
Modular rings indexed by absolute uptime phase, (secs / p) % N. The
|
||||
index is NOT an age; the oldest bucket is (current + 1) % N. Crossing
|
||||
into a bucket zeroes it.
|
||||
|
||||
airtimes.period{TX,RX,RX_ALL}[]
|
||||
Shift-ordered, slot 0 newest, index IS age in hours. Slot 0 is a partial
|
||||
hour; normalise it by getSecondsSinceBoot() % getSecondsPerPeriod().
|
||||
|
||||
The percentages measure wall time, not time awake. A light-sleeping node still
|
||||
hears traffic, and reporting over observed time would make two nodes'
|
||||
broadcast readings incomparable.
|
||||
|
||||
channelUtilization spans 60s but reaches the mesh at >= 1h cadence, so remote
|
||||
readings are a snapshot rather than an average. Its contention-window consumer
|
||||
moves in 20-percentage-point steps, map(chanutil, 0, 100, CWmin, CWmax), so
|
||||
small errors never reach the backoff.
|
||||
|
||||
Rotation happens on access, not on the scheduler tick: every public method
|
||||
calls syncNow() first and runOnce() only guarantees once a second. A
|
||||
scheduler-driven window stops advancing during light sleep. Enforced by
|
||||
test_channel_utilization_is_independent_of_scheduler_rate.
|
||||
|
||||
TODO: airtime accuracy. Four known defects remain - the quantised denominator,
|
||||
its sawtooth, whole-packet attribution to the completing bucket, and
|
||||
getSilentMinutes() reading a modular ring as if the index were an age. Each is
|
||||
pinned by a test tagged CHARACTERISATION in test/test_airtime.
|
||||
*/
|
||||
|
||||
#define CHANNEL_UTILIZATION_PERIODS 6
|
||||
@@ -35,16 +86,42 @@
|
||||
|
||||
enum reportTypes { TX_LOG, RX_LOG, RX_ALL_LOG };
|
||||
|
||||
void logAirtime(reportTypes reportType, uint32_t airtime_ms);
|
||||
// Arms AirTime's nested-take check. Sound only where the lock is not a real lock: the check runs
|
||||
// before the take, because a nested take blocks forever and a later check would never run - so
|
||||
// under preemption it would false-positive on legitimate contention and race on its own write.
|
||||
// Portduino is where it earns its keep anyway; there Lock::lock() is empty, so a nested take
|
||||
// succeeds silently and nothing else would notice. On an on-target test build the nesting it
|
||||
// catches shows up as a hang instead. Test builds only: nothing in this tree defines DEBUG or
|
||||
// NDEBUG, so either spelling would ship an abort() to every board, and nrf52_promicro_diy_tcxo
|
||||
// has no flash for it.
|
||||
#if defined(PIO_UNIT_TESTING) && !defined(HAS_FREE_RTOS)
|
||||
#define AIRTIME_REENTRY_CHECK
|
||||
#endif
|
||||
|
||||
uint32_t *airtimeReport(reportTypes reportType);
|
||||
|
||||
// Not thread-safe: everything but getPeriodsToLog()/getSecondsPerPeriod() either rotates the
|
||||
// windows via syncNow() or reads the buckets. Current callers are all on the OSThread scheduler -
|
||||
// RadioLibInterface/SimRadio, RadioInterface, Router, DeviceTelemetry, ContentHandler, and the
|
||||
// screen renderers. New callers must be on that thread too, or this needs a lock.
|
||||
// TODO: airtime lock-guarding - serialise the above behind a lock so the contract is enforced
|
||||
// rather than documented. Kept out of this PR: it is a separate concern from millis() rollover.
|
||||
// Serialised behind `lock` because two FreeRTOS tasks genuinely reach this class at once on nRF52.
|
||||
// NRF52Bluetooth registers its ToRadio write callback with defer == false, so a phone's packet runs
|
||||
// PhoneAPI::handleToRadio -> MeshService::sendToMesh -> Router::send on the Bluefruit BLE task,
|
||||
// which reads utilizationTXPercent() and getSilentMinutes() while loopTask may be inside
|
||||
// logAirtime() from a reception. That is an unsynchronised read-modify-write of utilizationTX[] and
|
||||
// secSinceBoot against a summing read. ESP32 hands BLE work to the main task and does not have it.
|
||||
//
|
||||
// Two mechanisms keep it serialised:
|
||||
//
|
||||
// - a lock-free inner core (Windows) holds all state and all logic. It has no lock member, and
|
||||
// must never reach one through the global `airTime` - `airTime->anyPublicMethod()` from inside
|
||||
// a Windows method would take a second Held and hang, because concurrency::Lock is a
|
||||
// non-recursive binary semaphore taken with portMAX_DELAY. Nothing does this today; the
|
||||
// AIRTIME_REENTRY_CHECK assert is the backstop, and it only builds on host test builds.
|
||||
// - a private Held token takes the lock in its constructor and is the only thing that satisfies a
|
||||
// core method's `const Held &`, so the lock cannot be forgotten.
|
||||
//
|
||||
// Every public method takes the lock exactly once and delegates, with two exceptions: the two
|
||||
// constexpr accessors below touch no state and take none, and isTxAllowedAirUtil() takes it zero or
|
||||
// one times, depending on whether the duty-cycle branch is entered at all. Nothing inside locks -
|
||||
// that includes isTxAllowed*(), which call the core rather than the public accessors.
|
||||
//
|
||||
// A new write-path helper belongs to Windows or is a free function, never a method on AirTime: an
|
||||
// AirTime method locks, and logAirtime() would call it while already holding the lock.
|
||||
class AirTime : private concurrency::OSThread
|
||||
{
|
||||
|
||||
@@ -55,43 +132,85 @@ class AirTime : private concurrency::OSThread
|
||||
float channelUtilizationPercent();
|
||||
float utilizationTXPercent();
|
||||
|
||||
float UtilizationPercentTX();
|
||||
uint32_t channelUtilization[CHANNEL_UTILIZATION_PERIODS] = {0};
|
||||
uint32_t utilizationTX[MINUTES_IN_HOUR] = {0};
|
||||
|
||||
/// Compatibility shim: no caller in the tree, kept for out-of-tree ones.
|
||||
void airtimeRotatePeriod();
|
||||
uint8_t getPeriodsToLog();
|
||||
uint32_t getSecondsPerPeriod();
|
||||
/// Constants, not state: no lock, and usable where a constant expression is required so a
|
||||
/// caller's buffer and the count it passes to airtimeReport() cannot drift apart.
|
||||
static constexpr uint8_t getPeriodsToLog() { return PERIODS_TO_LOG; }
|
||||
static constexpr uint32_t getSecondsPerPeriod() { return SECONDS_PER_PERIOD; }
|
||||
uint32_t getSecondsSinceBoot();
|
||||
uint32_t *airtimeReport(reportTypes reportType);
|
||||
/// Copies `count` buckets into `out`, newest first. Copies rather than returning the array so a
|
||||
/// caller cannot hold a handle to buckets that every other entry point rotates underneath it.
|
||||
/// False if `out` is null, `count` exceeds the log depth, or the report type is unknown.
|
||||
bool airtimeReport(reportTypes reportType, uint32_t *out, size_t count);
|
||||
uint8_t getSilentMinutes(float txPercent, float dutyCycle);
|
||||
bool isTxAllowedChannelUtil(bool polite = false);
|
||||
bool isTxAllowedAirUtil();
|
||||
|
||||
private:
|
||||
bool firstTime = true;
|
||||
uint8_t lastUtilPeriod = 0;
|
||||
uint8_t lastUtilPeriodTX = 0;
|
||||
// Time::getUptimeSecs() as of the last syncNow(); the gap since is what the windows rotate by,
|
||||
// so they stay correct even if the scheduler was paused by light sleep.
|
||||
uint32_t secSinceBoot = 0;
|
||||
concurrency::Lock lock;
|
||||
|
||||
#ifdef AIRTIME_REENTRY_CHECK
|
||||
// Set for the lifetime of a Held and checked before the lock is taken, so a nested take is
|
||||
// reported rather than hung at. See the macro's definition for why it is host-only.
|
||||
bool reentryFlag = false;
|
||||
#endif
|
||||
|
||||
/// Takes `lock` for its lifetime and doubles as proof that it is held. Only AirTime can
|
||||
/// construct one, so a core method taking `const Held &` cannot be called without the lock.
|
||||
/// A bare LockGuard would not do: it proves only that *some* lock is held.
|
||||
class Held
|
||||
{
|
||||
public:
|
||||
explicit Held(AirTime *a) : owner(armReentryCheck(a)), guard(&a->lock) {}
|
||||
~Held();
|
||||
Held(const Held &) = delete;
|
||||
Held &operator=(const Held &) = delete;
|
||||
|
||||
private:
|
||||
static AirTime *armReentryCheck(AirTime *a);
|
||||
AirTime *owner; // declared first, so its initialiser runs before the lock is taken
|
||||
concurrency::LockGuard guard;
|
||||
};
|
||||
|
||||
/// All state, all logic, no lock. Cannot take one, so cannot nest.
|
||||
struct Windows {
|
||||
bool firstTime = true;
|
||||
// Time::getUptimeSecs() as of the last syncNow(). The windows rotate by the gap since, so
|
||||
// they stay correct across a paused scheduler.
|
||||
uint32_t secSinceBoot = 0;
|
||||
|
||||
// Modular rings: index is absolute phase, (uptime secs / period) % N, never age.
|
||||
uint32_t channelUtilization[CHANNEL_UTILIZATION_PERIODS] = {0}; // 6 x 10s
|
||||
uint32_t utilizationTX[MINUTES_IN_HOUR] = {0}; // 60 x 60s, our TX only
|
||||
|
||||
// Hour crossings rotated but not yet traced. The core cannot log its own rotations: it
|
||||
// only ever runs under the lock, and DEBUG_PORT.log() blocks on a UART write. runOnce()
|
||||
// drains this and logs after releasing, so the trace costs the lock nothing.
|
||||
uint32_t rotationsPendingLog = 0;
|
||||
|
||||
// Shift-ordered, unlike the rings above: slot 0 is the newest hour and the index is age.
|
||||
struct airtimeStruct {
|
||||
uint32_t periodTX[PERIODS_TO_LOG] = {0}; // AirTime transmitted
|
||||
uint32_t periodRX[PERIODS_TO_LOG] = {0}; // AirTime received and repeated (valid mesh packets)
|
||||
uint32_t periodRX_ALL[PERIODS_TO_LOG] = {0}; // AirTime received regardless of validity. May be noise.
|
||||
} airtimes;
|
||||
|
||||
void logAirtime(reportTypes reportType, uint32_t airtime_ms, const Held &);
|
||||
float channelUtilizationPercent(const Held &);
|
||||
float utilizationTXPercent(const Held &);
|
||||
bool airtimeReport(reportTypes reportType, uint32_t *out, size_t count, const Held &);
|
||||
uint8_t getSilentMinutes(float txPercent, float dutyCycle, const Held &);
|
||||
uint8_t getPeriodUtilMinute(const Held &);
|
||||
uint8_t getPeriodUtilHour(const Held &);
|
||||
// Advance rolling airtime windows from monotonic uptime, not from runOnce() calls.
|
||||
void syncNow(const Held &);
|
||||
} w;
|
||||
|
||||
uint8_t max_channel_util_percent = 40;
|
||||
uint8_t polite_channel_util_percent = 25;
|
||||
uint8_t polite_duty_cycle_percent = 50; // half of Duty Cycle allowance is ok for metadata
|
||||
|
||||
struct airtimeStruct {
|
||||
uint32_t periodTX[PERIODS_TO_LOG]; // AirTime transmitted
|
||||
uint32_t periodRX[PERIODS_TO_LOG]; // AirTime received and repeated (Only valid mesh packets)
|
||||
uint32_t periodRX_ALL[PERIODS_TO_LOG]; // AirTime received regardless of valid mesh packet. Could include noise.
|
||||
uint8_t lastPeriodIndex;
|
||||
} airtimes;
|
||||
|
||||
uint8_t getPeriodUtilMinute();
|
||||
uint8_t getPeriodUtilHour();
|
||||
uint8_t currentPeriodIndex();
|
||||
// Advance rolling airtime windows from monotonic uptime, not from runOnce() calls.
|
||||
void syncNow();
|
||||
|
||||
protected:
|
||||
virtual int32_t runOnce() override;
|
||||
};
|
||||
|
||||
+3
-1
@@ -3525,8 +3525,10 @@ void NodeDB::addFromContact(meshtastic_SharedContact contact)
|
||||
// last_heard will remain as-is (or remain 0 if this entry wasn't in the nodeDB).
|
||||
// If the protected cap refuses the favorite, fall back to a heard-now stamp so the
|
||||
// contact still isn't the first eviction victim.
|
||||
if (!setProtectedFlag(info, NODEINFO_BITFIELD_IS_FAVORITE_MASK, true))
|
||||
if (!setProtectedFlag(info, NODEINFO_BITFIELD_IS_FAVORITE_MASK, true)) {
|
||||
LOG_WARN(PROTECTED_CAP_WARN_FMT, "favorite", contact.node_num, MAX_NUM_NODES - 2);
|
||||
stampContactHeardNow(info);
|
||||
}
|
||||
}
|
||||
|
||||
// As the clients will begin sending the contact with DMs, we want to strictly check if the node is manually verified
|
||||
|
||||
@@ -628,13 +628,18 @@ void handleReport(HTTPRequest *req, HTTPResponse *res)
|
||||
return s;
|
||||
};
|
||||
|
||||
uint32_t *logArray;
|
||||
logArray = airTime->airtimeReport(TX_LOG);
|
||||
std::string txLog = arrayFromLog(logArray, airTime->getPeriodsToLog());
|
||||
logArray = airTime->airtimeReport(RX_LOG);
|
||||
std::string rxLog = arrayFromLog(logArray, airTime->getPeriodsToLog());
|
||||
logArray = airTime->airtimeReport(RX_ALL_LOG);
|
||||
std::string rxAllLog = arrayFromLog(logArray, airTime->getPeriodsToLog());
|
||||
// One constant sizes the buffer and the count, so they cannot drift. Buffer is per call, so a
|
||||
// report that fails emits zeros rather than the previous type's data.
|
||||
constexpr size_t periods = AirTime::getPeriodsToLog();
|
||||
auto reportFor = [&](reportTypes reportType) {
|
||||
uint32_t logArray[periods] = {0};
|
||||
(void)airTime->airtimeReport(reportType, logArray, periods);
|
||||
return arrayFromLog(logArray, (int)periods);
|
||||
};
|
||||
|
||||
std::string txLog = reportFor(TX_LOG);
|
||||
std::string rxLog = reportFor(RX_LOG);
|
||||
std::string rxAllLog = reportFor(RX_ALL_LOG);
|
||||
|
||||
String wifiIPString = WiFi.localIP().toString();
|
||||
std::string wifiIP = wifiIPString.c_str();
|
||||
|
||||
@@ -1,3 +1,4 @@
|
||||
#include "UptimeClock.h"
|
||||
#include "configuration.h"
|
||||
#include "mesh/Throttle.h"
|
||||
#include <Adafruit_TinyUSB.h>
|
||||
@@ -296,7 +297,7 @@ void preFSBegin()
|
||||
if (!(NRF_POWER->RESETREAS == 0 && NRF_POWER->GPREGRET == NRF52_MAGIC_LFS_IS_CORRUPT))
|
||||
return;
|
||||
NRF_POWER->GPREGRET = 0;
|
||||
last_format_ms = millis();
|
||||
last_format_ms = Time::getMillis();
|
||||
formatted_this_boot = true;
|
||||
InternalFS.format();
|
||||
LOG_INFO("LittleFS format complete; restoring default settings");
|
||||
@@ -309,8 +310,12 @@ extern "C" void lfs_assert(const char *reason)
|
||||
// minutes after each wrap.
|
||||
if (formatted_this_boot && Throttle::isWithinTimespanMs(last_format_ms, MULTIPLE_CORRUPTION_DELAY_MILLIS)) {
|
||||
RECORD_CRITICALERROR(meshtastic_CriticalErrorCode_FLASH_CORRUPTION_UNRECOVERABLE);
|
||||
const long millis_remain = MULTIPLE_CORRUPTION_DELAY_MILLIS - (millis() - last_format_ms);
|
||||
LOG_WARN("Pausing %d seconds to avoid wear on flash storage", millis_remain / 1000);
|
||||
// Same clock Throttle just read, and clamped: the check above and a second, later read
|
||||
// can straddle the backoff, which would wrap the remainder into a ~50-day delay().
|
||||
const uint32_t elapsed = Time::getMillis() - last_format_ms;
|
||||
const uint32_t millis_remain =
|
||||
elapsed < MULTIPLE_CORRUPTION_DELAY_MILLIS ? MULTIPLE_CORRUPTION_DELAY_MILLIS - elapsed : 0;
|
||||
LOG_WARN("Pausing %u seconds to avoid wear on flash storage", millis_remain / 1000);
|
||||
delay(millis_remain);
|
||||
}
|
||||
LOG_INFO("Rebooting to format LittleFS");
|
||||
|
||||
+1090
-5
File diff suppressed because it is too large.
Load diff
@@ -181,7 +181,7 @@ static void test_eviction_preservesFavorite(void)
|
||||
|
||||
// A node heard during this boot is newer than every persisted epoch, including valid epochs after
|
||||
// 2038. Ranking both domains in one uint32_t incorrectly evicts the current-boot node first.
|
||||
static void test_eviction_prefers_current_boot_stamp_over_post2038_epoch(void)
|
||||
static void test_eviction_prefersCurrentBootStampOverPost2038Epoch(void)
|
||||
{
|
||||
constexpr NodeNum futureDated = 0x70000001;
|
||||
constexpr NodeNum heardThisBoot = 0x70000002;
|
||||
@@ -291,7 +291,7 @@ NDB_TEST_ENTRY void setup()
|
||||
RUN_TEST(test_migration_carriesRoleAndProtectedIntoWarm);
|
||||
RUN_TEST(test_migration_carriesSignerBitThroughWarm);
|
||||
RUN_TEST(test_eviction_preservesFavorite);
|
||||
RUN_TEST(test_eviction_prefers_current_boot_stamp_over_post2038_epoch);
|
||||
RUN_TEST(test_eviction_prefersCurrentBootStampOverPost2038Epoch);
|
||||
RUN_TEST(test_ignored_survivesEvictionAndCleanup);
|
||||
RUN_TEST(test_protectedCap_refusesBeyondLimit);
|
||||
RUN_TEST(test_removeNodeByNum_absentNodeOnFullDb);
|
||||
|
||||
@@ -417,6 +417,9 @@ void setUp(void)
|
||||
resetRoutingAuthEvaluationCount();
|
||||
}
|
||||
|
||||
// Set while C14's saturated AirTime is installed; see useDutyCycleSaturatedAirTime() below.
|
||||
static AirTime *c14SavedAirTime = nullptr;
|
||||
|
||||
void tearDown(void)
|
||||
{
|
||||
delete mockNodeDB;
|
||||
@@ -425,13 +428,15 @@ void tearDown(void)
|
||||
|
||||
// Restore globals here, not at the end of a test body: an assertion aborts the body, and these
|
||||
// would otherwise leak into every later case. The injected clock is the one the N8-N11
|
||||
// suppression-window cases drive; the region and TX bucket are C14's duty-cycle setup.
|
||||
// suppression-window cases drive; the region and the AirTime swap are C14's duty-cycle setup.
|
||||
Time::useRealClock();
|
||||
Time::resetMonotonicForTests();
|
||||
if (airTime)
|
||||
airTime->utilizationTX[0] = 0;
|
||||
config.lora.region = meshtastic_Config_LoRaConfig_RegionCode_US;
|
||||
initRegion();
|
||||
if (c14SavedAirTime) {
|
||||
airTime = c14SavedAirTime;
|
||||
c14SavedAirTime = nullptr;
|
||||
}
|
||||
}
|
||||
|
||||
// ===========================================================================
|
||||
@@ -1500,12 +1505,32 @@ void test_C13_failed_initial_reliable_send_does_not_retry(void)
|
||||
"failed interface enqueue must not leave a retransmission pending");
|
||||
}
|
||||
|
||||
// C14 needs a node that has used its whole hourly duty-cycle allowance. Swaps in a separate AirTime
|
||||
// rather than poking the global's buckets, which are private now.
|
||||
//
|
||||
// Deliberately NOT a scoped guard: Unity's TEST_ABORT() is longjmp, which does not run destructors
|
||||
// of automatic objects, so a guard would leave `airTime` dangling into an abandoned stack frame on
|
||||
// any assertion failure - and later cases dereference it (NodeInfoModule::allocReply). tearDown()
|
||||
// restores the global unconditionally instead. The instance is a function-local static so it
|
||||
// outlives the longjmp.
|
||||
//
|
||||
// Note it also parks channel utilisation at ~6000%, because logAirtime() credits that for every
|
||||
// report type. C14 gates on utilizationTXPercent() alone; do not reuse this for an
|
||||
// isTxAllowedChannelUtil() path, which would then pass for the wrong reason.
|
||||
static void useDutyCycleSaturatedAirTime()
|
||||
{
|
||||
static AirTime saturated;
|
||||
c14SavedAirTime = airTime;
|
||||
airTime = &saturated;
|
||||
saturated.logAirtime(TX_LOG, MS_IN_HOUR); // utilizationTXPercent() sums every bucket -> 100%
|
||||
}
|
||||
|
||||
void test_C14_duty_cycle_limited_reliable_send_remains_pending(void)
|
||||
{
|
||||
config.lora.region = meshtastic_Config_LoRaConfig_RegionCode_EU_868;
|
||||
config.lora.override_duty_cycle = false;
|
||||
initRegion();
|
||||
airTime->utilizationTX[0] = MS_IN_HOUR;
|
||||
useDutyCycleSaturatedAirTime();
|
||||
|
||||
meshtastic_MeshPacket initial = makeDecoded(LOCAL_NODE, REMOTE_NODE, meshtastic_PortNum_ROUTING_APP, SMALL_PAYLOAD);
|
||||
initial.id = 0xC14C14C1;
|
||||
@@ -1519,7 +1544,6 @@ void test_C14_duty_cycle_limited_reliable_send_remains_pending(void)
|
||||
TEST_ASSERT_EQUAL_UINT32_MESSAGE(1, pipelineRouter->pendingCount(),
|
||||
"duty-cycle rejection must retain the retry for when airtime is available");
|
||||
|
||||
airTime->utilizationTX[0] = 0;
|
||||
config.lora.region = meshtastic_Config_LoRaConfig_RegionCode_US;
|
||||
initRegion();
|
||||
}
|
||||
|
||||
@@ -37,24 +37,26 @@ constexpr NodeNum kTargetNode = 0x33333333;
|
||||
// a fresh requester for their "served again" step to avoid the per-requester window masking them.
|
||||
constexpr NodeNum kRemoteNode2 = 0x44444444;
|
||||
|
||||
// Telemetry hop exhaustion is gated on channel congestion (alterReceived checks
|
||||
// airTime->isTxAllowedChannelUtil/isTxAllowedAirUtil). Installs a global
|
||||
// airTime reporting 100% channel utilization for the enclosing scope.
|
||||
class ScopedBusyAirTime
|
||||
{
|
||||
public:
|
||||
ScopedBusyAirTime() : previous(airTime)
|
||||
{
|
||||
for (uint32_t i = 0; i < CHANNEL_UTILIZATION_PERIODS; i++)
|
||||
busy.channelUtilization[i] = 10000; // 10 s of airtime per 10 s period
|
||||
airTime = &busy;
|
||||
}
|
||||
~ScopedBusyAirTime() { airTime = previous; }
|
||||
|
||||
private:
|
||||
AirTime busy;
|
||||
AirTime *previous;
|
||||
};
|
||||
// INERT - commented out, not deleted. TrafficManagementModule holds no reference to airTime:
|
||||
// the gating this described went with exhaust_hop_telemetry / exhaust_hop_position, and
|
||||
// shouldExhaustHops() is now a compare of three members nothing sets. Writing the buckets did not
|
||||
// work either - the first accessor call takes AirTime's firstTime branch and memsets them, so this
|
||||
// reported 0%, not 100%. A revived version must fill them via logAirtime(); they are private now.
|
||||
//
|
||||
// class ScopedBusyAirTime
|
||||
// {
|
||||
// public:
|
||||
// ScopedBusyAirTime() : previous(airTime)
|
||||
// {
|
||||
// busy.logAirtime(RX_ALL_LOG, CHANNEL_UTILIZATION_PERIODS * 10 * 1000); // a full window
|
||||
// airTime = &busy;
|
||||
// }
|
||||
// ~ScopedBusyAirTime() { airTime = previous; }
|
||||
//
|
||||
// private:
|
||||
// AirTime busy;
|
||||
// AirTime *previous;
|
||||
// };
|
||||
|
||||
class MockNodeDB : public NodeDB
|
||||
{
|
||||
@@ -2307,7 +2309,7 @@ static void test_tm_nodeinfo_directResponse_fallbackUnsignedNotServed(void)
|
||||
*/
|
||||
static void test_tm_alterReceived_telemetryBroadcast_hopLimitUnchanged(void)
|
||||
{
|
||||
ScopedBusyAirTime busyChannel; // congestion present but exhaust is disabled
|
||||
// ScopedBusyAirTime busyChannel; // INERT: the module never reads airTime
|
||||
TrafficManagementModuleTestShim module;
|
||||
meshtastic_MeshPacket packet = makeDecodedPacket(meshtastic_PortNum_TELEMETRY_APP, kRemoteNode, NODENUM_BROADCAST);
|
||||
packet.hop_start = 5;
|
||||
|
||||
Reference in new issue
Block a user