logs.gokuls.in

This is the telemetry-side backstop for the loop fixed in #444. That fix stops

the loop at its source. This PR bounds what the next bug of the same kind can

cost.

Problem. The pipe forwarded every protocol.message.failed as its own row,

and no protocol event had any limit. A row cannot carry a message id: no

identifier has a field to land in, docs/privacy.md and the threat model say

so, and the golden fixture pins it. So the ingest cannot tell one failure

reported many times from many failures, and it meters every row. While the

outbox loop was running, a handful of devices each uploaded about 15 accepted

events per second for days.

The cap. Each reason gets a token bucket, in

telemetry/pipe/failure_limit.rs. It allows 500 rows at once, enough for a full

outbox expiring or being evicted in one sweep, then one row every 10 seconds.

The loop that sent 1.3M rows a day would now send about 8,600.

No count is lost.

• Every failure is still counted into the rollup's sends_failed_sum, so the

minute totals stay exact. Only the per-row reason and retry_count are

thinned.

• A held-back row is added to telemetryStats().dropped, which keeps the

existing identity true: sent plus dropped equals every event the pipe was

handed. The three-day soak test asserts that identity, and it now exercises

the cap as well.

Where the check runs. It runs on the borrowed &Event on both routes into

the pipeline (handle_protocol_event and handle for a

TelemetryRecord::Protocol), before classification copies the reason. A

held-back row therefore costs no allocation, in line with the pipe's

"never allocate for an event it drops" rule.

Design choices.

• Reasons are the engine's own fixed literals, so the table is a short Vec

scanned linearly. A table that somehow fills puts every further reason in one

shared bucket rather than growing.

• The buckets live as long as the pipe, not the session, so a device that

foregrounds often does not get a fresh burst each time.

Related issues

Refs #444.

Type of change

• feat — new feature
• docs — documentation only
• test — adding or correcting tests

Checklist

• cargo fmt --all -- --check passes
• cargo clippy --workspace -- -D warnings passes
• cargo test -p offline-protocol --lib passes (1,781 tests, 9 of them new). I did not run the full workspace locally.
• cargo-deny is satisfied (no dependency changes)
• Commits follow Conventional Commits
• Docs / CHANGELOG.md updated where relevant
• No new unsafe in core crates
• The UniFFI UDL did not change

Breaking changes

None. No wire change, no golden-fixture change, no new reason classifier (the

ADR 0013 rule is not engaged), no UDL change and no new setting. The only

visible difference is that dropped can now include held-back failure rows,

and the stats table in docs/telemetry.md says so.

Notes for reviewers

Tests.

• failure_limit.rs has seven unit tests covering:
• the burst
• the sustained rate, one row per refill over a simulated day at 20 per second
• separate buckets per reason
• refilling up to the burst and no further
• a full bucket banking no progress while it waits
• a clock that goes backwards
• the shared overflow bucket
• a_repeating_failure_is_counted_in_full_and_sent_up_to_its_ceiling (pipeline)

covers both routes sharing one ceiling and sends_failed_sum staying exact.

• a_looping_failure_uploads_its_burst_and_counts_the_rest_as_dropped runs the

scenario end to end through an inline pipe and a capturing client.

Mutation checks. Removing the rollup count from the hold-back path fails the

pipeline test. Removing the dropped count fails the scenario test and the

soak test's identity.

Soak test. three_days_offline_... emits the same reason 40 times per tick,

so the cap now engages. Its "the caps trimmed the queue" assertion used to read

stats.dropped, which would now pass on held-back rows alone. It reads the

store's own dropped_events() instead, so it still proves what its message says.

CI. The Test job is red on every branch right now, main included, because of

an expired fixture in offline-protocol-leaf/tests/phone_interop.rs. That is

unrelated to this change and is fixed separately.

A handful of long-lived sessions are uploading about 15 protocol.message.failed

rows per second each, all with reason "Outbox capacity exceeded" and

retry_count 0. That is about 3.7M rows in the last 30 days, and every one is

metered. The rows are real SDK output, not an ingest bug. The SDK is reporting

the same kind of failure over and over, and the app receives each one as a

terminal MessageFailed.

The loop. A full outbox evicts its least recently sent entry and reports it

failed. Eviction removed only the outbox entry and its persisted copy, so the

message stayed in the retry queue. process_retry_queue and the reconnect flush

both call ensure_outbox_entry before resending, and that call re-creates a

missing entry with fresh timestamps. With the outbox still full, re-creating it

evicted a different message. That message was reported failed, and it was still

queued for retry too.

Why it never ended. The outbox is the only thing that expires a message, and

each resurrection reset its clocks. The retry queue's own cleanup_expired never

fired either, because every re-enqueue stamps added_at again. So a device

holding more than 500 undeliverable messages reported one "terminal" failure per

retry, forever, for ids it had already reported.

The numbers fit. At the 300s backoff ceiling, 15 failures per second is a

backlog of roughly 5,000 messages. retry_count is 0 because none of those sends

ever succeeded. The new test reproduces the loop: ten process() ticks against a

full, all-failing outbox reported 200 failures for one eviction.

A second hole of the same kind. A message evicted while awaiting its ACK

stayed in the ACK tracker.

• If the ACK timed out, the message was reported failed a second time, as

"Message missing from outbox (cannot retry)".

• If the ACK arrived first, the message was reported delivered after it had been

reported failed.

The fix. Every path that gives a message up now goes through one function,

