Files
977b1d775c Dmshell (#11976)
* Very WIP dmshell

* Dumb fixes

* Interactive mode

* Try to re-request missed sequences

* troubleshoot dropped packets

* Don't firehose missing packets

* Attempt at better responsiveness

* DMShell heartbeat

* dmshell client serial support and tweaks

* Remove some dead code and LLM overcomplication

* Trunk

* Use RemoteShell in protobufs

* Make the DMShell tests compile

* Harden against possible memory overflows

* Minor cleanups

* No Child Left Behind

* simplify pt 1

* Refactor and Simplify

* Make new protobuf value consistent

* dmshell reliability tweaks

* Add real Lock handling on Portduino

* talking stick

* latest test changes

* Guard the DMShell TX-queue check against a null RadioLibInterface

runOnce() dereferenced RadioLibInterface::instance unconditionally. It is
null on any node whose radio is not RadioLib-backed - meshtasticd with
Lora.Module sim, and the serialHal path - so the first runOnce after a
session went active segfaulted the process.

* Revert the DMShell half-duplex turn-taking ("talking stick") scheme

Before: a DMShell session gated every transmission on a token. The server
only sent shell output while it held the turn; with no token it emitted an
RTS and waited (rate-limited to one per 250 ms) for the client to grant one.
Each grant, yield and re-grant was its own LoRa frame, so an unprompted burst
of shell output cost a full RTS -> grant round trip before the first byte
moved, and a long burst paid another yield/grant pair every 8 frames. On a
link where a single frame already takes a noticeable fraction of a second,
that turned interactive use into seconds of latency per exchange.

After: both ends transmit as soon as they have something to send, which is
how the module behaved before the scheme landed. The flags field stays in the
wire format but is written as 0 and ignored, so nothing in the protobuf
changes and a peer still running the turn-taking build is simply not answered
in kind.

The scheme was introduced in f25e3e893 and refined in 11a14bdda. Neither
commit is reverted wholesale, because both carry unrelated work that stays:

- 11a14bdda's NodeDB.h fix, narrowing the pre-hop drop policy to reject only
  HopStartStatus::INVALID, is untouched.
- The client's hop_limit fix (default 3 plus a --hop-limit flag) and its
  packet.decoded.bitfield assignment are re-applied on top of the revert;
  they address the far-end pre-hop drop, not channel access.
- 5e2d6d225's null guard on RadioLibInterface::instance is re-applied.

Removed with the scheme: the TURN_FLAG_GRANT/MORE/RTS constants and the
TURN_BUDGET_FRAMES, RTS_RETRY_MS and TURN_LINGER_MS tunables; the per-session
turnManaged, hasToken, lastRtsMs, turnDeadlineMs and turnFramesSent state;
applyTurnFlags, ptyHasOutput, serviceTurn, sendOutputFrame, sendTurnGrant and
sendRts; and on the client the TxIntent queue, the sender thread that owned
the token, and the --no-turn-taking, --turn-budget and --turn-reclaim flags.
Nothing else referenced any of it - no test covered the scheme.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_018Umi2iPd9BN7BWGFhinwkx

* DMShell: stop an unfillable gap becoming an endless retry storm

A lost frame could put a DMShell session into a retransmission loop that never
terminated, and the faster the modem preset the sooner it happened. Three causes,
all in the recovery path:

Both ends keep a replay history bounded at 50 *frames*, so the wall-clock span it
covers scales with the preset - about two minutes on LongFast, under seven seconds
on ShortTurbo - while the client's retry timers are fixed in seconds. Once a
requested frame aged out, resendFramesFrom() logged "not found in history" and
returned, telling the peer nothing. Neither side advances past a hole, so the peer
asked again every second until the five-minute idle timeout. Report the eviction
and close the session instead: the request is unanswerable, and saying so turns a
dead session into a diagnosable one.

Every frame arriving above a gap produced its own replay request, and each request
cost the sender a duplicate replay, so one loss cost as many extra transmissions
as the sender had frames in flight. Damp the requests per sequence number, over an
interval derived from getPacketTime() rather than a constant, since one frame's
airtime spans 100 msec on ShortTurbo and over 2 sec on LongFast. A different gap
is still reported immediately, so recovery gains no round trip. The client backs
its own retry off exponentially to 30 sec for the same reason.

A teardown could sit behind a gap: CLOSE and CLOSED both went through the ordering
check, so a session ending because a gap could not be filled was itself buffered
behind that gap. Both are now acted on out of band. ERROR deliberately stays
ordered - it is not always terminal, and skipping its sequence number would open a
gap of its own.

Also drops a sendAck() whose replay field underflowed to 0xffffffff when called
with no argument, which the peer read as a request for a sequence number that had
never been sent.

The sequence and history bookkeeping moves to DMShellRecovery.h, which takes the
time as an argument and pulls in no platform headers, so test_dmshell_recovery
covers it - including the damping boundaries and the millis() wrap.

DMSHELL_LEGACY_RECOVERY=1 on the node, paired with --legacy-recovery on the
client, restores the previous behaviour on the same build so a session can be
measured with and without the fix.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: act on the first hardware measurements of the retry storm

A two-radio bench run on US/ShortTurbo (473 frames one-way, plus a short
bidirectional run) measured what the previous commit was guessing at, and
three things follow from it.

The client could not start at all. config.proto imports field_metadata.proto,
which was missing from required_protos; protoc resolves it via -I for
compilation but only emits a _pb2 module for files named on the command line,
so config_pb2 imported a module that was never written. Named it.

The missing-sequence backoff was tuned for the wrong failure. It doubled to a
30 s cap on the theory that each repeat was evidence the peer could not fill
the gap. On hardware every repeat was a collision on a gap that did fill: 8 of
8 recovered, worst case 5 attempts, zero unfillable. Doubling from the first
repeat made those recover 2-3x slower, which is plainly visible in an
interactive shell. Hold the base interval for the first four attempts and only
grow after that, with an 8 s ceiling - the ceiling only has to bound the
residue now that an evicted frame is reported in one round trip.

Eviction turns out to be symmetric, so the client needs the same report the
firmware got. prune_sent_frames would have made the client's ring hold only
unacked frames, but its one call site is commented out, so tx_history is a flat
last-50-sent ring exactly like txHistory and can be outrun the same way. When
the peer asks for a frame the client no longer holds, close the session and log
replay_evicted instead of logging replay_unavailable and leaving the peer asking
until the idle timeout. --legacy-recovery keeps the old silent behaviour for the
A/B.

Also document the contiguity invariant DMShellTxHistoryWindow derives its
retained range from, at the one choke point every remembered frame passes
through.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: bound unacknowledged output instead of the replay ring

Hardware runs at both ends of the preset range showed the replay-eviction
failure is ratio-specific, not preset-specific: whichever side has the higher
frame rate outruns its own ring first. On ShortTurbo the server sends ~3
frames/s against a keystroke every 1.5 s, so the server's ring goes; on
LongFast the client sends many small frames against few large ones, so the
client's goes, and a LongFast run logged 106 unanswerable replay requests with
zero firmware evictions. Enlarging or time-bounding a ring on one side would
therefore have moved the failure to the other side rather than fixing it.

Bound the outstanding data instead. The server tracks the peer's cumulative
receive cursor and stops generating new output once four frames are
unacknowledged, so it can never get more than a window ahead of a gap and can
always still answer the replay request for it. Ring size stops mattering, at
any preset, on both sides.

This also removes the zombie session without touching the idle timer. The
timer could never fire because the server refreshed it with its own output
while the send path was unbounded; a sender blocked on a closed window stops
sending, so it stops refreshing, and the existing five-minute timeout finally
applies to a peer that has vanished. The self-refresh was only a bug in the
absence of a bound.

The window needs the peer to acknowledge, and on a one-way stream the client
transmitted nothing at all - its heartbeat is suppressed while inbound traffic
keeps arriving - so it now sends a bare ack every second in-order frame. The
ack interval must not exceed the server's window or the two deadlock until the
heartbeat breaks it; both are configurable so the pair can be swept, and
DMSHELL_TX_WINDOW=0 or legacy mode restores the unbounded behaviour for the
A/B on one build.

Liveness and the flow-control cursor now come from every authenticated
in-session frame rather than only those passing the ordering gate. An
out-of-order frame still proves the peer is alive and still carries a valid
cursor, and during a gap it may be the only kind arriving.

Also raise the OPEN_OK wait onto its own --open-timeout. A lost OPEN costs a
full frame airtime, ~2.2 s on LongFast against ~0.1 s on ShortTurbo, and a
measured LongFast session needed 150 s to open against a 10 s default.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: log window open/close transitions

The window opens and closes several times a second, so per-poll logging would
drown the log, but with no line at all there is no way to tell from a run
whether the bound ever engaged - which is the first thing to check on the next
hardware run. Log only the transitions, with the outstanding count.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: retransmit from the sender when the window latches shut

The window stopped the retry storms and cut the frames needed per delivered
line by 60x, but it introduced a silent permanent stall, reproduced on
hardware in both runs at around 20 s: the window closes one last time and
never reopens, while frames keep arriving from the peer and the session stays
open looking healthy.

The cause is that recovery was entirely receiver-driven, and the window
removed the stimulus it depended on. A lost frame freezes the peer's
cumulative cursor at the last in-order sequence number. The sender then fills
its window against that frozen cursor and stops. From there nothing can make
progress: the peer only asks for a replay when a frame arrives carrying a
higher sequence number, and with the window shut none ever does. The peer's
own INPUT frames carry the frozen cursor, and neither the INPUT path nor
anything else on the ordered path triggers a replay - only ACK and PING do.

So the sender now takes responsibility for its own unacknowledged data, which
is the "no sender-side retransmit timer" gap named in the original analysis.
While the window is shut it retransmits the frame the peer's cursor says is
missing, one round trip apart, derived from the modem config the way replay
requests already are. It resends the missing frame rather than something new,
because sending something new would push the sender further ahead of the gap,
which is what the window exists to prevent.

The client had a second, independent hole in the same path. Its heartbeat is
what makes the server retransmit via the PING handler, but heartbeat_due keyed
off traffic in either direction, so the client's own keystrokes reset it -
typing faster than HEARTBEAT_IDLE_DELAY_SEC suppressed the heartbeat
completely. Measured: zero heartbeats in 60 s while typing every 1.5 s into a
stalled session, against four when idle. An interactive user was silencing
their own recovery. It now keys off inbound silence alone, so a healthy stream
still sends none.

Either change alone breaks the deadlock; both are correct independently.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: stop retransmitting to a peer that has gone away

Bounding the outstanding data left one unbounded behaviour behind. A sender
whose window is shut repeats the frame the peer's cursor says is missing, and
nothing ever ends that: it stays under the replay ring so nothing is evicted,
and the idle timeout keeps being refreshed while the peer sends anything at
all. On the bench the session became a zombie twice, repeating one sequence
number 88 and 89 times and still going 67 s after the client had exited,
because the client's teardown did not survive the link.

A healthy link on the same rig needed at most 11 repeats of a single sequence
number, so the allowance is 25 per sequence number, reset whenever the peer's
cursor advances. It is a frame count rather than a duration because the
retransmission interval already derives from the modem config, so it scales
with the preset by itself - about 11 s on ShortTurbo, 114 s on LongFast. When
it runs out the session closes as peer_unresponsive: the evidence says the
peer vanished rather than that the link failed. DMSHELL_MAX_RETRANSMITS=0
restores the old behaviour so one build can still be measured both ways.

Also flush the PTY's pending output when a peer's input carries the terminal's
interrupt character. A local line discipline does this for free; over LoRa the
~15 KiB the PTY holds is about 77 frames, 17 s of airtime on ShortTurbo and
nearly three minutes on LongFast, all of it output the user has just
cancelled. The flush happens before the interrupt is written through, so the
shell's own response to it survives.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: bound unacknowledged input as well as output

The send window bounded the server's output and left the client's input
unbounded, so only half the original failure was fixed. Measured on hardware:
at ShortTurbo the server outran its own replay ring and the window fixed it,
but at LongFast - where keystrokes are emitted far faster than the server
drains them - the client outran its ring instead and the session still died
with replay_evicted seq=5 while its own ring had moved on to 12. Whichever end
has the higher frame rate loses, so both ends need the bound.

The client now tracks the server's cumulative receive cursor from the ack_seq
and last_rx_seq that already ride on every inbound frame, holds typed input
locally once four frames are unacknowledged, and sends it in order as the
cursor advances. Overflowing the local hold is reported rather than silent,
because the bytes are the user's.

Bounding the sender re-creates the latch it created on the server: with the
window full the server never sees a sequence number above the gap, so it never
asks for the replay that would reopen us, and its only trigger is an arriving
frame. So the client also repeats the frame the cursor says is missing while
the window is shut, escalating the interval the way a replay re-ask does - it
cannot read the modem config the way the firmware can - and gives up after 25
repeats, matching the firmware's bound.

For that to work the server has to acknowledge input even when it has no
output: a keystroke a program swallows would otherwise leave the client's
window full against a silent peer. So the server sends a bare ACK carrying its
cursor after two in-order frames with nothing of its own to send, and answers
a repeated frame with one directly. A replay request carries the same cursor
and counts as that answer; a damped gap stays silent, which is what the
damping is for. Frames the server originates already carry the live cursor, so
a busy stream sends no extra frames at all.

Input sends are serialised across the input and heartbeat threads: both flush
the held bytes, and two takes interleaving with two sends would put the user's
keystrokes on the wire out of order.

DMSHELL_INPUT_WINDOW sizes the client bound and 0 disables it, so one build can
still be measured both ways; --legacy-recovery disables it too.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: fix the window-transition counts

The client's input-window transition logging was misleading. Both lines lived
inside the flush loop, which only runs while typed bytes are queued, so a
window that reopened with an empty queue logged nothing and a run ended up with
a close that had no matching reopen. That reads as a latch and is not one. The
transitions are now recorded on every service tick, so the counts describe the
window rather than the typing. The retransmit line also carries the attempt
number and the current interval, which is what separates a link recovering
slowly from one not recovering at all.

(The client half of 8384c66 on the bench branch; its radio-side scan logging
stays out of the DMShell branch.)

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: name the op and seq on an inbound frame

"Received a DMShell message" could not answer the question that matters when a
gap will not close: whether the peer's replay arrived and was discarded, or
never arrived. It is logged before the session and ordering checks, so a frame
rejected by either still shows up, which is what makes the two cases separable
from one log stream.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: hold out-of-order frames instead of discarding them

The receiver had no reorder buffer at all. A frame arriving above a gap was
dropped even though it arrived intact, so the peer had to send it again once the
gap filled - a round trip per frame that was already in hand. Measured at
LongFast: the sequence numbers the receiver kept asking for had arrived a dozen
times each, and the session advanced roughly one frame per round trip while
delivering 24 lines in 300 s. Read as loss, it looked like a 5% link; it was
frames arriving and being thrown away.

Frames above the gap are now held, eight slots deep - twice the peer's default
send window, so a well-behaved peer can never fill it and an unbounded one is
bounded here - and delivered in order the moment the gap fills. When the buffer
is full the highest sequence number is the one dropped, because the gap fills
from below and the lowest are needed soonest.

Two things fall out of it. The op handling is now applySessionFrame(), reached
from the radio and from the buffer alike. And a replay request is suppressed for
a sequence number already held: the ordering window deals only in sequence
numbers it has passed to the session, so it cannot know what the buffer has, and
asking for a frame we are holding is pure channel load.

Simulated against the discarding version across loss rates from 5% to 40%, this
roughly halves the transmissions needed per frame delivered - 2.1 to 1.1 at 10%
loss - with the larger saving in wall-clock time, since each frame no longer
costs its own round trip.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: send with hop_limit 0, like the firmware already does

A non-zero hop limit on our frames arms two mechanisms in the peer's
firmware that this protocol wants nothing from, and both cost airtime in
the direction that matters.

NextHopRouter::sendWithNextHop starts its own relay retransmissions for a
packet whose gate it passes - (hop_limit > 0 || want_ack) with a known
next hop - so the sending node repeats each of our frames up to twice
more, then floods the last attempt and resets the learned next hop. Those
repeats reuse the packet id, so the destination discards them in
shouldFilterReceived as dupes after paying for them on the air; they
never reach DMShell, which is why they were invisible in per-sequence
arrival counts.

To stop them, ReliableRouter::sniffReceived answers every frame whose
next_hop names it with a 0-hop routing ACK. That is one extra
transmission per input frame, from the peer, competing on a half-duplex
channel with the shell output it is trying to send us.

The firmware end of the session already sends with hop_limit 0, so
DMShell is a direct-neighbour protocol in both directions either way, and
the asymmetry bought nothing. hop_start 0 survives the receiver's pre-hop
drop policy because classifyHopStart accepts it when the Data bitfield is
present, and perhapsEncode sets that on every locally-originated packet -
which is what makes the firmware's own hop_limit 0 frames arrive here.

--hop-limit 3 restores the old behaviour for a same-binary comparison.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: time input retransmissions off the measured round trip

The input retransmission reused the replay re-ask escalation: a flat 1 s
for four attempts, then doubling to an 8 s ceiling. One second is shorter
than a single frame's time on air at LongFast (~2.2 s), so a repeat went
out while the frame it was repeating was still being transmitted, and
another behind that. Worse, the deadline was armed by the poll that
noticed the frame rather than by the frame itself, and advancing the
peer's cursor cleared it - so the moment one frame was acknowledged, the
next one, possibly sent milliseconds earlier, was repeated on the
following poll. Measured at LongFast over 300 s: 117 retransmissions and
105 arrivals for 22 distinct sequence numbers, against 17 replay requests
from the peer. The duplication was almost entirely ours.

Two changes, both of which need only what this side can observe:

A frame is never repeated before it has been outstanding for a full
interval. SentShellFrame now carries the time it was last handed to the
API, and the first deadline for a sequence number is measured from that
rather than from the tick that noticed it.

The interval itself comes from the link instead of a constant. Every time
the peer's cumulative cursor passes a frame we sent, the time from
sending it to seeing that is folded into a smoothed estimate, and the
interval is twice the estimate, floored at the old 1 s and capped at the
old 8 s. This side cannot see the modem preset, so measuring beats
deriving, and the OPEN/OPEN_OK exchange supplies the first sample before
any keystroke is sent. The replay re-ask uses the same base, for the same
reason: it was asking again before an answer could arrive.

The run bound is untouched: still exactly MAX_INPUT_RETRANSMITS repeats
of one sequence number before the session is declared unrecoverable, and
a frame that has aged out of the ring still fires immediately.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: report the round trip the interval is derived from

The retransmission interval is now measured rather than constant, so a run
has to be able to show what it measured. Reporting it only when a
retransmission happens would describe the traffic instead of the
mechanism - the same mistake that made an earlier input-window diagnostic
read as a latch - so the estimate is reported from the poll, which runs
whether or not anything is queued.

The first sample goes to the transcript as well as the replay log, since
it is what tells the operator whether the interval matches the preset in
use, and it lands before any keystroke is sent. After that it is reported
again only once it has moved by a quarter, which on a settled link is
never. The retransmission line names the estimate alongside the interval.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* Lock: make the Portduino mutex implementation conditional on Portduino

Two independent build breaks, both from de6269c6 "Add real Lock handling on
Portduino", and both invisible here because every build on this branch has
been `-e native`.

Before: `-e rak_wismesh_pocket` fails at `src/concurrency/Lock.cpp:4` with
`logging.h: No such file or directory`. That header belongs to the Portduino
framework and the include was unconditional, so it broke every target that
is not Portduino: the whole nRF52 family, ESP32 and RP2040 (which take the
FreeRTOS branch and never needed it) and STM32WL. Nothing else in the tree
includes it, and nothing in this file needs it - `LOG_INFO`, `LOG_WARN` and
`console` all arrive through configuration.h, which pulls in
DebugConfiguration.h and SerialConsole.h.

Removing it exposes the second break, which is the real one. The pthread
implementation sat behind a bare `#else`, so it applied to every target
without FreeRTOS - and that set is not "Portduino", it is "Portduino plus
STM32WL". STM32WL builds on arm-none-eabi newlib, which has no pthread.h at
all, so `pthread_mutex_t mutex;` in the header fails to name a type for every
translation unit that includes Lock.h. Before de6269c6 that branch was
no-ops, so nothing outside Portduino ever relied on real locking there.

After: the split is three-way. FreeRTOS keeps its semaphore, Portduino gets
the pthread mutex, and anything else falls back to the upstream no-ops. The
header also includes pthread.h itself on the Portduino path instead of
relying on Arduino.h to have pulled it in.

Verified by compiling Lock.cpp three ways against stand-ins for
freertosinc.h and configuration.h: the FreeRTOS path, the Portduino path,
and a target with neither, the last one with an include path that makes
pthread.h a hard error so it stands in for newlib. All three build clean
under -Wall -Wextra. The same harness reproduces both original failures
exactly. This is not a substitute for CI, which is still the first real
build of the affected targets.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* Lock: stop logging on every mutex acquisition on Portduino

Before: `Lock::lock()` emitted `LOG_WARN("Lock")` on every successful
acquisition, and `LOG_INFO("Attempt to lock an already locked Lock!")`
whenever the mutex was already held. There are ~300 lock sites in the tree,
and they include the hottest paths on the device: spiLock around every SPI
transaction, cryptLock around every encrypt and decrypt, and deferredLock on
every received packet. So each of those paid a formatted write to the console
before doing its work.

That matters beyond noise on this branch specifically, because the open
question here is radio-thread latency - a false preamble is abandoned after
~8 ms at ShortTurbo, and one CH341 SPI transaction was already measured at
4-8 ms. Logging inside the lock that serialises those transactions puts I/O
on exactly the path being measured, so it has to go before the next round's
numbers mean anything.

The already-locked line also could not do what it claimed. `locked` records
that the mutex is held by somebody, so an ordinary contention between two
threads - the normal case for spiLock - triggers it just as readily as a
thread re-entering its own lock. It logged before blocking, too, so on a
genuine recursive lock it printed and then hung.

After: the Portduino implementation locks and unlocks, and says nothing. The
`locked` field goes with the lines that read it; nothing else used it.

Recursive-lock detection would be worth having, but it needs the owning
thread recorded and compared against the caller, not a bare held flag, and
that is a deliberate change rather than something to slip into a build fix.
Reverting this commit restores the old lines without touching the build fix
underneath it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* dmshell client: add --peer-log to capture the node's own log

Measuring the radio's own timing on a board whose logs do not reach a serial
console meant choosing between running the session and capturing the log,
because both want the single USB port.  There was no need to choose: the log
already rides the stream the client is reading.  RedirectablePrint's log path
calls log_to_serial for every line, SerialConsole::log_to_serial hands it to
StreamAPI::emitLogRecord, and that writes it as FromRadio.log_record on the same
stream the client takes packets from.  The client was parsing those frames and
discarding them.

--peer-log <file> writes them out instead, one line per record carrying the
local clock, the node's own clock, the level, the thread and the message.  The
local timestamp is what lines a capture up against the client transcript and
against the other node's log.  Records are dropped, as before, when the option
is absent.

The node only emits them when config.security.debug_log_api_enabled is set,
which defaults off; the help text says so.  The write path is called from the
reader loop and swallows OSError, since a full disk should cost the log rather
than the session, and it holds its own lock because a trace-level node produces
thousands of lines a minute.  Log records deliberately do not refresh the
inbound-activity clock: they come from the local node, and letting them stand in
for peer traffic would suppress the heartbeat that drives recovery.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: report a session's traffic when it ends

Every measurement round so far has counted dropped and resent frames by
grepping a session log by hand, and in round 7 that produced a median over two
differently-selected populations because three different log lines carry a
last-look figure and only two of them belong to the same deadline. Counting in
the client removes that class of error from the measurement.

--stats prints a summary to stderr when the session ends; --stats-json writes
the same object to a file, which is what an A/B actually needs. Both run from
the same finally block that closes the peer log, so a session that timed out or
was interrupted still reports - that is the run whose numbers matter most.

The counters hook the paths every frame already passes through rather than
adding new ones: note_received_seq classifies inbound frames, send_shell_frame
is the single transmit choke point, and log_replay_event already sees the whole
replay lifecycle. That last one counts before taking its lock, because the write
it guards is skipped when no --replay-log was asked for and the counts must not
depend on a flag.

Two of the numbers are the ones worth comparing between runs. Inbound loss is
the gap between the peer's highest sequence number and what we delivered in
order, which is observable from this end; outbound loss is not, so the
retransmission count stands in for it. transmissions_per_frame is every frame
handed to the radio divided by the frames we originated, so it prices
retransmissions, replays and acks as the airtime they cost.

The counters are cumulative for the session and sit behind their own lock.
input_retransmits and missing_request_attempts deliberately stay as they are:
they reset per sequence number and describe the current gap, not the run.
Distinct gaps are counted on insertion into requested_missing_seqs rather than
per request, since the set drops a sequence number once it is replayed and the
ratio between requests and gaps is the damping working.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: stop logging at WARN on every frame

Three lines on the hot path were left at WARN: both PTY reads, which fire once
per OUTPUT frame, and the packet-building line in sendFrameToPeer, which fires
once per frame of any kind. WARN is not filtered by log level on any normal
build, and when debug_log_api_enabled is on these also ride the API stream to
whatever client is attached.

This matters for what comes next rather than in principle. The next measurement
is dropped and resent frames under an interactive workload, where the thing
being measured is per-frame cost, and console I/O per frame is the same defect
as the per-acquisition lock logging removed in 59cded1 - which was measurably
load-bearing when it went.

TRACE rather than DEBUG, because the information is per-frame protocol detail
and MESHTASTIC_TRACE_LOGGING already defaults on for Portduino with a runtime
level gate, so a diagnostic run can still ask for it and an ordinary run pays
nothing. The recovery lines stay at WARN deliberately: they are damped, they
are rare, and they are what a measurement run counts.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: separate the resend count from total airtime overhead

transmissions_per_frame was every frame handed to the radio over the frames we
originated. That is a real quantity but the name invites reading it as a resend
ratio, and it is not one: in a session where the server is streaming output our
ACKs dominate it, so it can sit at 4.0 on a run with no loss at all. Renamed to
transmissions_per_originated_frame, and the printed line now says what it is.

The number actually wanted is resends, counted in note_frame_resent, which is
the single point both our replays for the peer and our own input
retransmissions pass through. resend_ratio is that over the frames we
originated.

Also fixes an undercount that the old name hid. note_received_seq returns "gap"
for a frame below the cursor when a gap is already open, because a replay
request is the action that frame triggers - so counting the outcome alone
missed the peer's resends during exactly the periods when the peer is
resending. Inbound frames are now counted twice over: what the frame is, judged
against the cursor before it moved, and separately what we did about it. So
duplicates means the peer put that frame on the wire twice, which with resends
above gives loss visible from both directions.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: let an OUTPUT frame carry the ack when the window is open

Every frame already carries ack_seq, and sendFrameToPeer() zeroes
framesSinceOutbound because of it, so an OUTPUT frame settles the flow-control
debt for free. runOnce() was not taking advantage: the bare-ACK check ran ahead
of the PTY read and returned, so whenever output was waiting the server sent an
ACK and then the data, two frames carrying one cursor, with the data delayed by
a scheduler pass.

That happens more than the immediate read in applySessionFrame() suggests. The
read there runs the instant the input is written, so a shell that has not
produced its echo yet returns nothing, and the echo lands in runOnce() on the
next pass - where the debt is now due.

The bare ACK stays ahead of the window gate for the case the comment there
describes: while our own window is shut we retransmit, a retransmission carries
a stale cursor, and a bare ACK is then the only thing that keeps the peer's
window open when both directions are blocked at once. It is now limited to that
case, and the open-window case is settled after the read, where the counter has
already been cleared if anything went out. Guarded on session.active, because
the read loop also breaks there after closeSession() on EOF or a read error.

No behaviour changes when the PTY is empty: the ACK goes out in the same pass it
used to, just at the end of it.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell client: bound how long input can be held before it goes on the wire

The input batch window restarts on every byte, so it is an idle-gap timer, not
a window. Above one character per 0.5 s each keystroke refreshes the deadline
and nothing leaves until the 64-byte cap or an Enter. Driving the loop as
written at 5 char/s with no Enter gives 50 bytes per frame and a maximum hold
of 12.6 s: twelve seconds of typing with no echo, because the frame carrying it
had not been sent yet.

Keep the per-byte reset, which is what makes burst coalescing work, and cap the
total wait at 2 s from the first byte. Measured on the same driver: 5 char/s
with no Enter goes from 50 bytes and 12.6 s to 10 bytes and 2.0 s; 5 char/s
with Enter every ten characters is unchanged at 10 bytes, because the break on
\r already bounded it; 20 char/s still coalesces to 40 bytes per frame; and one
character per 1.5 s is untouched at one byte per frame and a 0.5 s hold, which
no client-side batching can improve on when the keystrokes are 1.5 s apart.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: recover a lost OPEN_OK instead of waiting out the open timeout

Round 10 on hardware: the client sent OPEN, heard no OPEN_OK, and waited its
full 180 s --open-timeout, while the server had accepted the session and was
streaming the shell's prompt to nobody.

It could not recover, and not only because nothing retried. OPEN_OK is always
seq 1, and a replay request for seq N encodes as last_rx_seq = N - 1, which
both ends read as "no request" when it is 0. So the client saw the gap when
seq 2 and 3 arrived, and its request for seq 1 went out looking like a bare
ACK. A lost OPEN_OK was unrecoverable by design.

The client now repeats its OPEN while no OPEN_OK has arrived, 5 s doubling to
30 s, with the same session id and seq every time. A naive repeat would have
been worse than none: openSession() preempts the running session, so the
retry would fork a second shell over the first and discard its output. The
server now classifies an OPEN first (classifyOpen() in DMShellRecovery.h):
a repeat of the running session's id from its own peer resends OPEN_OK, and a
new id or another peer still preempts, as before. A repeat is ignored once
the peer's cursor shows it has OPEN_OK, because answering it would replay
seq 1, which on a long session has left the history and would close the
session as replay_evicted.

If the client does give up, it now sends CLOSE, which the server acts on out
of order, rather than leaving the session streaming until its own bounds
notice. Legacy recovery on either end keeps the old single OPEN, so the same
binaries still give an A/B baseline. The retry count is reported as
recovery.open_retries.

Six new cases in test_dmshell_recovery. classifyOpen() compiled and checked
standalone here; the module and the suite were not built, as pio cannot run in
this environment.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: time the server's retransmission per frame, from measured ack latency

Round 10 on hardware: arm C, a bulk transfer with zero loss, had 34% of
the frames reaching the client be copies. The server's window-shut
retransmission had the two defects the client fixed in 0246db2:

- The wait was measured from the poll, not the frame. Every cursor
  advance cleared nextRetransmitMs, so the next unacknowledged frame,
  queued moments earlier and often still waiting for the radio, was
  repeated on the very next poll.
- The interval was one derived round trip (two max-length frames plus
  250 ms, ~658 ms at SHORT_FAST). The acknowledgement it waits for
  queues behind up to a window of our own frames, each sitting out a
  CSMA backoff, so it arrives later than that.

Each frame now carries the time it was last handed to the radio, first
send or resend. A cursor advance samples the latency to the frame it
reached, smoothed by a quarter exactly as the client does, and the
interval is twice that, floored at the derived round trip and capped at
REPLAY_REQUEST_MAX_MS. A frame is repeated only once that interval has
passed since its own send.

Also clears the replay history when a session opens. Entries match on
seq alone and every session numbers from 1, so a repeated OPEN could be
answered with the previous session's OPEN_OK.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: make the OPEN retry testable, and log the retransmit interval

Round 11 on hardware confirmed the retransmit-timing fix but never
exercised the OPEN retry: no OPEN_OK was lost, so open_retries stayed 0.
The incident it guards against appeared once in a whole session.

--drop-open-ok N discards the first N OPEN_OK frames before any
accounting, as a frame lost on air is, and counts them in
recovery.open_ok_dropped. The client's repeated OPEN then has to recover
the session through the firmware's repeated-OPEN path.

The window-shut retransmit line now carries the interval it waited and
the ack latency estimate behind it. Round 11 measured a median of 5.8 s
from window close to first retransmit, which implies an estimate near
3 s at SHORT_FAST; this shows it directly.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* dmshell_client: stamp --peer-log lines to the millisecond

The host threw the resolution away: strftime gave whole seconds, and LogRecord.time is seconds too.
The stamp is still the arrival time on this host, so it carries the node's API and serial latency.
Measured against 448 frames with known air time, 79.5% of records arrive within 2 ms and 83.3%
within 15 ms, with a queueing tail (p90 +44 ms, p99 +152 ms).

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* DMShell: keep a sessionless ERROR out of the new session's sequence

A frame from an earlier run, still on air when a new client started,
reached the server with no session open. The server rejected it with an
ERROR that took the next sequence number, seq 1, and session id 0. The
new client, still waiting for its OPEN_OK, took that ERROR in order as
seq 1, then dropped the real OPEN_OK (also seq 1) as a duplicate and
acknowledged it. The acknowledgement moved the server's cursor for the
peer, so every repeated OPEN after that read as a late copy, and the
session never opened. Seen twice on the bench, in rounds 30 and 31.

Both ends are fixed; either alone breaks the chain.

- The server sends an ERROR for a frame outside any session of its own
  unsequenced (seq 0), unremembered, echoing the frame's session id.
- The client ignores any frame whose session id is not its own, surfacing
  an ERROR as an event but touching no sequence or cursor state.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

* Fix the Windows/macOS build and the native test crash

The Portduino Lock now takes a real pthread mutex instead of doing nothing,
so a null spiLock is a null dereference rather than a harmless no-op. Only
three of the 89 native suites call initSPI(), so every suite that builds a
NodeDB segfaulted in Lock::lock(). Give spiLock static storage on Portduino
so it is live before initSPI() runs; the embedded targets keep the lazy
construction, since their semaphore cannot be created from a static
initializer.

DMShell drives a login shell through forkpty() and includes <pty.h>, which
the Windows and macOS Portduino hosts do not have. Gate the module on
Linux rather than on ARCH_PORTDUINO alone.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Address the CodeRabbit review

Lock::lock(timeout) on Portduino now honours its deadline: poll
pthread_mutex_trylock to the deadline, since pthread_mutex_timedlock is not
portable to macOS, and return false rather than blocking for good. A zero
timeout no longer waits at all.

DMShell keeps the bytes a nonblocking PTY would not take. write() on a
nonblocking fd may accept less than it was given, and the receive cursor has
already moved past those bytes, so the tail is queued and retried ahead of
any later input rather than being dropped.

A killed shell child is now reaped. SIGKILL ends the process but does not
collect it, so the pid is kept until waitpid() confirms the exit instead of
being cleared straight after the signal.

PING replay uses the highest cursor the peer reported, as
notePeerReceiveCursor() already does. A stale last_rx_seq beside a higher
ack_seq asked for a replay from a frame the history had dropped, which ended
a session the peer was perfectly happy with.

A sequenced frame that never reaches the air gives its number back. The
callers draw from nextTxSeq before sendFrameToPeer(), so a failed packet
allocation or encode left a hole no replay could fill. The encode path also
leaked the packet it had allocated.

In the client, the config handshake now applies --timeout to each blocking
read, so a peer that never answers no longer hangs it for good, and a
non-TTY stdin waits for its queued input to be acknowledged before it sends
CLOSE - the server handles CLOSE ahead of any gap, so piped input longer
than the window was being truncated in silence.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Reformat with the pinned clang-format

Trunk Check runs clang-format 20.1.0 over whole modified files, and these two
spots predate this round of changes: the ternary in handleReceived(), a
LOG_WARN argument wrap, and one trailing comment in the recovery test. No
code changes.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Keep every unreaped child, and never take the lock late

A close arriving while the previous child was still dying overwrote the one
pending slot, so that pid was lost and its zombie stayed. Keep a small set of
pending children instead, each held until waitpid() confirms its exit.

The timed lock checked its deadline before sleeping, so a mutex that came
free during the sleep could be taken just past the deadline. Check
immediately before each retry instead.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Give the native tests a cryptLock

The same class of crash as spiLock, one layer further in: only Router's
constructor creates cryptLock, and a suite can reach the admin and crypto
paths that take it without ever building a Router. test_module_config died
in AdminModule::setPassKey for exactly that reason. Create it in
initializeTestEnvironment(), which 86 of the 89 suites call.

Router's constructor then has to stop asserting that the lock is null.
It now uses the idiom on the next line of the same constructor, the one
routingAuthCacheLock has always used: nothing in src/ ever deletes the
lock, so one that already exists is the process's only one.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Never drop a pending child pid

With every slot full, a further close dropped the pid and left a zombie.
Wait for the child in the first slot instead: it has had SIGKILL, which
cannot be caught or blocked, so it dies unless it is stuck in the kernel.
A blanket waitpid(-1) would be shorter but would swallow the exit status
of the popen() in PortduinoGlue.

reapChildIfExited() now treats ECHILD as the shell having exited, so a
child collected elsewhere still ends the session rather than leaving it to
the five-minute idle timeout.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Link the DMShell recovery suite

test_dmshell_recovery ERRORED at link with undefined references to setup
and loop from portduino's main.cpp. Portduino declares both extern "C",
and this is the only suite whose includes never reach a platform header:
DMShellRecovery.h deliberately pulls in nothing but mesh/Throttle.h so it
can be driven from a native test, and TestUtil.h stops at unity.h. The
definitions were therefore mangled and main() could not find them.

Include Arduino.h, as test_throttle already does.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Stop the test mocks deleting cryptLock

The mock routers freed the global crypt lock in their destructors, each
with a comment pointing at the reason: Router's constructor asserted the
global was null before allocating it, so a suite that built more than one
router had to hand it back. That assert is gone - the constructor now
reuses an existing lock, the same idiom as routingAuthCacheLock on the
next line - and nothing in src/ has ever freed it, so these deletes now
free a lock the mock does not own and leave the global null behind them.

test_admin_radio is where that bites: ~HamModeMockRouter runs from
tearDown, and the next test reaches AdminModule's receive path, which
takes LockGuard(cryptLock) - a null dereference now that the Portduino
Lock is a real mutex. The other six were the same hazard waiting for a
suite to add a test after them.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Bind client frames to the selected peer, and bound its reorder buffer

Two client-side holes CodeRabbit's architecture pass kept on its list.

The reader matched a frame to the session on the session id alone, which
is carried in the frame and so is not an identity: any sender whose
decoded packets reach this stream could match it and then write to the
terminal, move the cursors or close the session. Drop anything not from
the node --to selected.

The out-of-order dictionary had no bound, unlike the server's eight fixed
slots, so a peer that never filled a gap grew it for the life of the
session. Bound it at the same eight and evict by the same rule: the
lowest sequence numbers are needed soonest, so the highest held is the
one worth losing, and only to something lower than it.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Never signal a reaped pid, and never silently lose input

Two findings from CodeRabbit's pass over 401b7a6, both real.

reapChildIfExited() calls closeSession() once waitpid() has collected the
shell's exit - but closeSession() then sends SIGTERM to session.childPid,
which at that point names a pid the kernel is free to have handed to an
unrelated process. Clear the pid before closing, so nothing signals it.

A rejected INPUT answered with an ERROR. The frame's sequence number is
already acknowledged by the time the write is attempted, so the peer will
never send those bytes again and no replay can recover them; the client
treats ERROR as non-terminal and carries on with a hole in the command
line. Close the session instead, which for a shell is the lesser harm.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Bound the handshake frame scan by its deadline

--timeout was enforced per read, not over the scan for a frame marker. A
wrong port or a noisy serial line delivers bytes steadily, so every read
returns inside its own timeout and recv_stream_frame() never comes back to
the caller's clock - the handshake then runs past the deadline it was
given. Pass the deadline in and check it each time around the scan.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Hold the handshake deadline over a whole frame, and assert the payload

recv_stream_frame() checked the deadline only while scanning for the start
marker. A sender that trickles returns a byte inside every read timeout,
so a frame arriving one byte at a time still ran past --timeout; the
deadline now reaches recv_exact() and is checked per chunk.

The RemoteShell round-trip helper took a payload and never encoded it, so
the INPUT and CLOSE cases asserted an empty body and would have passed
against a serializer that dropped their bytes. Copy it in and assert it
back.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* Three narrow failure cases around the new timed lock

ReentrantSpiLock::lock(timeout) recorded this thread as the owner whether
or not the underlying lock was taken. That was harmless while Portduino's
timed lock could not fail - it blocked until it had the mutex - but this
branch gives it a real deadline, so a false result would leave the thread
passing the reentrancy check without holding the mutex and unlocking one
it never took. Claim ownership only on success.

Lock::Lock() ignored a failed pthread_mutex_init, leaving every later use
of the mutex undefined. Abort, as the FreeRTOS branch beside it does.

The client set the transport timeout once before reading a frame, so a
frame arriving near the deadline could run nearly a full read timeout past
it. recv_exact() now shortens the transport's timeout to what is left.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VeY5PczVYsxWNZhE2Cx4Sv

* DMShell client: bound a torn stream frame, and count the resyncs

Bench fixes that ran on every round since 46 but were never committed, so a
stash across a server rebuild silently dropped them. (The millisecond peer-log
stamps are already here as 17614a5ac.)

MAX_STREAM_FRAME bounds the length a header may claim: a torn header can name
any 16-bit value, and reading that many bytes stalls the session waiting for
bytes the node never sends. A byte that fails START2, or a rejected header, is
scanned again for the real frame's START1, as StreamAPI does.

STREAM_RESYNC and torn_frames count what the framing had to step over. A frame
destroyed on the USB stream is one the node did send and the radio did receive,
and it reaches the ledger as a replay request - indistinguishable from a frame
the radio never heard. A run reporting non-zero has lost frames to the
transport and its receive miss reads high by that much. Both are exported in
stats.json.

Co-Authored-By: Jonathan Bennett <jbennett@incomsystems.biz>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01REkPVFh6kvG4AZJ5A8AtM9

---------

Co-authored-by: James Rich <james.a.rich@gmail.com>
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-10-02 03:48:17 +00:00

818 lines
31 KiB
C++

// Unit tests for DMShellRxWindow and DMShellTxHistoryWindow in src/modules/DMShellRecovery.h - the
// sequence tracking and replay bookkeeping behind DMShell's retransmission scheme.
//
// Two contracts are pinned here, and both exist because of an observed failure: a DMShell session on
// a fast modem preset (ShortTurbo) degenerated into a retransmission storm that never terminated.
//
// 1. A replay request is damped per sequence number. Without damping, every frame arriving above a
// gap produces its own request, so one lost frame costs as many requests as the sender has frames
// in flight, and each of those costs the sender a duplicate replay - a positive feedback loop on
// an already contended channel. The damping is keyed on the sequence number, not on time alone,
// so a *different* gap is always reported immediately; delaying that would add a round trip to
// every recovery.
//
// 2. A request for a frame that has aged out of the send ring is distinguishable from one that can
// still be answered. The ring is bounded in frames (50), so the wall-clock span it covers scales
// with the preset: about two minutes on LongFast but under seven seconds on ShortTurbo. Once a
// requested frame is gone the peer can never receive it, and neither side advances past the hole,
// so the request repeats until the session idles out five minutes later. DMShellModule relies on
// the Evicted verdict to close the session instead.
//
// 3. The sender will not transmit more than a fixed number of frames past the peer's acknowledgements.
// This is what makes contracts 1 and 2 stop mattering: measured on hardware, whichever end has the
// higher frame rate outruns its own replay ring first, so a bigger ring on one side just moves the
// failure to the other. A sender that cannot get more than a window ahead of a gap can always
// answer a replay request. The window also bounds the send path in wall-clock terms, which is what
// lets an idle timeout detect a peer that has vanished - a blocked sender goes quiet and times out,
// where an unbounded one transmitted to nobody for as long as its command kept producing output.
//
// 4. A repeated OPEN from the peer that owns the running session is answered by resending OPEN_OK,
// not by opening a second session over the first. A lost OPEN_OK could not otherwise be recovered:
// OPEN_OK is always seq 1, and a replay request for seq 1 encodes as last_rx_seq 0, which both
// ends read as "no request". The client repeats its OPEN instead, and this makes that repeat safe.
//
// 5. The sender's window-shut retransmission waits for the frame, not the poll, and for a measured
// acknowledgement latency rather than a derived one. Either half alone left a lossless bulk
// transfer with a third of its frames arriving twice.
//
// The regression guarded: if these assertions are deleted or relaxed, the storm comes back, and it
// comes back invisibly - the failing session looks like a flaky radio link rather than a protocol
// bug, which is exactly how it was originally misdiagnosed.
//
// Time is passed in rather than read from millis() so the damping boundaries can be asserted
// exactly, including across the millis() wrap.
// Arduino.h for its extern "C" declarations of setup() and loop(): portduino's main() calls both
// with C linkage, and nothing else this suite includes reaches a platform header, so without it
// the definitions below are mangled and the test program does not link.
#include "Arduino.h"
#include "TestUtil.h"
#include "modules/DMShellRecovery.h"
#include <cstdint>
#include <unity.h>
namespace
{
// The OPEN sequence number every case seeds from, so the first data frame expected is 2.
constexpr uint32_t kOpenSeq = 1;
constexpr uint32_t kInterval = 1000;
/// Unity's equality assertions take integers, and DMShellReplayLookup is a scoped enum, so the
/// comparison has to be made explicitly. A macro rather than a function so a failure still reports
/// the caller's line.
#define ASSERT_LOOKUP(expected, actual) TEST_ASSERT_EQUAL_UINT8(static_cast<uint8_t>(expected), static_cast<uint8_t>(actual))
DMShellRxWindow makeWindow()
{
DMShellRxWindow w;
w.reset(kOpenSeq);
return w;
}
} // namespace
void setUp(void) {}
void tearDown(void) {}
void test_dmshell_rx_seq_zero_always_processed()
{
DMShellRxWindow w = makeWindow();
const DMShellRxDecision d = w.classify(0, 0, kInterval);
TEST_ASSERT_TRUE(d.process);
TEST_ASSERT_FALSE(d.requestReplay);
}
void test_dmshell_rx_in_order_run_requests_nothing()
{
DMShellRxWindow w = makeWindow();
for (uint32_t seq = 2; seq <= 6; seq++) {
const DMShellRxDecision d = w.classify(seq, seq * 10, kInterval);
TEST_ASSERT_TRUE(d.process);
TEST_ASSERT_FALSE(d.requestReplay);
}
TEST_ASSERT_EQUAL_UINT32(6, w.lastInOrder());
TEST_ASSERT_EQUAL_UINT32(7, w.nextExpected());
}
void test_dmshell_rx_gap_requests_once_then_damps()
{
DMShellRxWindow w = makeWindow();
// Frame 2 is lost; 3 arrives and opens the gap.
const DMShellRxDecision first = w.classify(3, 0, kInterval);
TEST_ASSERT_FALSE(first.process);
TEST_ASSERT_TRUE(first.requestReplay);
TEST_ASSERT_EQUAL_UINT32(2, first.replaySeq);
// Everything the sender had in flight arrives next. Before the damping each of these produced
// its own request for seq 2, and each one cost the sender a duplicate replay.
for (uint32_t seq = 4; seq <= 8; seq++) {
const DMShellRxDecision d = w.classify(seq, 100, kInterval);
TEST_ASSERT_FALSE(d.process);
TEST_ASSERT_FALSE(d.requestReplay);
}
}
void test_dmshell_rx_gap_reasks_once_the_interval_elapses()
{
DMShellRxWindow w = makeWindow();
TEST_ASSERT_TRUE(w.classify(3, 0, kInterval).requestReplay);
// One millisecond short of the interval is still damped; the boundary itself is not.
TEST_ASSERT_FALSE(w.classify(4, kInterval - 1, kInterval).requestReplay);
const DMShellRxDecision again = w.classify(5, kInterval, kInterval);
TEST_ASSERT_TRUE(again.requestReplay);
TEST_ASSERT_EQUAL_UINT32(2, again.replaySeq);
}
void test_dmshell_rx_a_different_gap_is_not_damped()
{
DMShellRxWindow w = makeWindow();
TEST_ASSERT_TRUE(w.classify(3, 0, kInterval).requestReplay); // asks for 2
// The replay of 2 arrives well inside the damping interval and fills that hole, but 3 was
// dropped on arrival so it is now the missing one. That must be reported at once: making the
// caller wait out an interval keyed to a sequence number it has already recovered would add a
// round trip to every single recovery.
const DMShellRxDecision filled = w.classify(2, 10, kInterval);
TEST_ASSERT_TRUE(filled.process);
TEST_ASSERT_TRUE(filled.requestReplay);
TEST_ASSERT_EQUAL_UINT32(3, filled.replaySeq);
}
void test_dmshell_rx_duplicate_with_no_gap_requests_nothing()
{
DMShellRxWindow w = makeWindow();
TEST_ASSERT_TRUE(w.classify(2, 0, kInterval).process);
// A stale duplicate when we are fully caught up. The predecessor of this code answered it with
// an unconditional acknowledgement whose replay field underflowed to 0xffffffff, which the peer
// read as a request to replay a sequence number it had never sent.
const DMShellRxDecision dup = w.classify(2, 10, kInterval);
TEST_ASSERT_FALSE(dup.process);
TEST_ASSERT_FALSE(dup.requestReplay);
}
void test_dmshell_rx_zero_interval_disables_damping()
{
DMShellRxWindow w = makeWindow();
// DMSHELL_LEGACY_RECOVERY passes 0 to reproduce the pre-fix behaviour on the same build, so the
// A/B comparison does not depend on reflashing. Every frame above the gap must ask again.
TEST_ASSERT_TRUE(w.classify(3, 0, 0).requestReplay);
for (uint32_t seq = 4; seq <= 8; seq++) {
TEST_ASSERT_TRUE(w.classify(seq, 0, 0).requestReplay);
}
}
void test_dmshell_rx_damping_survives_millis_wrap()
{
DMShellRxWindow w = makeWindow();
// Ask just before the wrap, so the deadline lands just after it.
const uint32_t nearWrap = 0xffffff00u;
TEST_ASSERT_TRUE(w.classify(3, nearWrap, kInterval).requestReplay);
// Still inside the interval, but now() has not wrapped yet: a naive comparison reads the wrapped
// deadline as long past and un-damps every request from here to the wrap.
TEST_ASSERT_FALSE(w.classify(4, 0xfffffff0u, kInterval).requestReplay);
// Past the wrapped deadline (0xffffff00 + 1000 == 0x2e8).
TEST_ASSERT_TRUE(w.classify(5, 0x300u, kInterval).requestReplay);
}
void test_dmshell_tx_history_finds_retained_sequence()
{
DMShellTxHistoryWindow h(4);
for (uint32_t seq = 1; seq <= 4; seq++) {
h.noteStored(seq);
}
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(1, 5));
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(4, 5));
}
void test_dmshell_tx_history_reports_evicted_sequence()
{
DMShellTxHistoryWindow h(4);
for (uint32_t seq = 1; seq <= 5; seq++) {
h.noteStored(seq);
}
// Storing 5 in a ring of 4 displaced 1. Reporting that as merely "not found" is what let the
// peer retry an unanswerable request until the session idled out.
ASSERT_LOOKUP(DMShellReplayLookup::Evicted, h.classify(1, 6));
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(2, 6));
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(5, 6));
}
void test_dmshell_tx_history_evicts_with_capacity_one()
{
DMShellTxHistoryWindow h(1);
h.noteStored(1);
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(1, 2));
h.noteStored(2);
ASSERT_LOOKUP(DMShellReplayLookup::Evicted, h.classify(1, 3));
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(2, 3));
}
void test_dmshell_tx_history_ignores_unsent_sequence()
{
DMShellTxHistoryWindow h(4);
h.noteStored(1);
h.noteStored(2);
// A peer asking for something at or past our next sequence number is confused, not owed data.
// Closing the session on that would hand any malformed request a way to kill the shell.
ASSERT_LOOKUP(DMShellReplayLookup::NotSentYet, h.classify(3, 3));
ASSERT_LOOKUP(DMShellReplayLookup::NotSentYet, h.classify(99, 3));
ASSERT_LOOKUP(DMShellReplayLookup::NotSentYet, h.classify(0, 3));
}
void test_dmshell_tx_history_empty_ring_is_not_eviction()
{
DMShellTxHistoryWindow h(4);
// Nothing stored: frames went out without being remembered (a replay passes remember=false).
// The safe answer is to ignore the request, not to tear the session down.
ASSERT_LOOKUP(DMShellReplayLookup::NotSentYet, h.classify(1, 5));
}
void test_dmshell_tx_history_reset_forgets_everything()
{
DMShellTxHistoryWindow h(4);
for (uint32_t seq = 1; seq <= 6; seq++) {
h.noteStored(seq);
}
ASSERT_LOOKUP(DMShellReplayLookup::Evicted, h.classify(1, 7));
// A new session restarts sequence numbering at 1, so stale retention bounds would report the
// new session's first frames as evicted.
h.reset();
h.noteStored(1);
ASSERT_LOOKUP(DMShellReplayLookup::Found, h.classify(1, 2));
}
void test_dmshell_tx_window_unbounded_when_capacity_zero()
{
DMShellTxWindow w;
w.reset(0);
// DMSHELL_TX_WINDOW=0 and legacy mode both reproduce the pre-window behaviour on one build, so
// the bound can be measured with and without it without reflashing.
for (uint32_t seq = 1; seq <= 500; seq++) {
w.noteSent(seq);
TEST_ASSERT_TRUE(w.canSend());
}
TEST_ASSERT_EQUAL_UINT32(500, w.outstanding());
}
void test_dmshell_tx_window_closes_at_capacity()
{
DMShellTxWindow w;
w.reset(2);
w.noteSent(1);
TEST_ASSERT_TRUE(w.canSend());
w.noteSent(2);
TEST_ASSERT_FALSE(w.canSend()); // two outstanding, nothing acknowledged
TEST_ASSERT_EQUAL_UINT32(2, w.outstanding());
}
void test_dmshell_tx_window_reopens_on_ack()
{
DMShellTxWindow w;
w.reset(2);
w.noteSent(1);
w.noteSent(2);
TEST_ASSERT_FALSE(w.canSend());
// A cumulative cursor, so one acknowledgement can free several slots.
w.notePeerAcked(1);
TEST_ASSERT_TRUE(w.canSend());
TEST_ASSERT_EQUAL_UINT32(1, w.outstanding());
w.notePeerAcked(2);
TEST_ASSERT_EQUAL_UINT32(0, w.outstanding());
}
void test_dmshell_tx_window_ignores_stale_and_overreaching_cursors()
{
DMShellTxWindow w;
w.reset(2);
w.noteSent(1);
w.noteSent(2);
w.notePeerAcked(2);
// A duplicate or reordered frame carrying an older cursor must not close the window again.
w.notePeerAcked(1);
TEST_ASSERT_EQUAL_UINT32(0, w.outstanding());
// A peer claiming to have received more than we ever sent cannot buy itself extra credit; the
// cursor is clamped, so the window reflects our own progress once we do send more.
w.notePeerAcked(999);
w.noteSent(3);
w.noteSent(4);
TEST_ASSERT_EQUAL_UINT32(2, w.outstanding());
TEST_ASSERT_FALSE(w.canSend());
}
void test_dmshell_tx_window_of_one_is_strict_request_response()
{
DMShellTxWindow w;
w.reset(1);
w.noteSent(1);
TEST_ASSERT_FALSE(w.canSend());
w.notePeerAcked(1);
TEST_ASSERT_TRUE(w.canSend());
}
void test_dmshell_tx_window_reset_clears_peer_state()
{
DMShellTxWindow w;
w.reset(2);
w.noteSent(1);
w.noteSent(2);
w.notePeerAcked(2);
// A new session restarts sequence numbering at 1, so a stale cursor would grant credit for
// frames the new session has not sent.
w.reset(2);
TEST_ASSERT_EQUAL_UINT32(0, w.outstanding());
w.noteSent(1);
w.noteSent(2);
TEST_ASSERT_FALSE(w.canSend());
}
void test_dmshell_tx_window_reports_peer_cursor_for_retransmission()
{
DMShellTxWindow w;
w.reset(4);
for (uint32_t seq = 1; seq <= 4; seq++) {
w.noteSent(seq);
}
w.notePeerAcked(2);
// A blocked sender works out what to retransmit from this, so it has to be the clamped, monotone
// value rather than whatever the last frame happened to claim.
TEST_ASSERT_EQUAL_UINT32(2, w.peerAcked());
w.notePeerAcked(1);
TEST_ASSERT_EQUAL_UINT32(2, w.peerAcked());
w.notePeerAcked(99);
TEST_ASSERT_EQUAL_UINT32(4, w.peerAcked());
}
void test_dmshell_tx_window_latches_when_peer_cursor_freezes()
{
DMShellTxWindow w;
w.reset(4);
// The failure measured on hardware. The peer loses frame 3, so its cumulative cursor freezes at
// 2 however many frames arrive afterwards, and the sender fills the window against a cursor that
// will never move on its own.
w.noteSent(1);
w.noteSent(2);
w.notePeerAcked(2);
for (uint32_t seq = 3; seq <= 6; seq++) {
w.noteSent(seq);
}
TEST_ASSERT_FALSE(w.canSend());
TEST_ASSERT_EQUAL_UINT32(4, w.outstanding());
// Nothing here reopens it, which is why the sender has to retransmit peerAcked() + 1 rather than
// wait to be asked: with the window shut the peer never sees a higher sequence number, so it
// never re-asks, and the session latches silently.
TEST_ASSERT_EQUAL_UINT32(3, w.peerAcked() + 1);
// The retransmission lands and the cursor jumps past the whole run the peer had buffered.
w.notePeerAcked(6);
TEST_ASSERT_TRUE(w.canSend());
TEST_ASSERT_EQUAL_UINT32(0, w.outstanding());
}
void test_dmshell_retransmit_run_allows_exactly_the_bound()
{
DMShellRetransmitRun r;
r.reset(3);
for (uint32_t attempt = 1; attempt <= 3; attempt++) {
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_EQUAL_UINT32(attempt, r.repeatCount());
}
// The fourth ask is refused and stays refused, so the caller tears the session down once rather
// than alternating between giving up and trying again.
TEST_ASSERT_FALSE(r.allowRetransmit(7));
TEST_ASSERT_FALSE(r.allowRetransmit(7));
TEST_ASSERT_EQUAL_UINT32(3, r.repeatCount());
}
void test_dmshell_retransmit_run_restarts_on_a_new_sequence_number()
{
DMShellRetransmitRun r;
r.reset(2);
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_FALSE(r.allowRetransmit(7));
// A different gap is a different problem. Healthy recovery walks through many sequence numbers,
// so the allowance has to be per sequence number or a long session would eventually trip it.
TEST_ASSERT_TRUE(r.allowRetransmit(8));
TEST_ASSERT_EQUAL_UINT32(1, r.repeatCount());
}
void test_dmshell_retransmit_run_clear_forgives_a_peer_that_caught_up()
{
DMShellRetransmitRun r;
r.reset(2);
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_TRUE(r.allowRetransmit(7));
// The peer's cursor advanced, which proves it is alive; the frames it needed next must not
// inherit a nearly spent allowance.
r.clear();
TEST_ASSERT_EQUAL_UINT32(0, r.repeatCount());
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_TRUE(r.allowRetransmit(7));
TEST_ASSERT_FALSE(r.allowRetransmit(7));
}
void test_dmshell_retransmit_run_unbounded_when_limit_zero()
{
DMShellRetransmitRun r;
r.reset(0);
// The measured pre-fix behaviour, kept reachable so one build can be A/B tested: 88 repeats of a
// single sequence number and still going.
for (uint32_t attempt = 0; attempt < 200; attempt++) {
TEST_ASSERT_TRUE(r.allowRetransmit(7));
}
TEST_ASSERT_EQUAL_UINT32(200, r.repeatCount());
}
void test_dmshell_rx_duplicate_is_flagged_for_a_bare_ack()
{
DMShellRxWindow w;
w.reset(1);
// Nothing missing, so there is no replay request to carry our cursor. The peer is repeating a
// frame we already have, which is what a sender whose window has shut looks like, and the caller
// answers with a bare ACK.
DMShellRxDecision d = w.classify(2, 1000, 500);
TEST_ASSERT_TRUE(d.process);
TEST_ASSERT_FALSE(d.duplicate);
d = w.classify(2, 1100, 500);
TEST_ASSERT_FALSE(d.process);
TEST_ASSERT_TRUE(d.duplicate);
TEST_ASSERT_FALSE(d.requestReplay);
}
void test_dmshell_rx_damped_gap_is_not_a_duplicate()
{
DMShellRxWindow w;
w.reset(1);
// A frame above the gap, then another while the request is damped. The second is silent on
// purpose - answering every frame behind a hole is exactly the load the damping exists to avoid -
// so it must not be mistaken for a duplicate.
DMShellRxDecision d = w.classify(4, 1000, 500);
TEST_ASSERT_TRUE(d.requestReplay);
TEST_ASSERT_FALSE(d.duplicate);
d = w.classify(5, 1100, 500);
TEST_ASSERT_FALSE(d.process);
TEST_ASSERT_FALSE(d.requestReplay);
TEST_ASSERT_FALSE(d.duplicate);
}
void test_dmshell_rx_duplicate_behind_a_gap_asks_instead()
{
DMShellRxWindow w;
w.reset(1);
w.classify(4, 1000, 500); // opens a gap at 2 and damps the request
DMShellRxDecision d = w.classify(2, 2000, 500);
TEST_ASSERT_TRUE(d.process);
// Still waiting on 3, and a replay request carries the same cursor a bare ACK would, so the
// caller has nothing extra to send.
d = w.classify(2, 3000, 500);
TEST_ASSERT_TRUE(d.duplicate);
TEST_ASSERT_TRUE(d.requestReplay);
TEST_ASSERT_EQUAL_UINT32(3, d.replaySeq);
}
void test_dmshell_rx_reorder_holds_and_returns_slots()
{
DMShellRxReorder r;
r.reset();
const int slot = r.claimSlotFor(5);
TEST_ASSERT_TRUE(slot >= 0);
TEST_ASSERT_TRUE(r.holds(5));
TEST_ASSERT_EQUAL_INT(slot, r.find(5));
TEST_ASSERT_EQUAL_UINT32(1, r.count());
// The same sequence number arriving again must not take a second slot, or a retransmitting peer
// would fill the buffer with copies of one frame.
TEST_ASSERT_EQUAL_INT(-1, r.claimSlotFor(5));
TEST_ASSERT_EQUAL_UINT32(1, r.count());
r.release(slot);
TEST_ASSERT_FALSE(r.holds(5));
TEST_ASSERT_EQUAL_UINT32(0, r.count());
}
void test_dmshell_rx_reorder_never_holds_seq_zero()
{
DMShellRxReorder r;
r.reset();
// Unsequenced control frames are always processed in order, so they have nothing to reorder, and
// 0 is the empty marker.
TEST_ASSERT_EQUAL_INT(-1, r.claimSlotFor(0));
TEST_ASSERT_FALSE(r.holds(0));
TEST_ASSERT_EQUAL_INT(-1, r.find(0));
}
void test_dmshell_rx_reorder_full_buffer_keeps_the_lowest()
{
DMShellRxReorder r;
r.reset();
for (uint32_t seq = 20; seq < 20 + (uint32_t)DMShellRxReorder::SLOTS; seq++) {
TEST_ASSERT_TRUE(r.claimSlotFor(seq) >= 0);
}
TEST_ASSERT_EQUAL_UINT32((uint32_t)DMShellRxReorder::SLOTS, r.count());
// Full. A frame further out than everything held is the one to drop, because the gap fills from
// below and the lowest sequence numbers are needed soonest.
TEST_ASSERT_EQUAL_INT(-1, r.claimSlotFor(99));
TEST_ASSERT_FALSE(r.holds(99));
// A frame nearer the gap displaces the furthest one.
TEST_ASSERT_TRUE(r.claimSlotFor(10) >= 0);
TEST_ASSERT_TRUE(r.holds(10));
TEST_ASSERT_FALSE(r.holds(20 + (uint32_t)DMShellRxReorder::SLOTS - 1));
TEST_ASSERT_EQUAL_UINT32((uint32_t)DMShellRxReorder::SLOTS, r.count());
}
void test_dmshell_rx_reorder_drains_in_order_after_the_gap_fills()
{
// The measured failure: frames above a gap arrived intact and were discarded, so the peer had to
// resend each one after the gap filled - a round trip per frame it already had. Here they are held
// and the whole run is delivered as soon as the missing frame lands.
DMShellRxWindow w;
DMShellRxReorder r;
w.reset(10);
r.reset();
for (uint32_t seq = 12; seq <= 15; seq++) {
DMShellRxDecision d = w.classify(seq, 1000 + seq, 500);
TEST_ASSERT_FALSE(d.process);
TEST_ASSERT_FALSE(d.duplicate);
TEST_ASSERT_TRUE(r.claimSlotFor(seq) >= 0);
}
TEST_ASSERT_EQUAL_UINT32(4, r.count());
DMShellRxDecision d = w.classify(11, 3000, 500);
TEST_ASSERT_TRUE(d.process);
// The window wants 12 next and asks for it, but we are holding it - which is what the caller's
// suppression check is for, so no replay request goes out for a frame already in hand.
TEST_ASSERT_TRUE(d.requestReplay);
TEST_ASSERT_EQUAL_UINT32(12, d.replaySeq);
TEST_ASSERT_TRUE(r.holds(d.replaySeq));
uint32_t delivered = 0;
while (r.count() > 0) {
const int slot = r.find(w.nextExpected());
if (slot < 0) {
break;
}
const uint32_t seq = w.nextExpected();
r.release(slot);
TEST_ASSERT_TRUE(w.classify(seq, 3100 + seq, 500).process);
delivered++;
}
TEST_ASSERT_EQUAL_UINT32(4, delivered);
TEST_ASSERT_EQUAL_UINT32(0, r.count());
TEST_ASSERT_EQUAL_UINT32(15, w.lastInOrder());
// Fully caught up, so nothing is outstanding and the next frame in sequence just flows.
TEST_ASSERT_TRUE(w.classify(16, 4000, 500).process);
}
void test_dmshell_rx_reorder_a_hole_inside_the_buffer_still_asks()
{
DMShellRxWindow w;
DMShellRxReorder r;
w.reset(10);
r.reset();
// 13 is lost as well, so draining stops at it and the window has to ask for that one.
const uint32_t arrived[] = {12, 14, 15};
for (uint32_t seq : arrived) {
w.classify(seq, 1000 + seq, 500);
r.claimSlotFor(seq);
}
TEST_ASSERT_TRUE(w.classify(11, 3000, 500).process);
const int slot = r.find(w.nextExpected());
TEST_ASSERT_TRUE(slot >= 0);
r.release(slot);
DMShellRxDecision d = w.classify(12, 3100, 500);
TEST_ASSERT_TRUE(d.process);
TEST_ASSERT_TRUE(d.requestReplay);
TEST_ASSERT_EQUAL_UINT32(13, d.replaySeq);
// Not held, so this request is the one that must actually go out.
TEST_ASSERT_FALSE(r.holds(13));
TEST_ASSERT_EQUAL_INT(-1, r.find(w.nextExpected()));
TEST_ASSERT_EQUAL_UINT32(2, r.count());
}
// An OPEN whose OPEN_OK was lost. Round 10 on hardware: the client waited out its full 180 s
// --open-timeout while the server, which had accepted the session, streamed output to nobody. The
// client now repeats its OPEN under the same session id, and this is the server's side of that.
namespace
{
constexpr uint32_t kSession = 0x3b091724;
constexpr uint32_t kPeer = 0x999312f2;
} // namespace
void test_dmshell_open_with_no_session_opens()
{
TEST_ASSERT_EQUAL(DMShellOpenAction::Open, classifyOpen(false, 0, 0, kSession, kPeer, 0));
}
void test_dmshell_open_repeated_before_any_ack_resends_open_ok()
{
// Preempting here would fork a second shell and discard the first one's output, which is what a
// naive client-side retry would have done.
TEST_ASSERT_EQUAL(DMShellOpenAction::ResendOpenOk, classifyOpen(true, kSession, kPeer, kSession, kPeer, 0));
}
void test_dmshell_open_repeated_after_the_peer_acked_is_ignored()
{
// The peer has OPEN_OK. Answering would replay seq 1, and on a session long enough for seq 1 to
// have left the history, the replay path closes the session as evicted.
TEST_ASSERT_EQUAL(DMShellOpenAction::Ignore, classifyOpen(true, kSession, kPeer, kSession, kPeer, 1));
TEST_ASSERT_EQUAL(DMShellOpenAction::Ignore, classifyOpen(true, kSession, kPeer, kSession, kPeer, 500));
}
void test_dmshell_open_with_a_new_session_id_still_preempts()
{
// A restarted client picks a fresh random id, and must still be able to take the shell over.
TEST_ASSERT_EQUAL(DMShellOpenAction::Open, classifyOpen(true, kSession, kPeer, kSession + 1, kPeer, 0));
}
void test_dmshell_open_from_another_peer_still_preempts()
{
TEST_ASSERT_EQUAL(DMShellOpenAction::Open, classifyOpen(true, kSession, kPeer, kSession, kPeer + 1, 0));
}
void test_dmshell_open_with_session_id_zero_never_matches()
{
// The module replaces an id of 0 with a random one, so a running session can never carry 0 - but a
// match on it must not be possible even if one somehow did.
TEST_ASSERT_EQUAL(DMShellOpenAction::Open, classifyOpen(true, 0, kPeer, 0, kPeer, 0));
}
// The server's window-shut retransmission, timed the way the client's has been since 0246db2. Round 10
// on hardware: a bulk transfer with zero loss had 34% of its arriving frames be copies, because the
// retransmission fired on the poll after every cursor advance, and its interval was one derived round
// trip where the acknowledgement it waits for queues behind a window of our own frames.
void test_dmshell_ack_latency_first_sample_is_the_estimate()
{
DMShellAckLatency l;
TEST_ASSERT_EQUAL_UINT32(0, l.estimateMs());
l.noteSample(800);
TEST_ASSERT_EQUAL_UINT32(800, l.estimateMs());
}
void test_dmshell_ack_latency_smooths_by_a_quarter()
{
DMShellAckLatency l;
l.noteSample(800);
l.noteSample(1600); // 800 + (1600 - 800) / 4
TEST_ASSERT_EQUAL_UINT32(1000, l.estimateMs());
l.noteSample(200); // 1000 + (200 - 1000) / 4
TEST_ASSERT_EQUAL_UINT32(800, l.estimateMs());
}
void test_dmshell_ack_latency_ignores_a_zero_sample()
{
// A zero sample means the send stamp and the acknowledgement landed on the same millisecond, which
// says nothing about the link. Taken as the first sample it would read as "no estimate".
DMShellAckLatency l;
l.noteSample(0);
TEST_ASSERT_EQUAL_UINT32(0, l.estimateMs());
l.noteSample(500);
l.noteSample(0);
TEST_ASSERT_EQUAL_UINT32(500, l.estimateMs());
}
void test_dmshell_ack_latency_interval_is_floored_before_any_sample()
{
// No acknowledgement yet, so the derived round trip is all there is: the old behaviour.
DMShellAckLatency l;
TEST_ASSERT_EQUAL_UINT32(658, l.intervalMs(658, 10000));
}
void test_dmshell_ack_latency_interval_is_twice_the_estimate_within_bounds()
{
DMShellAckLatency l;
l.noteSample(1200);
TEST_ASSERT_EQUAL_UINT32(2400, l.intervalMs(658, 10000));
DMShellAckLatency fast;
fast.noteSample(100); // 200 is below the derived round trip, which still wins
TEST_ASSERT_EQUAL_UINT32(658, fast.intervalMs(658, 10000));
DMShellAckLatency slow;
slow.noteSample(9000); // 18 s would sit out most of a LongFast session
TEST_ASSERT_EQUAL_UINT32(10000, slow.intervalMs(658, 10000));
}
void test_dmshell_retransmit_waits_for_the_frame_not_the_poll()
{
// The frame went to the radio at 5000. A poll at 5010 - which is where a cursor advance used to
// send it again - must not; only a full interval after the frame's own send may.
TEST_ASSERT_FALSE(retransmitDue(5010, 5000, 1400));
TEST_ASSERT_FALSE(retransmitDue(6399, 5000, 1400));
TEST_ASSERT_TRUE(retransmitDue(6400, 5000, 1400)); // inclusive, as Throttle::hasElapsed()
TEST_ASSERT_TRUE(retransmitDue(9000, 5000, 1400));
}
void test_dmshell_retransmit_due_survives_millis_wrap()
{
const uint32_t sent = 0xFFFFFF00u; // 256 ms before the wrap
TEST_ASSERT_FALSE(retransmitDue(0x00000100u, sent, 1400)); // 512 ms later, across the wrap
TEST_ASSERT_TRUE(retransmitDue(sent + 1400, sent, 1400));
}
void setup()
{
initializeTestEnvironment();
UNITY_BEGIN();
RUN_TEST(test_dmshell_rx_seq_zero_always_processed);
RUN_TEST(test_dmshell_rx_in_order_run_requests_nothing);
RUN_TEST(test_dmshell_rx_gap_requests_once_then_damps);
RUN_TEST(test_dmshell_rx_gap_reasks_once_the_interval_elapses);
RUN_TEST(test_dmshell_rx_a_different_gap_is_not_damped);
RUN_TEST(test_dmshell_rx_duplicate_with_no_gap_requests_nothing);
RUN_TEST(test_dmshell_rx_zero_interval_disables_damping);
RUN_TEST(test_dmshell_rx_damping_survives_millis_wrap);
RUN_TEST(test_dmshell_tx_history_finds_retained_sequence);
RUN_TEST(test_dmshell_tx_history_reports_evicted_sequence);
RUN_TEST(test_dmshell_tx_history_evicts_with_capacity_one);
RUN_TEST(test_dmshell_tx_history_ignores_unsent_sequence);
RUN_TEST(test_dmshell_tx_history_empty_ring_is_not_eviction);
RUN_TEST(test_dmshell_tx_history_reset_forgets_everything);
RUN_TEST(test_dmshell_tx_window_unbounded_when_capacity_zero);
RUN_TEST(test_dmshell_tx_window_closes_at_capacity);
RUN_TEST(test_dmshell_tx_window_reopens_on_ack);
RUN_TEST(test_dmshell_tx_window_ignores_stale_and_overreaching_cursors);
RUN_TEST(test_dmshell_tx_window_of_one_is_strict_request_response);
RUN_TEST(test_dmshell_tx_window_reset_clears_peer_state);
RUN_TEST(test_dmshell_tx_window_reports_peer_cursor_for_retransmission);
RUN_TEST(test_dmshell_tx_window_latches_when_peer_cursor_freezes);
RUN_TEST(test_dmshell_retransmit_run_allows_exactly_the_bound);
RUN_TEST(test_dmshell_retransmit_run_restarts_on_a_new_sequence_number);
RUN_TEST(test_dmshell_retransmit_run_clear_forgives_a_peer_that_caught_up);
RUN_TEST(test_dmshell_retransmit_run_unbounded_when_limit_zero);
RUN_TEST(test_dmshell_rx_duplicate_is_flagged_for_a_bare_ack);
RUN_TEST(test_dmshell_rx_damped_gap_is_not_a_duplicate);
RUN_TEST(test_dmshell_rx_duplicate_behind_a_gap_asks_instead);
RUN_TEST(test_dmshell_rx_reorder_holds_and_returns_slots);
RUN_TEST(test_dmshell_rx_reorder_never_holds_seq_zero);
RUN_TEST(test_dmshell_rx_reorder_full_buffer_keeps_the_lowest);
RUN_TEST(test_dmshell_rx_reorder_drains_in_order_after_the_gap_fills);
RUN_TEST(test_dmshell_rx_reorder_a_hole_inside_the_buffer_still_asks);
RUN_TEST(test_dmshell_open_with_no_session_opens);
RUN_TEST(test_dmshell_open_repeated_before_any_ack_resends_open_ok);
RUN_TEST(test_dmshell_open_repeated_after_the_peer_acked_is_ignored);
RUN_TEST(test_dmshell_open_with_a_new_session_id_still_preempts);
RUN_TEST(test_dmshell_open_from_another_peer_still_preempts);
RUN_TEST(test_dmshell_open_with_session_id_zero_never_matches);
RUN_TEST(test_dmshell_ack_latency_first_sample_is_the_estimate);
RUN_TEST(test_dmshell_ack_latency_smooths_by_a_quarter);
RUN_TEST(test_dmshell_ack_latency_ignores_a_zero_sample);
RUN_TEST(test_dmshell_ack_latency_interval_is_floored_before_any_sample);
RUN_TEST(test_dmshell_ack_latency_interval_is_twice_the_estimate_within_bounds);
RUN_TEST(test_dmshell_retransmit_waits_for_the_frame_not_the_poll);
RUN_TEST(test_dmshell_retransmit_due_survives_millis_wrap);
exit(UNITY_END());
}
void loop() {}