Clock skew detection for spans and metrics#283
Merged
Conversation
observe end_time not start_time so long-running spans (batch jobs, long-poll) don't get flagged, only spans that actually ended outside the skew window. counted post pii masking to match log semantics.
observes r.time inside the existing enrichment map, no pii masking on this path so nothing to order against. never rejects, same rule as logs and spans.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Follows #282 (merged). Targets
develop.#282 detects clock skew for log ingestion. Spans and metrics take the same kind of client-supplied timestamp and had no such check: a skewed span or data point is stored, is invisible in every time-windowed view, and nothing says why.
Spans are observed on
end_time, notstart_timeThis is the whole design, and it corrects a wrong premise in #282's own followup, which claimed spans have "the same exposure" as logs. They do not.
For logs the rule is exact: a log is a point-in-time event, so a
time27 hours before ingestion has no legitimate explanation. A span is not a point in time. Spans are exported at end, so a span that STARTED 27 hours ago is routinely fine: batch jobs, long transactions, long-poll connections. Observingstart_time(the fieldingestSpansactually stores astime) would fire on operations that are working perfectly, which is worse than the silence this feature exists to fix.Clock skew shifts both ends together; a long span moves only its start.
end_timeis what separates a broken clock from a slow operation, and the test that proves a long-running span is not flagged is the load-bearing test of this branch.The threshold is exact for logs and a judgement call here
Worth stating plainly so nobody inherits a rigor that is not there. For logs, 24 hours is derived: it is the maximum alert
time_window, so past it no threshold rule in the product can ever match. No alert rules run over spans or metrics, so no equivalent statement exists. The harm is weaker: the data is invisible in the time windows of trace views and dashboards. We reuse 24 hours for consistency and because it is conservative. The code comments say so.Metrics are observed on the data point
time, which is what dashboards window on, so that one lines up cleanly.Counters must stay under
ingestion.ingestion.span_timestamp_skewandingestion.metric_timestamp_skew, separate types rather than one shared counter (a shared one would make the per-project number a lie: "1,234 logs" when some were spans).The prefix is not cosmetic. Two mechanisms key off it literally:
breakdown.tsexcludestype NOT LIKE 'ingestion.%'from tenant usage breakdowns, andrecorder.ts(per #282) letsingestion.*bypass theMETERING_ENABLEDgate. Atraces.timestamp_skewwould have shown up in tenant usage as billable consumption AND died when metering is off. Both silent.Surfaces
GET /api/v1/projects/:id/ingestion-healthreports per signal ({ skew: { logs, spans, metrics } }, each independently null), since the UI has to know which signal it is looking at: the log copy is factually false for the others. "These logs cannot trigger an alert" is wrong when no alert rules run over spans, and "omitting the field makes LogTide use server ingestion time" is wrong for OTLP exporters, which have no such field to omit. The banner now carries per-signal copy and the overview renders one per non-null signal.Span skew counts only post-masking survivors, matching the log path where masking filters before counting. Nothing is ever rejected.
Notes for review
Two bugs caught in review and fixed here, both worth knowing:
end_time; trace lists filterstart_time. The conclusion holds for real skew (both ends shift) but the stated reason was invented, which is exactly the class of error this branch exists to remove from the log copy.reservoir.ingestSpans, so a throwing ingest would have counted records that were never written, contradicting its own comment.Accepted limitation
A collector draining a multi-day persistent queue, or an offline edge agent, produces genuinely old
end_timewith a correct clock and will be flagged. This is the same equivalence class as log backfill: we warn rather than reject precisely because we cannot tell them apart. Called out in a code comment so it stays a known cost.Verification
Full backend run with coverage: 271 files, 4765 tests passed, coverage 89.89% lines / 82.43% branches / 95.33% functions, above the 80% gate. Frontend 86 (incl. 11 banner tests),
svelte-checkclean of new errors,tsc --noEmitclean.