retire_undeliverable_message. It takes the id out of the retry queue, the ACK

tracker and the outbox together, fails any media transfer the id belongs to, and

records the transport failure.

Path	Retry entry before this PR	ACK entry before this PR
Capacity eviction (both outboxes)	leaked	leaked
ACK timeout with no outbox entry	leaked	removed
Lifetime expiry	removed	removed (none can be pending there)
Retry exhaustion	removed	removed

Each path still emits its own event, because what a drop owes the app differs by

path. Expiry now also clears staged re-seal provenance, which it skipped before

because it removed the outbox entry directly.

Related issues

No issue filed. The report came from the telemetry backend.

Type of change

• fix — bug fix
• docs — documentation only
• test — adding or correcting tests

Checklist

• cargo fmt --all -- --check passes
• cargo clippy --workspace -- -D warnings passes
• cargo test --workspace --lib passes (1,776 engine unit tests, 4 of them new). I did not run the doctest pass locally; no doc examples changed.
• cargo-deny is satisfied (no dependency changes)
• Commits follow Conventional Commits
• Docs / CHANGELOG.md updated where relevant
• No new unsafe in core crates
• The UniFFI UDL did not change

Breaking changes

None. No change to the UDL, the wire format, the FFI error enum or storage, and

no binding code changes. No bridge matches on the reason string, and none

buffers or dedupes message_failed.

Apps can see two behaviour changes:

• An evicted message is no longer re-sent, so it can no longer be delivered

after the app was told it failed.

• An app that counts message_failed events will see that count drop to one

per failed message.

Notes for reviewers

Tests. The existing eviction test could not see this bug. It never drove

process(), its backoff was 60s, and it filtered failures on the one reason

string, so a second settlement under another reason was invisible. The new tests

count failures across every reason:

• test_outbox_capacity_eviction_is_not_resurrected_by_the_retry_queue drives

the retry ladder at a 1ms backoff. It also checks the invariant in count form:

on an all-failing device, retry_queue_size() == outbox_entry_count().

• test_outbox_capacity_eviction_is_not_resurrected_by_a_flush checks that

flush_outbox_all does not re-drive an evicted message.

• test_outbox_capacity_eviction_while_awaiting_ack_settles_once covers an

evicted message whose ACK times out and whose late ACK then arrives.

• test_media_outbox_capacity_eviction_retires_the_retry_entry covers the same

leak in the media outbox, which was silent because the transfer abort is

idempotent.

Mutation checks. Removing the retry-queue line from the helper fails the three

resurrection tests. Removing the ACK-tracker line fails only the awaiting-ACK

test.

ensure_outbox_entry stays in the retry and flush paths as a guard, and its

comments no longer describe resurrection as intended. I found no other path that

leaves an ACK-requiring message queued for retry without an outbox entry:

• The initialize_mls rollback restores the outbox but never enqueues retries.
• Restore never touches the retry queue.

Not addressed here:

• Messages that do not require an ACK and whose send fails are enqueued for retry

without an outbox entry. Because added_at is reset on every re-enqueue, such a

message has no lifetime at all. I have not checked whether any caller of

handle_send_failure sends one.

• A telemetry-side backstop, a rate limit on forwarding message_failed with the

rollup count kept exact, will follow as a separate PR.

Since 2026-09-18 at 12:12Z, the Test job fails on every branch, main included.

48 of the 65 tests in offline-protocol-leaf/tests/phone_interop.rs fail with

the phone refusing the device's key package:

the phone accepts the device's key package: InvalidKeyPackage("The lifetime of the leaf node is not valid.")

Why it expired. The suite ran at a fixed instant,

NOW = 1_787_314_332 (2026-08-21T12:12:12Z). The fixed date was chosen so the

suite could not expire: control-frame stamps are signed, and the device refuses

a stale one. That reasoning holds for the device, which is told the time. It

does not hold for the phone. The phone is a production MlsManager, and its

MLS library checks a key package's lifetime against the system clock, with no

seam to pin it. A device key package minted at NOW therefore stopped being

acceptable LEAF_KEY_PACKAGE_LIFETIME (28 days) later. Main's last green run

was about six hours before that.

The fix. The instant is now the wall clock, read once per test process

through a OnceLock. Every stamp and every handle() call in a run still sees

the same value, which is the property the fixed date was protecting, and the

phone's own reading agrees with it. Most of the diff is rustfmt re-wrapping

lines that grew when NOW became now().

This is test-only. No library code changes.

Related issues

Unblocks #444 and #445, whose Test jobs fail on this and nothing else.

Type of change

• test — adding or correcting tests

Checklist

• cargo fmt --all -- --check passes
• cargo clippy --workspace -- -D warnings passes (no library change)
• cargo test -p offline-protocol-leaf passes: 65 of 65 interop tests, up from 17
• cargo test --workspace --no-fail-fast passes, so no second expired fixture was hiding behind this one (CI stops at the first failing binary)
• cargo-deny is satisfied (no dependency changes)
• Commits follow Conventional Commits
• No new unsafe
• The UniFFI UDL did not change

Breaking changes

None.

Notes for reviewers

• tools/embedded-footprint/src/bin/leaf.rs pins the same instant as

PAIRED_AT. It never reaches a phone-side lifetime check, so it cannot

expire this way.

• The leaf crate's doc example also pins it, and it only builds a key-package

frame.

• Neither of those is changed.