Skip to content

Count what a lost session actually does - #36

Merged
myobie merged 1 commit into
mainfrom
feat/connection-telemetry
Aug 3, 2026
Merged

Count what a lost session actually does#36
myobie merged 1 commit into
mainfrom
feat/connection-telemetry

Conversation

@myobie

@myobie myobie commented Aug 3, 2026

Copy link
Copy Markdown
Collaborator

What this answers

Fabric logged a line for every loss, reconnect attempt, and resume. A line
reconstructs one incident by hand. It cannot answer whether resumption works in
daily use, because that needs a grep over megabytes of log and the answer dies
at the next rotation. I answered a smaller version of that question by hand this
week, which is what showed the manual method does not scale.

fabric status now reports it:

sessions
  hetz	lost=4 resumed=4 failed=0 attempts=7 reconnect_p50=2.0s reconnect_max=4.5s
    lost_on=direct=3,relay=1 resumed_on=direct=2,relay=2

Three things the log could not report, now durable in <state>/telemetry.json:

  • A count of losses, resumes, and failed resumes. The pair is the point: 9
    resumes from 10 losses and 9 from 90 are very different systems.
  • The measured reconnect time. The log carried the backoff delay before the
    next attempt. That is a different number and it is never the total.
  • The path beside each loss and each resume. "It came back" and "it came
    back on the relay" are different outcomes.

A loss counts once, not once per retry. The session's retry counter is monotonic
and never resets, so it cannot separate a new break from a retry. An in-flight
entry does, and only a resume or a failure closes it.

The probe stops discarding its measurement

The liveness probe computed a round trip time and a path on every probe and threw
both away, so comparing direct against relay meant parsing days of log text.
Latency is now summarized per peer and per path.

Nothing reads it to make a routing decision. This change only stops throwing it
away, so the path-quality work has its data source ready.

How it is proved

The store has unit tests, and they prove only that it counts what it is told.
They cannot catch the failure that matters: a daemon that never calls it.

So a_real_shell_loss_and_resume_moves_the_durable_counters drives a shell over
two real daemons, takes its transport away, waits for the resume, and reads the
counters back through the same control response an operator uses. It also checks
the PTY still holds its marker variable, so this counted a genuine resume rather
than a silent replacement.

I verified the test can fail. Removing the single line that records the event
makes it fail with losses: 0, resumes: 0 after 30s, so it is not green by
accident. Its negative control runs BEFORE the loss on purpose: a counter already
at 1 would make the later assertion pass for the wrong reason.

Other properties pinned: an unmatched resume records no duration rather than a
zero, an in-flight loss does not survive a restart (a duration measured across a
restart would be fiction), a corrupt file starts the counts over instead of
stopping the daemon, and quantiles never exceed the largest sample seen.

Latency is bucketed rather than sampled, which keeps a file rewritten on every
event bounded on a daemon that runs for weeks. A test proves it: 4000 events
across 4 peers stay under 16 KB and do not grow with event count.

Cost

The file is rewritten on every recorded event rather than batched behind a flush
timer, because a flush window would lose exactly the incident these counters
exist to record. Probes pay the same write, at a few KB per peer per 20s
interval, alongside the log line the same probe already writes. No new order of
magnitude.

Tests

191 lib, 7 bin, 23 integration, all green. Changed files pass rustfmt. Clippy
introduces no new warning category; two functions move from 12 to 13 arguments
on an existing too_many_arguments warning.

Not in this change

No demotion or routing logic. No host was touched.

Fabric logged a line for every loss, reconnect attempt, and resume. A line
reconstructs one incident by hand. It cannot answer the question that matters,
which is whether resumption works in daily use. Answering that meant a grep over
megabytes of log, and the answer died at the next rotation. I answered a smaller
version of it that way this week, which is what showed the manual method does
not scale.

Three things the log could not report are now durable, per peer, in
<state>/telemetry.json:

- A count of losses, resumes, and failed resumes. The pair is the point: 9
  resumes from 10 losses and 9 from 90 are very different systems.
- The measured reconnect time. The log carried the backoff delay before the NEXT
  attempt. That is a different number and it is never the total.
- The path in use beside each loss and each resume. "It came back" and "it came
  back on the relay" are different outcomes, and a counter that omits the path
  sends the next reader back to grepping.

A loss is counted once, not once per retry. The session's own retry counter is
monotonic and never resets, so it cannot separate a new break from a retry; an
in-flight entry does, and only a resume or a failure closes it.

The liveness probe also stops discarding its measurement. It computed a round
trip time and a path on every probe and threw both away, so comparing the direct
path against the relay meant parsing days of log text. Latency is now summarized
per peer and per path. Nothing reads it to make a routing decision. This change
only stops throwing it away, so the path-quality work has its data source ready.

Latency is bucketed rather than sampled, which is what keeps a file that is
rewritten on every event bounded on a daemon that runs for weeks. A test proves
that: 4000 events across 4 peers stay under 16 KB and do not grow with event
count.

Proved through the real path, not only the store. A test drives a shell over two
real daemons, takes its transport away, waits for the resume, and reads the
counters back through the same control response an operator uses. Removing the
one line that records the event makes it fail, so it is not green by accident.
Its negative control runs BEFORE the loss, because a counter already at 1 would
make the later assertion pass for the wrong reason. Every wrong finding in this
repo's history came from never proving the tested condition occurred.

An unmatched resume records no duration rather than a zero, an in-flight loss
does not survive a restart, and a corrupt file starts the counts over instead of
stopping the daemon. Counters are not state the product depends on.

191 lib, 7 bin, 23 integration tests green.
@myobie
myobie merged commit 26ecf6c into main Aug 3, 2026
2 checks passed
@myobie
myobie deleted the feat/connection-telemetry branch August 3, 2026 23:24
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant