Repository navigation
Metric hardening, bulk pre-bucketed histogram recording - #68
Conversation
7afec6f to
4539866
Compare
A single NaN or infinity recorded into an instrument made its `sum` (and a histogram's min/max range) permanently unusable, and threw at JSON encoding time, taking the whole export payload with it. `Counter.add` and `Histogram.record` checked the sign but not finiteness, and NaN compares false against both `< 0` and every explicit bound, so it slipped past. Guard every record site with `isFiniteMetricValue`, following the existing convention for invalid input: assert in debug, drop in release. The helper tests the type by metatype rather than casting the value, so the check folds away when the generic is specialized and `Counter<Int>.add` is unchanged at ~580 ns/call; a `value as? Double` cast measured ~20 ns per call in an interleaved A/B. Also drop negative span durations in `reportAsDurationHistogramMetric`, which `Span.adjust` can produce. A negative duration is not measurable, so it is dropped rather than recorded into the histogram's negative range. `adjust` documents that both offsets may be negative, which is legitimate for shifting a span while keeping a positive duration, but nothing caught an adjustment that puts the end before the start. Assert on the result rather than on the arguments, so shifting still works and only a negative duration trips. This is checkable only for a span that has already ended; when the end time is still unknown the adjustment is stored and the negative duration materialises in `end()`, where the duration histogram already drops the sample. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
`FlushTimer.deinit` cancelled the timer and released it, but `cancel()` does not clear an outstanding suspension, and libdispatch traps on the release of a suspended source: "BUG IN CLIENT OF LIBDISPATCH: Release of a suspended object". `Tracer.flushTrace` suspends `idleTimer`, and only a subsequent span retirement re-arms it, so a tracer flushed with no active root held a suspended timer for the rest of its life. Releasing that tracer aborted the process — reproduced as signal 5 (SIGTRAP) both from the timer directly and through Tracer. Cancel first so resuming cannot deliver the event handler, then balance the suspend count before the source is released. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
`flushTrace` suspends `idleTimer` for the duration of the flush, but `retire` was the only thing that resumed it. Flushing with no active root retires nothing, so the idle timeout stayed suspended until some later span happened to end — and if no further span ended, `idleTimeout()` was never delivered again. Re-arm the timer at the end of the flush, which is the same `setupTimer()` call `retire` uses to push the deadline ahead. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sources like MetricKit hand back measurements that are already aggregated into device-chosen buckets, which the existing one-value-at-a-time record API can't accept. BucketedMeasurement pairs a representative value with an observation count. Histogram gains record(_:count:) and record(_ measurements:), the latter taking the mutex once and touching the backing dictionary once for the whole batch. The source's buckets are expected to line up with the histogram's explicitBounds, and a bucket is recorded at its midpoint. Bucket assignment is insensitive to that choice -- a midpoint and a bound select the same destination bucket when the bounds line up -- but `sum` is not: the midpoint is the mean of a uniformly distributed bucket, so it keeps `sum` unbiased, whereas recording at a bound skews it by up to a bucket width per observation, and with it any rate or mean derived from `sum`. Bounds are taken as separate parameters rather than a ClosedRange, because forming `lower...upper` traps when they are reversed, which would put the crash at the call site beyond reach of any guard in the initializer. The initializer is failable and rejects non-finite, negative, and reversed bounds, asserting in debug and returning nil in release. The single-value record path is unchanged: HistogramBuckets.record(_:count:) is a separate method rather than a defaulted parameter, so Histogram<Int> codegen doesn't pick up a T(exactly:) witness call. Rejection asserts, so each guard is covered by a macOS-only exit test expecting the child process to trap, as TimeReferenceTests does. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The subscriber only dumped payloads to the log and was gated behind DEBUG && os(iOS), so nothing consumed it. MetricKit-sample.json was a 2021 payload capture from an unrelated app, referenced only by the Package.swift exclude list. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Identifiers.swift is for identifier and attribute types; the numeric metric vocabulary is unrelated to it. Pure move, no behavior change. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
TimeReference and Tracer+Metrics were the only two files failing lint on main. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The test asserted an exact handler count on a live repeating timer: `XCTAssertEqual(handlerCallCount, 1)` ran after waiting for the first fire, but the 0.1s timer can fire again before the test thread resumes, so the count reaches 2. Reproduced deterministically by sleeping 0.25s before the assertion. Assert that the timer fired at all instead, matching the other tests here. Three further hazards in the same test: - `handlerCallCount` was written on NautilusTelemetry.queue and read from the test thread with no synchronization. Guard it with a Mutex, as testFlushTimerSuspendAndResume already does. - The second expectation was fulfilled on every fire past the first, so a third fire tripped XCTest's over-fulfillment check. Set assertForOverFulfill. - It waited only 1.0s for the next fire, against a 0.1s interval with 100ms leeway. Use the same 10s timeout as the rest of the file. "Fired after the interval change" is now measured against a baseline captured once the queue has drained, so a fire left over from the old schedule can't satisfy it. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
- BucketedMeasurement.boundsAreUsable is a pure predicate again; the two initializers assert on a false result, so the failure reports at the initializer rather than inside the helper. - isFiniteMetricValue switches on the metatype instead of chaining `==`. Verified this keeps the hot path intact: at -O with the generic specialized both forms emit identical machine code -- the Int case folds to `mov w0, #1; ret` either way, and the compiler merges the Double cases into one body. The swift_dynamicCastMetatype calls appear only in the unspecialized generic, which no in-module caller reaches, since the function is internal and @inline(__always). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
Thanks for tagging me for visibility, @ladd. I reviewed this at a high level to follow along, and I will generally defer to @jparise's review (thanks!).
My understanding is that this PR adds support for recording pre-bucketed data, such as data from MetricKit, into a histogram that may also contain individually recorded samples. Is that right? I wanted to confirm. 👍
| /// A count of observations that another source has already placed in a single bucket, such as one | ||
| /// `MXHistogramBucket` of a MetricKit `MXHistogram`. |
In this case it's not mixed with individual samples, but the OpenTelemetry APIs have an implicit assumption that you have access to the original samples to produce the sum: Since we don't have that here, we fake it with a calculated bucket midpoint value to produce an approximation. |
Doing some backflips to get MetricKit data to fit into the Otel histogram model.
@jparise
CC: @bachand
Claude commentary below:
Hardening
sum.FlushTimer.flushTrace.Span.adjustcannot produce a negative duration. Negative durations are handled at the reporting site:reportAsDurationHistogramMetricdrops the sample.Bulk pre-bucketed histogram recording
Sources like MetricKit return measurements already aggregated into device-chosen buckets, which the one-value-at-a-time
recordcan't accept.BucketedMeasurementpairs a representative value with an observation count;Histogramgainsrecord(_:count:)andrecord(_ measurements:), the latter taking the mutex once for the whole batch.Bounds are taken separately rather than as a
ClosedRange, because forminglower...uppertraps when the bounds are reversed — a guard inside aninit(range:)could never fire. The initialiser is failable and rejects non-finite bounds, reversed bounds, and buckets below zero, asserting in debug and returningnilin release.The source's buckets are expected to line up with the histogram's
explicitBounds, and a bucket is recorded at its midpoint. Bucket assignment is insensitive to that choice — a midpoint and a bound select the same destination bucket when the bounds line up — butsumis not: the midpoint is the mean of a uniformly distributed bucket, so it keepssumunbiased, whereas recording at a bound skews it by up to a bucket width per observation, and with it any rate or mean derived fromsum. Not implemented forExponentialHistogram.MetricKitInstrument removal
It only dumped payloads to the log behind
DEBUG && os(iOS); nothing consumed it.MetricKit-sample.jsonwas a 2021 capture from an unrelated app.Testing
swift testpasses. Each rejection guard is covered by a macOS-only exit test expecting the child process to trap, matchingTimeReferenceTests. Like that test, these only hold where assertions are compiled in, so they fail under-c release.Also fixes a pre-existing flake in
FlushTimerTests.testFlushTimerIntervalChange, which asserted an exact handler count on a live repeating timer.Also moves
MetricNumericandisFiniteMetricValueout ofIdentifiers.swiftinto a newNumeric.swift, and appliesswiftformat organizeDeclarationsMARKs toTimeReferenceandTracer+Metrics— the only two files that were failing lint onmain.Split into 8 logical commits, each of which builds on its own.
Rebased onto
mainafter #67.🤖 Generated with Claude Code