perf(tracer): stop rebuilding span metadata on every request - #3970
Conversation
8314316 to
4cb76fd
Compare
|
Reviewed against
|
NitinKumar004
left a comment
There was a problem hiding this comment.
The caching direction is reasonable, but as written this introduces a remotely-triggerable unbounded-memory DoS. Blocking on that.
🔴 Blocker — unbounded span cache → remote OOM
tracerSpanCache is a package-global sync.Map keyed on (method, route-template) with no eviction. The safety claim is that only bounded route templates are cached and raw/unmatched paths never are — but that guard is dead in a real GoFr app:
- GoFr registers a catch-all
router.PathPrefix("/"), somux.CurrentRoute(r)is set for every request andGetPathTemplate()returns("/", nil)even for unknown paths (verified with methodZZZQUUX, path/totally/unknown). Sotemplated == truealways, and everything is cached under{method, "/"}. method = strings.ToUpper(r.Method)is not restricted — Go's server accepts any RFC-7230 method token. An unauthenticated client streaming distinct methods (M00001,M00002, …) mints a permanent*spanMetaeach → resident memory grows without bound → OOM.
The pre-PR fmt.Sprintf path retained zero state, so this DoS vector is newly introduced, and the "no behaviour change / deliberately never cached" claims don't hold. Fix: don't cache the / catch-all (or any prefix catch-all); and/or cap+evict; and/or only cache routes registered via explicit Methods().Path().
Medium
BenchmarkTracermeasures the recording path, not the documented non-recording path. A prior test (TestTracerPropagatesIncomingTraceContext) installs a live recordingTracerProviderand never restores noop; tests run before benchmarks, soBenchmarkTracerruns withIsRecording()==trueand feeds the leaked in-memory exporter. The "non-recording: 13 allocs" headline only reproduces in isolation. Installnoop.NewTracerProvider()withb.Cleanup, likeBenchmarkTracer_Recording.
Low
- The
IsRecording()-gated non-recording branch (the path this PR optimizes) has no test. TestTracerPropagatesIncomingTraceContextalso leaks the globalTextMapPropagator(Baggage-less) with noCleanup, making the suite order-dependent.buildSpanNamegodoc + test enshrine a44.3 → 22.6 ns/opfigure that no shipped benchmark can reproduce (thefmt.Sprintfbaseline was removed).
⚠️ Cross-PR (HIGH, coordinate with #3972)
This is not the only cache with this shape. #3972 adds optionRecorder.cache (bounded 4096) and attrsRecorder.cache (unbounded) on the same (path, method, status) key space. The same malicious stream inflates all three. Fixing this cache in isolation is insufficient — bound all three consistently, reviewed as one unit. Also overlaps #3770 in the StatusResponseWriter block.
Requested changes: eliminate the unbounded-cache DoS (blocker); fix the benchmark + propagator leaks; add a non-recording test; and coordinate cache-bounding with #3972.
Addresses the blocker on #3970. tracerSpanCache was a package-global sync.Map with no eviction, and its safety argument - "only bounded route templates are cached" - did not survive contact with a real GoFr app. gofr.go registers a PathPrefix("/") catch-all, so mux.CurrentRoute is set for every request and GetPathTemplate() returns "/" even for a path nothing matched. The templated guard is therefore true always, and the route half of the key is not the bound it looked like. Reproduced: method "ZZZQUUX" on "/totally/unknown" resolves templated=true, route="/". The method half is worse. net/http accepts any RFC 7230 token, so an unauthenticated client streaming M00001, M00002, ... minted a permanent *spanMeta per request. Reproduced: 5000 distinct methods against the catch-all produced 5000 permanent entries. The pre-cache fmt.Sprintf path retained no state, so this was introduced by the cache rather than inherited. Two things now bound it. cacheableMethod restricts the key to the nine defined HTTP methods, which turns "methods x routes" back into the fixed quantity the cache was designed around; a request with a made-up method still works, it just rebuilds its span metadata as every request did before the cache existed. routeCache then caps the whole thing at 4096 entries, because the first bound is an argument about reachability and process memory should rest on a number too. routeCache and cacheableMethod live in their own file because the metrics caches in #3972 have the same shape on the same attacker-influenced key space, and the reviewer asked for all three to be bounded consistently rather than one at a time. BenchmarkTracer documented the non-recording path but did not measure it: TestTracerPropagatesIncomingTraceContext installs a live recording provider and never restored it, and tests run before benchmarks, so the benchmark ran recording and fed that test's in-memory exporter. Both globals it replaces are restored now, and the benchmark pins the noop provider itself. It reports 11 allocs/op on the path it describes. The non-recording branch this PR optimizes had no test; it has one now. buildSpanName's godoc no longer quotes a 44.3 -> 22.6 ns/op figure that nothing in the tree can reproduce, since the fmt.Sprintf baseline it was measured against is gone.
7c3d4ab to
4eed1cc
Compare
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
Umang01-hash
left a comment
There was a problem hiding this comment.
Strong, careful perf PR — I verified the risky parts hold: the shared per-route spanMeta cache is concurrency-safe (trace.WithAttributes only reads the cached slice; otel applies it via append(cfg.attributes, o...), and -race passes), the IsRecording gate is correct (http_server.go registers Tracer before Logging, so Tracer is outermost and the old StatusResponseWriter assertion always failed — the stale comment was wrong), and the tracer cache is genuinely DoS-bounded (cacheableMethod + routeCacheLimit). gofmt/vet/-race/benchmarks all green. One regression to fix before merge, plus two notes.
Baggage-loss regression (introduced here) — please fix
headerCarrier replaces propagation.HeaderCarrier but implements only Get/Set/Keys, not Values(string) []string. In otel v1.45.0, propagation.Baggage.Extract type-asserts the carrier to ValuesGetter — the stdlib HeaderCarrier satisfies it and combines all Baggage header values; headerCarrier fails the assertion, so Extract falls back to single-value Get("baggage") and silently drops every baggage member after the first when a request carries multiple Baggage headers (legal per W3C; commonly emitted by proxies/meshes). GoFr installs propagation.Baggage in the default composite propagator, so this is live.
Reproduced locally: stdlib carrier → 2 members, headerCarrier → 1. TestHeaderCarrierMatchesHeaderCarrier only compares Get/Keys, so it doesn't catch it. Fix is one line:
func (c headerCarrier) Values(key string) []string { return http.Header(c).Values(key) }plus a multi-Baggage equivalence assertion. A custom carrier replacing a stdlib one needs to be a faithful drop-in.
Note — the metrics sibling DoS (metrics.go routeAttrs) is still open
Not introduced here, and your commit message already calls it out for #3972 (the reusable routeCache is built for exactly this). Just flagging that it's the same live unbounded-key DoS — an unauthenticated client streaming distinct RFC-7230 method tokens grows routeAttrs without bound (repro'd ~61MB/200k requests). Landing this without #3972 leaves that hole open, so it'd be good to land them together or back-to-back.
Nit — benchmark doesn't exercise headerCarrier
BenchmarkTracer/_Recording set no propagation headers, so they never hit the canonicalization optimization — the measured alloc delta is from the cache + IsRecording only. The headerCarrier win is real by inspection but unproven by the bench; a header-bearing variant would close that.
No breaking API change (all new symbols unexported). Nice work overall — the DoS analysis in the doc comments is excellent.
… not lost Addresses review on #3970. headerCarrier replaces propagation.HeaderCarrier to avoid canonicalizing the lookup key on every request, but implemented only Get/Set/Keys. The stdlib type it replaces also satisfies propagation.ValuesGetter, and propagation.Baggage.Extract type-asserts to that interface to combine ALL values of the Baggage header. The assertion failed, so Extract fell back to the single-value Get and silently dropped every baggage member after the first. It only shows up when a request carries more than one Baggage header, which is legal per W3C and is what proxies and service meshes commonly emit, and GoFr installs propagation.Baggage in its default composite propagator - so the path is live. Reproduced against the stdlib carrier with three Baggage headers: stdlib extracted 3 members, headerCarrier extracted 1. The pre-existing equivalence test compared only Get and Keys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied. Values deliberately does not use the canonical-key fast path: baggage is not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimization second. BenchmarkTracer and BenchmarkTracer_Recording send a bare request, so the propagators find nothing and the canonicalization this PR avoids never runs - their delta is the per-route cache and the IsRecording gate alone. BenchmarkTracer_WithPropagationHeaders sends traceparent, tracestate and two Baggage headers, which is what a service behind a mesh actually receives and the only shape where the carrier's saving is visible. The propagator lookup keys are constants now rather than three repeated string literals.
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
Addresses the blocker on #3970. tracerSpanCache was a package-global sync.Map with no eviction, and its safety argument - "only bounded route templates are cached" - did not survive contact with a real GoFr app. gofr.go registers a PathPrefix("/") catch-all, so mux.CurrentRoute is set for every request and GetPathTemplate() returns "/" even for a path nothing matched. The templated guard is therefore true always, and the route half of the key is not the bound it looked like. Reproduced: method "ZZZQUUX" on "/totally/unknown" resolves templated=true, route="/". The method half is worse. net/http accepts any RFC 7230 token, so an unauthenticated client streaming M00001, M00002, ... minted a permanent *spanMeta per request. Reproduced: 5000 distinct methods against the catch-all produced 5000 permanent entries. The pre-cache fmt.Sprintf path retained no state, so this was introduced by the cache rather than inherited. Two things now bound it. cacheableMethod restricts the key to the nine defined HTTP methods, which turns "methods x routes" back into the fixed quantity the cache was designed around; a request with a made-up method still works, it just rebuilds its span metadata as every request did before the cache existed. routeCache then caps the whole thing at 4096 entries, because the first bound is an argument about reachability and process memory should rest on a number too. routeCache and cacheableMethod live in their own file because the metrics caches in #3972 have the same shape on the same attacker-influenced key space, and the reviewer asked for all three to be bounded consistently rather than one at a time. BenchmarkTracer documented the non-recording path but did not measure it: TestTracerPropagatesIncomingTraceContext installs a live recording provider and never restored it, and tests run before benchmarks, so the benchmark ran recording and fed that test's in-memory exporter. Both globals it replaces are restored now, and the benchmark pins the noop provider itself. It reports 11 allocs/op on the path it describes. The non-recording branch this PR optimizes had no test; it has one now. buildSpanName's godoc no longer quotes a 44.3 -> 22.6 ns/op figure that nothing in the tree can reproduce, since the fmt.Sprintf baseline it was measured against is gone.
f4512ad to
a09f4f6
Compare
… not lost Addresses review on #3970. headerCarrier replaces propagation.HeaderCarrier to avoid canonicalizing the lookup key on every request, but implemented only Get/Set/Keys. The stdlib type it replaces also satisfies propagation.ValuesGetter, and propagation.Baggage.Extract type-asserts to that interface to combine ALL values of the Baggage header. The assertion failed, so Extract fell back to the single-value Get and silently dropped every baggage member after the first. It only shows up when a request carries more than one Baggage header, which is legal per W3C and is what proxies and service meshes commonly emit, and GoFr installs propagation.Baggage in its default composite propagator - so the path is live. Reproduced against the stdlib carrier with three Baggage headers: stdlib extracted 3 members, headerCarrier extracted 1. The pre-existing equivalence test compared only Get and Keys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied. Values deliberately does not use the canonical-key fast path: baggage is not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimization second. BenchmarkTracer and BenchmarkTracer_Recording send a bare request, so the propagators find nothing and the canonicalization this PR avoids never runs - their delta is the per-route cache and the IsRecording gate alone. BenchmarkTracer_WithPropagationHeaders sends traceparent, tracestate and two Baggage headers, which is what a service behind a mesh actually receives and the only shape where the carrier's saving is visible. The propagator lookup keys are constants now rather than three repeated string literals.
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
91861bc to
02dd5b2
Compare
Addresses the blocker on #3970. tracerSpanCache was a package-global sync.Map with no eviction, and its safety argument - "only bounded route templates are cached" - did not survive contact with a real GoFr app. gofr.go registers a PathPrefix("/") catch-all, so mux.CurrentRoute is set for every request and GetPathTemplate() returns "/" even for a path nothing matched. The templated guard is therefore true always, and the route half of the key is not the bound it looked like. Reproduced: method "ZZZQUUX" on "/totally/unknown" resolves templated=true, route="/". The method half is worse. net/http accepts any RFC 7230 token, so an unauthenticated client streaming M00001, M00002, ... minted a permanent *spanMeta per request. Reproduced: 5000 distinct methods against the catch-all produced 5000 permanent entries. The pre-cache fmt.Sprintf path retained no state, so this was introduced by the cache rather than inherited. Two things now bound it. cacheableMethod restricts the key to the nine defined HTTP methods, which turns "methods x routes" back into the fixed quantity the cache was designed around; a request with a made-up method still works, it just rebuilds its span metadata as every request did before the cache existed. routeCache then caps the whole thing at 4096 entries, because the first bound is an argument about reachability and process memory should rest on a number too. routeCache and cacheableMethod live in their own file because the metrics caches in #3972 have the same shape on the same attacker-influenced key space, and the reviewer asked for all three to be bounded consistently rather than one at a time. BenchmarkTracer documented the non-recording path but did not measure it: TestTracerPropagatesIncomingTraceContext installs a live recording provider and never restored it, and tests run before benchmarks, so the benchmark ran recording and fed that test's in-memory exporter. Both globals it replaces are restored now, and the benchmark pins the noop provider itself. It reports 11 allocs/op on the path it describes. The non-recording branch this PR optimizes had no test; it has one now. buildSpanName's godoc no longer quotes a 44.3 -> 22.6 ns/op figure that nothing in the tree can reproduce, since the fmt.Sprintf baseline it was measured against is gone.
… not lost Addresses review on #3970. headerCarrier replaces propagation.HeaderCarrier to avoid canonicalizing the lookup key on every request, but implemented only Get/Set/Keys. The stdlib type it replaces also satisfies propagation.ValuesGetter, and propagation.Baggage.Extract type-asserts to that interface to combine ALL values of the Baggage header. The assertion failed, so Extract fell back to the single-value Get and silently dropped every baggage member after the first. It only shows up when a request carries more than one Baggage header, which is legal per W3C and is what proxies and service meshes commonly emit, and GoFr installs propagation.Baggage in its default composite propagator - so the path is live. Reproduced against the stdlib carrier with three Baggage headers: stdlib extracted 3 members, headerCarrier extracted 1. The pre-existing equivalence test compared only Get and Keys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied. Values deliberately does not use the canonical-key fast path: baggage is not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimization second. BenchmarkTracer and BenchmarkTracer_Recording send a bare request, so the propagators find nothing and the canonicalization this PR avoids never runs - their delta is the per-route cache and the IsRecording gate alone. BenchmarkTracer_WithPropagationHeaders sends traceparent, tracestate and two Baggage headers, which is what a service behind a mesh actually receives and the only shape where the carrier's saving is visible. The propagator lookup keys are constants now rather than three repeated string literals.
a09f4f6 to
9e20256
Compare
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
02dd5b2 to
cc8b654
Compare
Addresses the blocker on #3970. tracerSpanCache was a package-global sync.Map with no eviction, and its safety argument - "only bounded route templates are cached" - did not survive contact with a real GoFr app. gofr.go registers a PathPrefix("/") catch-all, so mux.CurrentRoute is set for every request and GetPathTemplate() returns "/" even for a path nothing matched. The templated guard is therefore true always, and the route half of the key is not the bound it looked like. Reproduced: method "ZZZQUUX" on "/totally/unknown" resolves templated=true, route="/". The method half is worse. net/http accepts any RFC 7230 token, so an unauthenticated client streaming M00001, M00002, ... minted a permanent *spanMeta per request. Reproduced: 5000 distinct methods against the catch-all produced 5000 permanent entries. The pre-cache fmt.Sprintf path retained no state, so this was introduced by the cache rather than inherited. Two things now bound it. cacheableMethod restricts the key to the nine defined HTTP methods, which turns "methods x routes" back into the fixed quantity the cache was designed around; a request with a made-up method still works, it just rebuilds its span metadata as every request did before the cache existed. routeCache then caps the whole thing at 4096 entries, because the first bound is an argument about reachability and process memory should rest on a number too. routeCache and cacheableMethod live in their own file because the metrics caches in #3972 have the same shape on the same attacker-influenced key space, and the reviewer asked for all three to be bounded consistently rather than one at a time. BenchmarkTracer documented the non-recording path but did not measure it: TestTracerPropagatesIncomingTraceContext installs a live recording provider and never restored it, and tests run before benchmarks, so the benchmark ran recording and fed that test's in-memory exporter. Both globals it replaces are restored now, and the benchmark pins the noop provider itself. It reports 11 allocs/op on the path it describes. The non-recording branch this PR optimizes had no test; it has one now. buildSpanName's godoc no longer quotes a 44.3 -> 22.6 ns/op figure that nothing in the tree can reproduce, since the fmt.Sprintf baseline it was measured against is gone.
… not lost Addresses review on #3970. headerCarrier replaces propagation.HeaderCarrier to avoid canonicalizing the lookup key on every request, but implemented only Get/Set/Keys. The stdlib type it replaces also satisfies propagation.ValuesGetter, and propagation.Baggage.Extract type-asserts to that interface to combine ALL values of the Baggage header. The assertion failed, so Extract fell back to the single-value Get and silently dropped every baggage member after the first. It only shows up when a request carries more than one Baggage header, which is legal per W3C and is what proxies and service meshes commonly emit, and GoFr installs propagation.Baggage in its default composite propagator - so the path is live. Reproduced against the stdlib carrier with three Baggage headers: stdlib extracted 3 members, headerCarrier extracted 1. The pre-existing equivalence test compared only Get and Keys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied. Values deliberately does not use the canonical-key fast path: baggage is not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimization second. BenchmarkTracer and BenchmarkTracer_Recording send a bare request, so the propagators find nothing and the canonicalization this PR avoids never runs - their delta is the per-route cache and the IsRecording gate alone. BenchmarkTracer_WithPropagationHeaders sends traceparent, tracestate and two Baggage headers, which is what a service behind a mesh actually receives and the only shape where the carrier's saving is visible. The propagator lookup keys are constants now rather than three repeated string literals.
9e20256 to
16ee698
Compare
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
|
Both blocking findings are fixed. Re-requesting review — the @NitinKumar004 — unbounded span cache → remote OOMYour analysis was exactly right, including the part that made it dangerous: the Two bounds now, because the first is an argument about reachability and process memory should rest on a number too:
Verified on the current head: You also asked that this be coordinated with #3972 rather than fixed in isolation. It is: The other items are done too — @Umang01-hash —
|
Sprintf walks a format string and boxes two arguments that are already strings, to produce a value that concatenation produces directly. Measured by BenchmarkBuildSpanName at the real call site: before 44.33 ns/op 16 B/op 1 allocs/op after 22.61 ns/op 16 B/op 1 allocs/op This is a CPU saving only, not an allocation saving. Both forms pay the one unavoidable allocation for the result string, because the span name escapes into the span; runtime.concatstrings only uses its 32-byte stack buffer when escape analysis proves the result stays in the frame. The span name and http.route attribute are unchanged, and are now pinned by tests rather than left implicit. (cherry picked from commit 9b03ddfc79c1c2bbe7cf7d72d753a9bebbbcc600)
A non-recording span discards SetAttributes by contract, but the call still builds the variadic []attribute.KeyValue to hand it. GoFr installs an SDK provider with NeverSample when no TRACE_EXPORTER is configured, so on the default deployment that slice was allocated and thrown away on every single request. Measured by a Tracer middleware benchmark under NeverSample: before 2072 B/op 19 allocs/op after 2008 B/op 18 allocs/op Recording spans are unaffected: the status attribute is still set, and is now pinned by TestTracerStatusAttributeStillRecorded. The implicit-200 normalization established by #3431 is pinned by TestTracerImplicit200StillRecorded. (cherry picked from commit aba7cbfffee78119a254c4d223bb24f438696a27)
The span name and the http.route attribute set are pure functions of
(method, route template), yet both were rebuilt on every request: one
string allocation for the name and one slice allocation for the
attributes handed to trace.WithAttributes.
They are now built once per (method, route) and reused, following the
routeAttrs cache already used by metrics.go.
Measured by a Tracer middleware benchmark under NeverSample:
before 2008 B/op 18 allocs/op
after 1864 B/op 16 allocs/op
Cumulative across this stack: 2072 B / 19 allocs -> 1864 B / 16 allocs.
Two safety properties, both tested:
* The cache is keyed on the route TEMPLATE, so 500 concrete paths
through /users/{id} produce one entry. An unmatched request carries a
raw, attacker-controlled path and is deliberately never cached, which
is what keeps the cache bounded by routes x methods.
* The attributes are still passed to Start rather than applied after
it. A sampler can read attributes when deciding, so applying them
later would silently change sampling for anyone sampling on
http.route.
The cache is package level because the middleware chain is rebuilt around
the matched handler on every request, so a closure-owned cache would be discarded
each time. Its contents are pure data and provider-independent, so it
stays correct across TracerProvider replacement.
(cherry picked from commit c680c5544438476d60e9b44bc4d37678eecaf60e)
Caching the attribute slice still left two allocations per request: trace.WithAttributes builds an option wrapper around the slice, and passing it to Start builds the variadic []trace.SpanStartOption. Both are immutable once constructed and both are pure functions of (method, route), so they belong in the same per-route cache. Measured by a Tracer middleware benchmark under NeverSample: before 1864 B/op 16 allocs/op after 1824 B/op 14 allocs/op Cumulative across this file: 2072 B / 19 allocs -> 1824 B / 14 allocs. The attributes are still supplied at Start rather than applied afterwards, so sampler behaviour is unchanged for anyone sampling on http.route. (cherry picked from commit 397a7fb510a3f9ebe780cf5d8e3836045fd2d1f1)
…request The W3C propagators look their headers up by the lowercase names from the specs -- "traceparent", "tracestate", "baggage" -- and propagation.HeaderCarrier forwards those to http.Header.Get, which canonicalizes whatever key it is handed. None of those names is already canonical, so every request allocated the canonical string, whether or not the header was present at all. The canonical spellings are constants, so they are resolved once and the carrier reads the header map directly. A key the carrier does not recognize falls through to the ordinary lookup, so a propagator using its own header names -- B3, Jaeger, anything user-installed -- keeps working. TestHeaderCarrierMatchesHeaderCarrier pins that it resolves exactly what propagation.HeaderCarrier resolves, including for an unrecognized key and an absent one. TestTracerPropagatesIncomingTraceContext pins the behaviour that matters: an incoming traceparent is still adopted as the parent span. (cherry picked from commit 76a9accceb90c61d0c9d63f82ba3d839f2aaad1d)
The status wrapper existed solely to put http.response.status_code on the span, but it was created on every request regardless of whether any span would keep it. Two things made that worse than it looks. Tracer is the outermost middleware, so the StatusResponseWriter that Logging installs does not exist yet and the type assertion always failed -- meaning the fallback allocated a fresh wrapper every request rather than the "uncommon" case the old comment described. And GoFr installs an SDK provider with NeverSample when no TRACE_EXPORTER is configured, so on the default deployment nothing ever read it. The wrapper and its deferred attribute are now inside the IsRecording check, which is known immediately after Start. A recording span still gets the wrapper and the attribute, including the implicit-200 normalization, pinned by TestTracerStatusAttributeStillRecorded and TestTracerImplicit200StillRecorded. (cherry picked from commit 73b87213c044ce6889340df3a81e14865cc390ba)
The change caches the span name, attributes and start option per route so they are not rebuilt on every request. Nothing measured that, and one benchmark alone would have been misleading: a service that samples runs both a recording and a non-recording provider, and the middleware must not be quietly worse in either. Two benchmarks, so both paths are covered: BenchmarkTracer non-recording 21 -> 13 allocs/op, 2074 -> 1760 B/op BenchmarkTracer_Recording recording 23 -> 17 allocs/op, 2875 -> 2657 B/op Only allocation counts are quoted. Wall-clock on the machine these were taken on varied by more than 5x between runs of the same binary, so ns/op there says nothing; the allocation counts were stable and moved monotonically with each commit in the series. Also repairs the comment on the cache, which had been scrambled so that a nolint directive split the sentence explaining why the cache is package level.
buildSpanName was inserted directly above methodKV, so methodKV's entire doc -- the semconv rationale and the escape-analysis note -- ended up documenting buildSpanName instead, and methodKV was left with none. Moves buildSpanName below methodKV. No code change.
Addresses the blocker on #3970. tracerSpanCache was a package-global sync.Map with no eviction, and its safety argument - "only bounded route templates are cached" - did not survive contact with a real GoFr app. gofr.go registers a PathPrefix("/") catch-all, so mux.CurrentRoute is set for every request and GetPathTemplate() returns "/" even for a path nothing matched. The templated guard is therefore true always, and the route half of the key is not the bound it looked like. Reproduced: method "ZZZQUUX" on "/totally/unknown" resolves templated=true, route="/". The method half is worse. net/http accepts any RFC 7230 token, so an unauthenticated client streaming M00001, M00002, ... minted a permanent *spanMeta per request. Reproduced: 5000 distinct methods against the catch-all produced 5000 permanent entries. The pre-cache fmt.Sprintf path retained no state, so this was introduced by the cache rather than inherited. Two things now bound it. cacheableMethod restricts the key to the nine defined HTTP methods, which turns "methods x routes" back into the fixed quantity the cache was designed around; a request with a made-up method still works, it just rebuilds its span metadata as every request did before the cache existed. routeCache then caps the whole thing at 4096 entries, because the first bound is an argument about reachability and process memory should rest on a number too. routeCache and cacheableMethod live in their own file because the metrics caches in #3972 have the same shape on the same attacker-influenced key space, and the reviewer asked for all three to be bounded consistently rather than one at a time. BenchmarkTracer documented the non-recording path but did not measure it: TestTracerPropagatesIncomingTraceContext installs a live recording provider and never restored it, and tests run before benchmarks, so the benchmark ran recording and fed that test's in-memory exporter. Both globals it replaces are restored now, and the benchmark pins the noop provider itself. It reports 11 allocs/op on the path it describes. The non-recording branch this PR optimizes had no test; it has one now. buildSpanName's godoc no longer quotes a 44.3 -> 22.6 ns/op figure that nothing in the tree can reproduce, since the fmt.Sprintf baseline it was measured against is gone.
… not lost Addresses review on #3970. headerCarrier replaces propagation.HeaderCarrier to avoid canonicalizing the lookup key on every request, but implemented only Get/Set/Keys. The stdlib type it replaces also satisfies propagation.ValuesGetter, and propagation.Baggage.Extract type-asserts to that interface to combine ALL values of the Baggage header. The assertion failed, so Extract fell back to the single-value Get and silently dropped every baggage member after the first. It only shows up when a request carries more than one Baggage header, which is legal per W3C and is what proxies and service meshes commonly emit, and GoFr installs propagation.Baggage in its default composite propagator - so the path is live. Reproduced against the stdlib carrier with three Baggage headers: stdlib extracted 3 members, headerCarrier extracted 1. The pre-existing equivalence test compared only Get and Keys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied. Values deliberately does not use the canonical-key fast path: baggage is not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimization second. BenchmarkTracer and BenchmarkTracer_Recording send a bare request, so the propagators find nothing and the canonicalization this PR avoids never runs - their delta is the per-route cache and the IsRecording gate alone. BenchmarkTracer_WithPropagationHeaders sends traceparent, tracestate and two Baggage headers, which is what a service behind a mesh actually receives and the only shape where the carrier's saving is visible. The propagator lookup keys are constants now rather than three repeated string literals.
…an design Rebasing onto #3770 replays this branch's tracer.go and tracer_test.go over #3770's, which drops #3770's twelve tracer characterization tests wholesale. All twelve are restored here unchanged - they exercise the middleware through its exported surface and are indifferent to whether the span metadata is cached. Test_TracerContract_ReusesStatusResponseWriter is the one that matters most: it pins the StatusResponseWriter block this branch wraps in the IsRecording gate, which is the overlap the review flagged as the place a careless merge resolution would silently drop the gate. It passes against the gated code, and the gate is verified present.
16ee698 to
9aee0c9
Compare
Addresses review on #3972. Both caches now go through the routeCache introduced for the span cache in #3970, under the same rules, because all three sit on the same attacker-influenced key space and bounding them one at a time does not help - one malicious request stream inflates whichever is left unbounded. attrsRecorder.cache had no ceiling at all while its sibling had one. Only a templated route may be cached now. Every branch of the path label that falls back to r.URL.Path yields a caller-controlled string - an unmatched route, a static-asset extension, /static, and the "/" template GoFr's PathPrefix("/") catch-all produces for every unmatched request. Those used to be cached, so a stream of unique unmatched paths filled the cache to its ceiling, after which every first-seen legitimate route could never be stored and rebuilt its measurement option per request forever. Memory stayed bounded and correctness was unaffected, but the optimization silently reverted to baseline for production traffic. The method half is filtered too, for the reason given in cacheableMethod: a bounded route with an unbounded method reopens the same growth. The fast path all production traffic uses now has label assertions. metricsManager implements RecordHistogramOpt, so requests flow through optionRecorder, yet nothing pinned what it emitted. Changing status from attribute.String to attribute.Int, or emitting the concrete path instead of the route template, left every test green while dashboards broke and cardinality exploded. Both are now caught - verified by making each change and watching the test fail. TestMetricsOptCacheIsBounded asserted that a compile-time constant was positive, so deleting the ceiling kept it green. It drives more than the limit in distinct keys through record() and inspects the cache size now; deleting the ceiling fails it, TestRouteCacheStopsAtItsLimit and TestAttrsRecorderIsCorrectAndBounded together. attrsRecorder was at zero coverage - no in-tree type selects it, since *metricsManager implements both optional interfaces and optionRecorder wins - and now has direct tests for its labels, its reuse and its bound. The "-650 B/request" figure is dropped. The shipped benchmarks give BenchmarkRecordHistogramAttrs at 424 B/op and 4 allocs/op against BenchmarkRecordHistogramOpt at 0 B/op and 0 allocs/op, with BenchmarkAttrBuild_HTTP at 448 B/op for the attribute build a cache hit also avoids. Those are the numbers the PR body now quotes.
|
Rebased onto current Requested changes, and where they landed
Worth noting the two reviews reached opposite conclusions on the cache: the blocker was filed on 18 Aug, and the independent verification that it is bounded ( Re-measured on today's development, not on the tree this PR was written against#3974 shipped in v1.60.0 and reworked the same request path, so the original numbers no longer describe the baseline. Same benchmarks, same machine, development's production code vs this branch,
The wins survive the rebase, and the propagation-header case — the one the earlier benchmarks could not see — is the largest of the three at −10 allocations per request. Baseline taken by reverting only Verification
Still true, and not for this PRThe metrics-side sibling ( |
Umang01-hash
left a comment
There was a problem hiding this comment.
Ran it locally end to end — drove real requests through the Tracer with a live OTel export pipeline and the spans come out right: /users/42 and /users/99 both land on GET /users/{id} sharing the cached meta, no attribute bleed across routes, correct method/route/status. -race is clean and I confirmed the shared attr slices aren't mutated by OTel.
The win is real: cached path measures 0 allocs/0 B vs 5 allocs/256 B when rebuilt per request. Also checked the diff against development — the semconv keys and the METHOD /route span name already shipped earlier, so this really is behaviour-identical like the description says.
The baggage Values() fix is a nice catch and the test that sends multiple Baggage headers and compares against the stdlib carrier proves it. CI's green. LGTM.
One tiny thing, non-blocking: meta, _ := v.(*spanMeta) could rebuild-on-miss instead of ignoring the assert. And separately (not this PR) rbac/solr still emit the old http.method/http.status_code keys — might be worth a follow-up to make semconv consistent.
…pled writer Two points from @PiyushSingh-ZS's review. spanMeta carried an attrs field that newSpanMeta filled and nothing in the middleware ever read -- startOpts is the only consumer, and it is built from the same slice. It read as though something still depended on it. Dropped, along with the doc comment that described it. Two tests did read it. Both now resolve the start options the way the SDK does, via trace.NewSpanStartConfig(...).Attributes(), which asserts the attributes the span will actually carry rather than a field the request path does not touch. The IsRecording gate also deserved a note it did not have. Skipping the StatusResponseWriter wrap on a non-recording span means the writer that reaches the next middleware now depends on whether the span records. GoFr's own chain is unaffected -- Logging wraps immediately after and Metrics reuses that wrapper -- but a user middleware placed between Tracer and Logging that type-asserts *StatusResponseWriter sees it on a sampled request and not on an unsampled one. The comment says so now, because the symptom would be near impossible to trace back. No behaviour change and no allocation change: BenchmarkTracer 1568 B/op 11 allocs/op BenchmarkTracer_Recording 2657 B/op 17 allocs/op BenchmarkTracer_WithPropagation 3721 B/op 30 allocs/op identical to before the edit. Package tests pass under -race.
…rning nil @Umang01-hash's non-blocking note. The cache lookup discarded the type assertion's ok: meta, _ := v.(*spanMeta) return meta A failed assertion returns nil, and every caller dereferences the result on the request path. Nothing else stores into tracerSpanCache, so it cannot fail today -- but the shape means a future change that broke that invariant would surface as a nil dereference serving traffic rather than as a cache miss. It now falls through to the rebuild the miss path already performs, which is what an uncacheable route does anyway. No allocation change: BenchmarkTracer stays at 1568 B/op, 11 allocs/op. Package tests pass under -race.
The cached-option branch discarded the type assertion's ok:
opts, _ := v.([]metric.RecordOption)
o.rec.RecordHistogramOpt(ctx, histogramName, seconds, opts...)
A failed assertion leaves opts nil, and recording with no options emits
the measurement with NO attributes -- an unlabelled time series that
looks like a working metric and silently corrupts whatever queries it.
That is worse than the nil dereference the same shape produced in the
tracer cache, because nothing fails loudly.
Nothing else stores into this cache, so it cannot fail today. It now
falls through to the rebuild the miss path already performs, matching
what spanMetaFor does since #3970.
attrsRecorder already handled this correctly -- its assertion is followed
by an `if b == nil` rebuild -- so only the option path changed.
No behaviour or allocation change: BenchmarkRecordHistogramOpt stays at
0 B/op, 0 allocs/op. pkg/gofr/http/middleware and pkg/gofr/metrics pass
under -race.
TL;DR — 8 fewer allocations per request. No behaviour change.
The problem
The tracing middleware runs on every request. For each one it rebuilt things that never change for a given route:
"GET /users/{id}") — viafmt.Sprintfhttp.request.method,http.route)trace.WithAttributesoption wrapper and the variadic slice holding itFor a fixed route table, all of that produces byte-identical results every single time.
The fix
Build it once per
(method, route)and reuse it. Six focused commits, one idea each.Cache key is the route template (
/users/{id}), never the concrete path. Unmatched requests carry a raw, attacker-controlled path and are never cached.The numbers
Two benchmarks ship with this, because a sampling service runs both paths and neither may regress:
Allocation counts only — see Measurement below.
Why it matters
Tracing is on the hot path of every request in every GoFr service. This is the single largest per-request allocation saving in the middleware chain.
Baggage regression, found in review and fixed
headerCarrierreplacespropagation.HeaderCarrierto avoid canonicalising the lookup key per request — but implemented onlyGet/Set/Keys. The stdlib type it replaces also satisfiespropagation.ValuesGetter, andpropagation.Baggage.Extracttype-asserts to that interface to combine all values of theBaggageheader. The assertion failed, soExtractfell back to the single-valueGetand silently dropped every baggage member after the first.It only surfaces when a request carries more than one
Baggageheader — legal per W3C, and what proxies and service meshes commonly emit — and GoFr installspropagation.Baggagein its default composite propagator, so the path is live. Reproduced against the stdlib carrier with threeBaggageheaders:Fixed by implementing
Values. It deliberately does not use the canonical-key fast path:baggageis not one of the keys that map covers, and a carrier replacing a stdlib one has to be a faithful drop-in first and an optimisation second.The pre-existing equivalence test compared only
GetandKeys, so it could not catch this. The new test compares extracted baggage member by member against the stdlib carrier across four header shapes, and asserts the interface is satisfied.BenchmarkTracer_WithPropagationHeaderscloses the other gap: the existing benchmarks send a bare request, so the propagators find nothing and the canonicalisation this PR avoids never runs — their delta is the per-route cache and theIsRecordinggate alone. The new one sendstraceparent,tracestateand twoBaggageheaders, which is what a service behind a mesh actually receives.What the cache costs
The saving is bought with resident memory: the cache is process-global and entries are never released, because they are pure functions of their key and stay valid for the life of the process.
Measured with
runtime.MemStatsaround a filled cache, stable across three runs:routeCacheLimitceilingSo a realistic service holds tens of kilobytes, and the worst case any service can reach is ~1.7 MB, permanently. That ceiling is the point of
routeCacheLimit— without it the table has no last row.It is a genuine trade rather than a free win, and it is the one thing in this PR that costs something. Weigh it against ~9 allocations saved on every request.
Safety
IsRecording()-gated non-recording branch — the path this PR optimizes — now has a test; it had none.buildSpanName's godoc no longer quotes a44.3 → 22.6 ns/opfigure: thefmt.Sprintfbaseline it was measured against is gone, so nothing in the tree can reproduce it.TracerProviderreplacement.Measurement
Only allocations and bytes are quoted. Wall-clock on the machine used varied by more than 5× between runs of the same binary, so ns/op there is meaningless. Allocation counts were stable and moved monotonically with each commit in the series.
Independent of the other
perf/*PRs — touches onlytracer.goand its test. Merge in any order.