From 88dd588123379b40c005a4b7ae5b3ae589aec81c Mon Sep 17 00:00:00 2001 From: rcourtman <8825017+rcourtman@users.noreply.github.com> Date: Thu, 24 Sep 2026 17:33:21 +0100 Subject: [PATCH] Stop timing the per-segment route normaliser The advisory Benchmarks check failed four pull requests on NormalizeSegment alone in the last 48 paired runs: #2217, #2225, #2252 and #2253. None of them touched the normaliser. On #2252 all five sub-benchmarks rose 25-39% together. Nine other runs moved the rows down by more than 10% instead, -20% to -28% on #2228, #2230 and #2242. Those 13 runs used EPYC 7763, EPYC 9V74 and Intel Xeon runners. The values are quantized. On EPYC 7763 short_name is 2.50ns or 3.12ns and uuid is about 29.6ns or 40.5ns, a cycle or two per call, or one per byte of the UUID scan. Go aligns these functions to 32 bytes, so a change anywhere earlier in the binary can move them between the halves of a 64-byte block. A 32-byte shift is enough: on pulse-dev, adding an unrelated init-time function ahead of the normaliser flipped that parity and failed the old tree the way #2252 did, all five rows +25% to +40% at p=0.000 and nothing else flagged. More samples cannot separate that from a real change, and batching does not help, because every call repeats the same instructions. The route-level rows do not behave this way. Over the same 48 runs no NormalizeRoute row except the root case retired in #2255 moved by more than 10%. with_uuid came closest at 9.2%. The guarantees the benchmark carried now live in deterministic tests. TestNormalizeSegment, TestLooksLikeUUID and TestIsNumeric already pin classification. TestNormalizeSegment_DoesNotAllocate pins zero allocations for the five former inputs, and fails with one allocation per call when the pass-through return copies the segment. It stores each result in a package-level sink: when normalizeSegment was cut down to an inlinable copy, a discarded result let the compiler keep short segments on the stack, and the test missed the allocation. Timing regressions still show in BenchmarkNormalizeRoute, since every path runs its segments through normalizeSegment. The proofs below are paired runs of the CI runner's recipe on pulse-dev, narrowed to ./internal/api/ and raised to 30 samples, because the shared host's load spread these rows by up to 25%, against about 1% on CI runners. - looksLikeUUID scanning twice: check-bench-regression.sh exited 1, flagging only NormalizeRoute/with_uuid, +13.7% (p=0.005). - normalizeSegment doing its work twice: exited 1, flagging only NormalizeRoute/with_uuid, +21.9% (p=0.030). - the candidate against a copy of itself: exited 0. - the candidate against itself plus the same init-time function: exited 0. The route rows still moved 4-5%, and with_uuid 9.2% (p=0.000). The margin for a UUID-scan slowdown is thin. On EPYC 7763 the scan is about 30ns of a 280ns with_uuid call, so doubling it reads as roughly +11% to +14%, while layout alone has moved with_uuid by up to 9.2% both on CI and in the probe above. Giving UUIDs a larger share of a route would make that row flip the way this one did; a smaller share would hide the slowdown. --- internal/api/http_metrics_bench_test.go | 37 ++++++------------------- internal/api/http_metrics_test.go | 20 +++++++++++++ 2 files changed, 28 insertions(+), 29 deletions(-) diff --git a/internal/api/http_metrics_bench_test.go b/internal/api/http_metrics_bench_test.go index 5d2e3fc813..7bb0c56670 100644 --- a/internal/api/http_metrics_bench_test.go +++ b/internal/api/http_metrics_bench_test.go @@ -14,11 +14,14 @@ import ( // BenchmarkNormalizeRoute measures route normalization with representative // API paths of varying complexity. // -// The "/" fast path is deliberately not timed here. Paired CI runs measured it -// at either 2.18ns or 2.50ns, about one CPU cycle apart, and changes that never -// touched this code flipped it both ways by 13-30%. -// TestNormalizeRoute_RootFastPathDoesNotAllocate pins what matters about the -// path instead. +// Neither the "/" fast path nor normalizeSegment is timed on its own. They +// take 2-40ns, and paired CI runs measured each at one of two values a CPU +// cycle or two apart, per call or per byte of the UUID scan. +// Changes that never touched this code flipped them both ways by 13-50%. +// Every path below runs its segments through normalizeSegment, so a real +// slowdown in segment classification still shows here, most in with_uuid. +// TestNormalizeRoute_RootFastPathDoesNotAllocate and +// TestNormalizeSegment_DoesNotAllocate pin the allocation guarantees. func BenchmarkNormalizeRoute(b *testing.B) { paths := []struct { name string @@ -135,30 +138,6 @@ func BenchmarkRecordAPIRequest_Parallel(b *testing.B) { }) } -// BenchmarkNormalizeSegment measures per-segment normalization for the three -// detection paths: numeric ID, UUID, and long token. -func BenchmarkNormalizeSegment(b *testing.B) { - segments := []struct { - name string - seg string - }{ - {"numeric_id", "12345"}, - {"uuid", "550e8400-e29b-41d4-a716-446655440000"}, - {"long_token", "abcdefghijklmnopqrstuvwxyz1234567890abcdef"}, - {"short_name", "resources"}, - {"medium_name", "metrics-store"}, - } - - for _, s := range segments { - b.Run(s.name, func(b *testing.B) { - b.ReportAllocs() - for i := 0; i < b.N; i++ { - _ = normalizeSegment(s.seg) - } - }) - } -} - // BenchmarkFullMiddlewarePath simulates the complete per-request overhead: // normalizeRoute + recordAPIRequest, as executed by the ErrorHandler middleware. // Uses r.URL.Path (no query params) matching the real middleware call site. diff --git a/internal/api/http_metrics_test.go b/internal/api/http_metrics_test.go index 3e6e98ab8a..9c68ab9038 100644 --- a/internal/api/http_metrics_test.go +++ b/internal/api/http_metrics_test.go @@ -192,6 +192,26 @@ func TestNormalizeSegment(t *testing.T) { } } +// normalizeSegment runs on every path segment of every request, and each class +// returns a constant label or the segment itself. The sink makes the result +// escape, as it does in normalizeRoute. Without it, an inlined normalizeSegment +// could copy a short segment into a stack buffer and hide the allocation. +var normalizeSegmentSink string + +func TestNormalizeSegment_DoesNotAllocate(t *testing.T) { + for _, seg := range []string{ + "12345", + "550e8400-e29b-41d4-a716-446655440000", + "abcdefghijklmnopqrstuvwxyz1234567890abcdef", + "resources", + "metrics-store", + } { + if allocs := testing.AllocsPerRun(100, func() { normalizeSegmentSink = normalizeSegment(seg) }); allocs != 0 { + t.Errorf("normalizeSegment(%q) allocated %v times per call, want 0", seg, allocs) + } + } +} + func TestNormalizeRoute(t *testing.T) { tests := []struct { name string