internet-latency-collector: stop re-exporting the boundary RIPE Atlas result - #4154
Conversation
… result RIPE's ?start= filter is inclusive, so passing the newest already-consumed timestamp returned that same result on every poll. Each duplicate appended another sample to the ledger account, advancing sample_index faster than the declared sampling interval, so derived sample times outran wall clock: 403 of 435 mainnet pairs drifted more than an hour in epoch 196, worst case +43.7h. wheresitup was unaffected. Ask for the following second instead, and document the parameter as exclusive. A stalled measurement now returns an empty page rather than a duplicate, which would have silenced the "timestamp not updated" warning that made the 2026-08-05 stall diagnosable. Move that signal to the no-results path, firing once silence exceeds several sampling intervals.
d974205 to
9d9c118
Compare
ben-dz
left a comment
There was a problem hiding this comment.
The +1 cursor fix is correct — ?start= is inclusive on the result timestamp field, which is exactly what UpdateTimestamp persists, and one duplicate record does become one permanent extra onchain sample (exporter/submitter.go:115 writes rtts []uint32 against a single start timestamp, no dedup downstream). Cold start, the exists guard, and the wheresitup path all check out.
What must change is the replacement stall signal. The new warn is inside if len(results) == 0, but the stall mode the removed warning actually caught returns a non-empty page — when the target probe goes dark, source probes keep uploading all-timeout results, which yield zero records and a zero maxTimestamp, so neither the new branch nor the one at collector.go:645 fires. The old inclusive ?start= re-returned the successful boundary result, which is precisely what made that path log. The two conditions are complementary, not overlapping, so the diff swaps which stall mode is covered rather than preserving coverage — and per the PR's own account, the 2026-08-05 incident was the mode that is now silent. Reattaching the check to "no new samples" instead of "no results" covers both.
…warning The replacement warning was guarded on an empty results page, but the stall mode that made the 2026-08-05 incident diagnosable returns a non-empty one: when the target probe goes dark the source probes keep pinging and keep uploading results whose ping array holds no rtt. Those parse to zero valid latencies, so no records are exported and maxTimestamp stays zero — neither the empty-page branch nor the "timestamp not updated" branch fires, and nothing above Debug is emitted. Key the check off the export cursor failing to advance instead, which is the condition both modes share, and log raw_results so the two are distinguishable. The all-timeout case is a regression test that fails without this change. Also document what exclusive ?start= gives up (a result stamped in the boundary second but uploaded after the previous poll is skipped, not deduplicated), and drop the claim that this is the only per-measurement stall signal — the measurement creation cycle already warns per measurement on the same staleness condition at the 1h mark.
ben-dz
left a comment
There was a problem hiding this comment.
lgtm
No new issues in the follow-up commit: stalled is snapshotted before the fetch so the later cursor update can't perturb it, the if/else chain leaves no silent path through a stalled measurement, raw_results on the warn distinguishes the two stall modes, and the CHANGELOG was updated to match. One operational note — no check runs have been dispatched against 3df2bc34 yet, so the green checks on record are the parent commit's.
nikw9944
left a comment
There was a problem hiding this comment.
One follow-up, no blockers. The exclusive-cursor fix is correct and the stall signal now covers both stall modes.
The "missing samples" alarm has been permanently silent and this fix turns it back on. Worth a CHANGELOG clause so the step change on deploy isn't read as a regression this PR caused.
- The "missing samples" alarm has been permanently silent and this fix turns it back on. The duplicate that this PR removes was always a successful result, so every circuit exported at least one record every cycle and the
Missingcounter atcontrolplane/internet-latency-collector/internal/ripeatlas/collector.go:512could never fire. It can now, and with one probe per circuit and the export and sampling intervals both at 600s (cmd/collector/main.go:32,33,35), poll jitter will trip it intermittently.
Nothing to change in the code — the counter is finally accurate. Name it in the CHANGELOG so the step change on deploy isn't read as a regression this PR caused.
nikw9944
left a comment
There was a problem hiding this comment.
The merge from main leaves the PR's own code unchanged, and the one follow-up from the last round is still open.
The "missing samples" alarm has been permanently silent and this fix turns it back on. Worth a CHANGELOG clause so the step change on deploy isn't read as a regression this PR caused.
- The "missing samples" alarm has been permanently silent and this fix turns it back on. The duplicate that this PR removes was always a successful result, so every circuit exported at least one record every cycle and the
Missingcounter atcontrolplane/internet-latency-collector/internal/ripeatlas/collector.go:512could never fire. It can now, and with one probe per circuit and the export and sampling intervals both at 600s (cmd/collector/main.go:32,33,35), poll jitter will trip it intermittently.
Nothing to change in the code — the counter is finally accurate. Name it in the CHANGELOG so the step change on deploy isn't read as a regression this PR caused.
…get scheduled (#4155) > **Stacked on #4154** — base is `internet-latency-collector-exclusive-start`, not `main`. The dependency is textual (both touch the same const block and CHANGELOG bullet), not logical. Merge #4154 first and this retargets to `main` cleanly. Refs #4153. ## Summary of Changes - A source probe can produce no successful sample for hours and nothing detects it. On 2026-08-05, 41 of 435 mainnet enlistments were in that state and were found only by reading the state file by hand. It has since recurred twice more — hkg (6 circuits) and dub (4) — both found the same way. - The signal already existed and nothing read it: a source's `last_response_at` is zeroed whenever its measurement is created and is only ever advanced by a sample with a latency above zero, so a zero on an older measurement means that probe has contributed nothing to it. Because a circuit is enlisted **exactly once** (a measurement for target `T` enlists only sources sorting after `T`, totalling 29+28+…+0 = 435), each such source darks its circuit with no other trace. - The hourly measurement cycle now tallies these by source location, exposes `doublezero_internet_latency_collector_ripeatlas_sources_without_samples{source_location}`, and warns with a sample capped at 20 identifiers. Both are silent when the count is zero. **The 2h grace period is its own constant, not the 1h `probeTimeout`.** RIPE dispatch is not immediate — an accepted enlistment has been observed producing its first result 80–100 minutes after creation, with all of one probe's enlistments starting within seconds of each other — so a 1h window reports probes that are merely warming up. Keeping it separate from `probeTimeout` also means tuning this reporting window cannot perturb the marking path. **It names no cause, deliberately.** `last_response_at` only advances on a sample with `latency > 0`, and `parseLatencyFromResult` returns 0 for a ping array carrying no `rtt`, so an enlistment RIPE never dispatched and a path at total packet loss are indistinguishable in this state. The metric, log line, and comments say what is measured — "no successful sample since the measurement was created" — not why. **Observation only.** It changes no state, marks no probes, and cannot trigger recreation. Recreation invalidates every measurement whose target sorts before that metro: rotating two probes on 2026-08-05 recreated 13 measurements covering 299 of 435 circuits and dropped coverage to 136/435 for a warm-up cycle, and every drop observed since has recovered unaided anyway. This also does **not** seed `last_response_at` at creation, which was the original suggestion in #4153. Seeding would silently enable the existing rotation path at `collector.go:801`, since the zero-guard at `:823` is the only thing holding it back. Applied to the 08-05 batch created at 13:12, this would have fired at the 15:12 cycle naming `hkg`, roughly 90 minutes before the metros were identified by hand. The 17:54 cycle would have stayed quiet: the sources flagged there (ymq, sjc, sqq) were inside dispatch latency and started reporting on their own at 18:13. ## Diff Breakdown | Category | Files | Lines (+/-) | Net | |--------------|-------|-------------|------| | Tests | 1 | +135 / -0 | +135 | | Core logic | 1 | +82 / -0 | +82 | | Scaffolding | 1 | +9 / -0 | +9 | | Docs | 1 | +1 / -0 | +1 | | **Total** | 4 | +227 / -0 | +227 | Nearly two thirds of the diff is tests; the logic is one pure function and its caller. <details> <summary>Key files (click to expand)</summary> - `controlplane/internet-latency-collector/internal/ripeatlas/collector_test.go` — table test over a synthetic `MeasurementState`, plus a sample-cap test - `controlplane/internet-latency-collector/internal/ripeatlas/collector.go` — new pure `sourcesWithoutSamples` helper, the `sourceSampleGracePeriod` constant, and the call site as step 4c of the measurement cycle - `controlplane/internet-latency-collector/internal/metrics/metrics.go` — the new `GaugeVec` </details> ## Testing Verification - Table test covers the states that matter: a measurement past the grace period with a silent source (counted), all sources responding (silent), a measurement inside the 80–100 minute dispatch window (silent), a measurement 60s old (silent), and `created_at == 0` (skipped rather than assumed old). Plus per-location accumulation across measurements, a measurement with no metadata, and the 20-item sample cap against 30 silent sources. - The fixtures are anchored on `sourceSampleGracePeriod` rather than a literal, so they straddle the real boundary. Tightening the constant from 2h to 1h fails exactly one subtest — `measurement inside observed RIPE dispatch latency is not reported` — and nothing else, which is the regression that matters here. - Separately confirmed the age guards are load-bearing: replacing `if !hasMeta || meta.CreatedAt == 0 || meta.CreatedAt >= createdBefore` with `if !hasMeta` fails the two warm-up subtests and the unknown-creation-time subtest. - The gauge `Reset()` before each cycle's writes means a recovered location goes absent rather than holding its last value. The `WARN` line itself is not asserted — the package has no log-capture harness and one line did not justify building one. - Extracted the tally as a pure function rather than testing through `RunRipeAtlasMeasurementCreation`, which needs a live client and location fetch.
Pull request was closed
) ## Summary of Changes - `parseLatencyFromResult` returns zero for a result whose ping array holds no `rtt`, and the caller gated the whole block on `if latency > 0`. So a source probe at 100% packet loss never advanced its `last_response_at`. The field only ever moved on a successful ping, which made a lossy path indistinguishable from a probe that had stopped answering. - The measurement cycle marks a source unresponsive once `last_response_at` ages past an hour. That is a rotation, and a metro's probe is a source for every measurement whose target sorts before it, so the blast radius is large. - A result the probe uploaded is now recorded as a response before the latency check, whether or not anything came back. **What is exported does not change.** A total-loss result still writes no sample. That is deliberate: it keeps the export cursor stalling when a whole measurement goes quiet, so #4154's `measurement stalled?` warning and the target-level staleness check both keep working. Exporting loss as `sample == 0` is a separate question, since it changes what lands on chain; it is not in this PR. ## Testing Verification - New table test covers the three states: a total-loss result records a response and exports nothing, a successful result records a response and exports one sample, and a result carrying no `prb_id` or timestamp records nothing. - Confirmed the test guards the change. Moving `UpdateSourceProbeResponse` back inside the `latency > 0` block fails `a_total-loss_result_counts_as_a_response`, and only that subtest.
Summary of Changes
?start=filter is inclusive, and the collector passed it the newest timestamp it had already consumed. Every poll re-fetched that boundary result and re-exported it, appending a duplicate sample to the circuit's onchain account.?start=now asks for the following second, and the parameter is documented as exclusive.start_timestamp + index × sampling_interval, the extra samples made derived times outrun wall clock: 403 of 435 mainnet pairs drifted more than an hour within epoch 196, worst case +43.7h, leaving consecutive epochs overlapping by days and anyevent_ts-keyed view unreliable.wheresitupwas unaffected (0/435), which is what isolated the defect to the RIPE path.timestamp not updated (old results?)warning only fired because duplicates were being exported, so this fix would have silenced it — and that warning is what made the 2026-08-05 mainnet stall diagnosable. The stall signal moves to the empty-result path, firing once a measurement returns nothing for longer than 30 minutes (several times the default 600s sampling interval, so ordinary polling jitter stays quiet).Existing accounts keep their already-inflated sample counts; this stops the drift accumulating from here forward. No migration.
Diff Breakdown
A one-line semantic fix to the fetch cursor, plus an observability branch so the fix does not remove an operator signal.
Key files (click to expand)
controlplane/internet-latency-collector/internal/ripeatlas/collector.go— warn instead of Debug when a measurement returns no new results for overstaleMeasurementWarnAfter(30m); guarded on having exported at least once, so a fresh measurement does not warn off a zero timestampcontrolplane/internet-latency-collector/internal/ripeatlas/client.go—?start=becomes exclusive (startTimestamp+1), with a doc comment stating the contract and whycontrolplane/internet-latency-collector/internal/ripeatlas/client_test.go— the existing assertion encoded the inclusive behavior; updated to require exclusivityTesting Verification
start == startTimestamp, i.e. it encoded the bug. Confirmed the updated assertion actually guards the fix: stashing onlyclient.gofailsTestInternetLatency_RIPEAtlas_GetMeasurementResultsIncrementalon two subtests withstart must exclude the last consumed timestamp, and passes with the change restored.max(event_ts - ingested_at)on mainnet showed 403/435 pairs above 1h in epoch 196 versus 0/435 forwheresitup, and a worked example (ymq↔ytoreaching sample_index 527 in 44h againstams↔fra's 252 over the same window) confirmed the ~2x sample rate against the declared 600s interval.Related
Investigated alongside #4153 (unscheduled RIPE Atlas enlistments silently killing circuits). That is a separate defect in the same export path and is not fixed here.