From 6823519503483b1570ef1cd2d9e95d0be33d33a1 Mon Sep 17 00:00:00 2001 From: Jean-Pierre Martineau Date: Tue, 14 Jul 2026 00:05:47 -0400 Subject: [PATCH] Trace: size the reply-wait to the route length MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A trace is one packet that must travel the whole path out and back before its reply reaches us, so a flat 10s wait cut long walks off mid-flight — the packet completed the circuit on the mesh, but our wait had already expired, so we logged a phantom "no reply" for a route that worked. run_trace now sizes the wait to the hop count (base + per-hop, capped) when the caller doesn't pin a timeout, counting the transmitted path (return leg included). An unknown path-less flood falls back to the old flat budget. run_traces and the mock thread the optional timeout through, so every trace surface — live screen, CLI, probe, TX optimizer — inherits the scaling. Co-Authored-By: Claude Opus 4.8 --- meshterm/core/connection.py | 21 ++++++++--- meshterm/services/trace_runner.py | 51 ++++++++++++++++++++++++-- tests/test_skeleton.py | 59 +++++++++++++++++++++++++++++++ 3 files changed, 124 insertions(+), 7 deletions(-) diff --git a/meshterm/core/connection.py b/meshterm/core/connection.py index 4f1b93f..9dc81e0 100644 --- a/meshterm/core/connection.py +++ b/meshterm/core/connection.py @@ -425,7 +425,7 @@ class Device(ABC): target: str, *, path: Optional[str] = None, - timeout: float = 10.0, + timeout: Optional[float] = None, ) -> TraceResult: """Run a single path trace to ``target`` and return per-hop SNR. @@ -436,7 +436,10 @@ class Device(ABC): the connection resolves one from the contact's learned route (the firmware itself never routes a trace — an explicit path is all it walks), falling back to path-less only for unknown targets. - timeout: Seconds to wait for the trace reply. + timeout: Seconds to wait for the trace reply. ``None`` (the default) sizes the + wait to the route: a trace has to travel the whole path out and back, so a + long walk is given proportionally longer to come home + (:func:`~meshterm.services.trace_runner.trace_timeout`). Returns: A :class:`TraceResult`; ``success`` is ``False`` on timeout. @@ -1467,11 +1470,11 @@ class MeshCoreDevice(Device): target: str, *, path: Optional[str] = None, - timeout: float = 10.0, + timeout: Optional[float] = None, ) -> TraceResult: from meshcore import EventType # local import keeps mock path dependency-free - from ..services.trace_runner import path_hash_flags + from ..services.trace_runner import path_hash_flags, trace_timeout mc = self._require() tag = random.randint(0, 0xFFFFFFFF) @@ -1494,6 +1497,14 @@ class MeshCoreDevice(Device): resolved = await self._trace_path_to_contact(mc, target) if resolved is not None: path_bytes, flags = resolved + + # Size the reply-wait to the route unless the caller pinned it. ``path_bytes`` is + # the whole walk — out plus the mirrored return leg — so its entry count (each + # ``1 << flags`` bytes wide) is the number of relay transmissions the packet makes + # before the reply reaches us. A path-less flood leaves the count unknown (0). + if timeout is None: + hops_walked = len(path_bytes) // (1 << flags) if path_bytes else 0 + timeout = trace_timeout(hops_walked) await mc.commands.send_trace(auth_code=0, tag=tag, flags=flags, path=path_bytes) event = await mc.wait_for_event( EventType.TRACE_DATA, @@ -2510,7 +2521,7 @@ class MockDevice(Device): target: str, *, path: Optional[str] = None, - timeout: float = 10.0, + timeout: Optional[float] = None, ) -> TraceResult: await asyncio.sleep(0.05) # mimic radio latency so progress bars are visible forced = [h for h in path.split(",") if h.strip()] if path else None diff --git a/meshterm/services/trace_runner.py b/meshterm/services/trace_runner.py index 092bee4..26e062d 100644 --- a/meshterm/services/trace_runner.py +++ b/meshterm/services/trace_runner.py @@ -158,6 +158,52 @@ def path_hash_flags(width_bytes: int) -> Optional[int]: return None +#: Fixed overhead in a trace's reply-wait budget, in seconds: our own transmit, the far +#: endpoint's turnaround, and our receive-side decode — the cost that doesn't grow with +#: the route. +TRACE_TIMEOUT_BASE_S = 4.0 +#: Per-hop allowance added to the budget, in seconds. Each entry in the walked path is one +#: relay transmission, and this covers its packet airtime, the repeater's processing, and +#: the randomised transmit backoff MeshCore adds so relays don't collide. +TRACE_TIMEOUT_PER_HOP_S = 1.6 +#: Upper bound on the reply-wait, in seconds, so a route that never comes home still +#: surrenders the trace (and the session) in bounded time rather than scaling without end. +TRACE_TIMEOUT_CEILING_S = 30.0 +#: Fallback budget, in seconds, when the hop count can't be known ahead of the send — a +#: path-less flood to a contact we hold no route for. This is the historical flat value, +#: kept for exactly the case where we can't size the walk. +TRACE_TIMEOUT_FLOOD_S = 10.0 + + +def trace_timeout(hop_count: int) -> float: + """Return the reply-wait budget, in seconds, for a trace walking ``hop_count`` hops. + + A trace is a *single* packet that has to travel the whole path — out to the far hop + and back over the mirrored return leg — before its reply reaches us, so the wait has + to grow with the route. A flat budget sized for a neighbour cuts a long walk off + mid-flight: the packet completes the circuit on the mesh, but our wait has already + expired, so we log a phantom "no reply" for a route that actually worked. The budget + is a fixed base (:data:`TRACE_TIMEOUT_BASE_S`) plus a per-hop allowance + (:data:`TRACE_TIMEOUT_PER_HOP_S`) for each relay transmission, capped at + :data:`TRACE_TIMEOUT_CEILING_S`. + + ``hop_count`` is the number of hops in the *transmitted* path, which already includes + the mirrored return leg (see :meth:`~meshterm.core.connection.MeshCoreDevice._trace_path_to_contact`), + so it maps one-to-one onto relay transmissions and must not be doubled here. + + Args: + hop_count: Hops in the walked path (return leg included). ``0`` (or less) means the + count is unknown — a path-less flood — and yields :data:`TRACE_TIMEOUT_FLOOD_S`. + + Returns: + The number of seconds to wait for the trace reply. + """ + if hop_count <= 0: + return TRACE_TIMEOUT_FLOOD_S + budget = TRACE_TIMEOUT_BASE_S + TRACE_TIMEOUT_PER_HOP_S * hop_count + return min(budget, TRACE_TIMEOUT_CEILING_S) + + async def run_traces( device: Device, target: str, @@ -165,7 +211,7 @@ async def run_traces( samples: int = 5, path: Optional[str] = None, cooldown_s: float = 1.0, - timeout: float = 10.0, + timeout: Optional[float] = None, on_result: Optional[ProgressCallback] = None, persist: Optional[Callable[[TraceResult], Awaitable[None] | None]] = None, ) -> list[TraceResult]: @@ -177,7 +223,8 @@ async def run_traces( samples: Number of traces to run. path: Optional explicit path to force on every trace. cooldown_s: Delay between traces to respect radio duty cycle. - timeout: Per-trace reply timeout in seconds. + timeout: Per-trace reply timeout in seconds. ``None`` (the default) lets each + trace size its own wait to the route via :func:`trace_timeout`. on_result: Optional callback invoked as ``(completed, total, result)`` after each trace, e.g. to advance a progress bar. persist: Optional callback to store each trace (sync or async). diff --git a/tests/test_skeleton.py b/tests/test_skeleton.py index 752f0fa..6f91036 100644 --- a/tests/test_skeleton.py +++ b/tests/test_skeleton.py @@ -262,6 +262,65 @@ async def test_mock_device_blank_path_traces() -> None: assert any(r.success and r.hops for r in results) +def test_trace_timeout_scales_with_hops() -> None: + """The reply-wait grows one allowance per hop, within its documented bounds.""" + from meshterm.services.trace_runner import ( + TRACE_TIMEOUT_BASE_S, + TRACE_TIMEOUT_CEILING_S, + TRACE_TIMEOUT_FLOOD_S, + TRACE_TIMEOUT_PER_HOP_S, + trace_timeout, + ) + + # An unknown hop count (a path-less flood) can't be sized, so it falls back to the + # flat historical budget. + assert trace_timeout(0) == TRACE_TIMEOUT_FLOOD_S + assert trace_timeout(-3) == TRACE_TIMEOUT_FLOOD_S + + # Each hop adds exactly one per-hop allowance on top of the fixed base... + assert trace_timeout(1) == TRACE_TIMEOUT_BASE_S + TRACE_TIMEOUT_PER_HOP_S + assert trace_timeout(5) == TRACE_TIMEOUT_BASE_S + 5 * TRACE_TIMEOUT_PER_HOP_S + # ...so a longer walk is always given longer to come home than a shorter one... + assert trace_timeout(8) > trace_timeout(3) + # ...until the ceiling caps a route that would otherwise scale without end. + assert trace_timeout(10_000) == TRACE_TIMEOUT_CEILING_S + + +async def test_run_trace_sizes_wait_to_the_forced_route() -> None: + """A forced path's reply-wait is sized to its hop count, not a flat default. + + The real device must hand ``wait_for_event`` the route-scaled budget so a long walk + isn't cut off before its reply can travel out and back. + """ + from meshterm.core.connection import MeshCoreDevice + from meshterm.services.trace_runner import trace_timeout + + seen: dict[str, float] = {} + + class _Commands: + async def send_trace(self, *, auth_code, tag, flags, path): # noqa: ANN001, ANN201 + return None + + class _MC: + commands = _Commands() + + async def wait_for_event(self, event_type, *, attribute_filters=None, timeout=None): # noqa: ANN001, ANN201 + seen["timeout"] = timeout + return None # a miss: run_trace returns a clean failure, no further calls + + device = MeshCoreDevice(port="COM-test") + device._mc = _MC() + + # Five single-byte hops → a five-hop walk (the spec is already the mirrored round trip). + result = await device.run_trace("Alice", path="3d,f2,3d,f2,3d") + assert result.success is False + assert seen["timeout"] == trace_timeout(5) + + # An explicit timeout still wins over the auto-scaling. + await device.run_trace("Alice", path="3d,f2,3d,f2,3d", timeout=2.0) + assert seen["timeout"] == 2.0 + + def test_trace_edges_endpoints_are_our_device() -> None: """The first edge originates at us and the last edge returns to us (#3/#4).""" from meshterm.core.models import Hop