Remove field-map copying from default request access logs

perfloop-oss/skipper · AVOIDABLE COPY

https://perfloop.ai/t/oss/case_rrbfv2xa8m

Verdict

VERIFIED · settled 2026-10-07 · merged as zalando/skipper#4326

What happened: The paired measurements met the required improvement.

Hypothesis

Reduce memory spent producing default access logs without disabling logs or request filters. Ordinary configured inline replies, forwarded query requests and redirects can benefit once per completed logged request. Fixed fields currently pass through populated maps before text formatting. Avoiding that representation work could meet the preferred whole-request allocation target while preserving the existing logger's output pipeline. Net savings and behavior are unproved.

Required benefiting rows are the logged equivalents of native status(200)/inlineContent with ten-byte text, the same row with enableAccessLog(1,200,3), and the documented status(418)/28-byte inline recipe; plus the basics tutorial's GET / through setQuery("lang","pt") to its explicitly defined local backend replying twelve-byte Hello world!; plus common-use-cases GET /foo through redirectTo(308,"http://127.0.0.1:9999") and modPath("/","/my/new/base/") before that redirect. The redirect bodies are empty and Location is source-defined. These forwarding/redirect inputs and body sizes come independently from docs/tutorials/basics.md:289–336 and common-use-cases.md:5–119, not from arbitrary native-test payloads. Requests are origin-form HTTP/1.1 with empty bodies, curl User-Agent/Accept for tutorial rows, compiled routing and fresh response state. The network row uses a real warm persistent loopback backend; all rows require nonnil NewAccessLogger with default text and synchronous output to a real regular file. Setup stays outside recurring calls, but the complete handler,request/response filters,contexts,metrics,tracing,response close and log output stay inside.

Source at3a146625 binds the logger in WithParams and calls LogAccess once from ServeHTTP's deferred log selection. Its AccessEntry retains the incoming request. The required filters do not add access-log supplemental metadata, so empty data reaches this common route without an error/retry condition. createAccessLog chooses the private builtin formatter when custom/JSON options are absent. LogAccess then builds fourteen fields and derives WithFields/WithContext entries; the builtin formatter reads fixed positions. Installed pinned Logrus source confirms populated-map copies and a further final event snapshot. A map-free default message can leave the final Entry structure and actual emitter intact while avoiding those populated maps; selecting this path must be tied to construction mode, not merely visibility of a helper.

Measured exploratory whole-handler baselines are18115/19779/18075 B/op for the original logged inline rows. Final source-defined query and redirects observed25427/16690/18083 B/op,233/112/130 allocations, and106/108/108 log bytes per operation on Go1.27.1 linux/amd64,GOMAXPROCS1. The network query body's byte count/capitalization is fixed by the tutorial. Earlier external-site12B replays remain controls and are not this provenance. Exact allocation attribution on forwarding puts about1.6KiB in builder copies; initial map/boxes and final populated event copying add roughly another1.4–1.5KiB gross. Required source-defined query/pathredirect exact probes also found LogAccess13.46%/18.96%of process allocated bytes. These profiles include loopback server/transport/runtime work; they do not turn process bytes into handler-only bytes or sampled CPU shares into speedup ceilings. The final working-file captures hit the retention limit, so their later results are exploratory observations in this run, not downloadable Candidate proof. Case must reproduce them from the pinned definitions and specified rows.

Relevant removal is fixed per logged event, not payload copying: fourteen field entries and their materialized copies, about3KiB gross. It is a measured/inferred workload budget, not a claimed net gain. The common-path prior is supported by ordinary logger selection on these documented configurations; no rare error condition is required. In allocated-byte terms these maps are material beside the largest8KiB scratch allocation on the same operation, with the whole-handler profiles supplying attributable scale. Timing benefit and production share remain unknown. The direction is architecture-independent and adds no public operation,type,option or protocol.

Preserve timestamp/duration,remote-host handling,query behavior,field order,empty-string-to-dash rule,exact newline and all actual synchronized writes. Keep Logrus emission so buffer-pool integration,error diagnostics and synchronization across AccessLogger value copies and fallback calls remain. Use the same incoming Request context. Custom,JSON and nonempty supplemental calls retain the original field pipeline, including overrides,mask-map mutation and validation of unsupported values. Those are required regression controls, not benefiting population. Filter order,short circuits,contexts,status,headers,bodies and concurrent requests must remain unchanged; no request snapshot is recycled.

Require>=10%lower whole-handler B/op on every listed benefiting row, without time/op or allocation-count regressions. This gross budget can close those per-row gaps if net costs fit. Owned-entry construction is a subset,not a companion gain. The existing WriterTo guard addresses different response scratch on inline rows but has zero predicted eligibility on observed standard network bodies; it is not necessary for this log direction's bound. logging/access.go and logging/log.go are byte-identical at checked current upstreamf7d86904. Native JSON/custom context and upstream formatter/additional-data contributions constrain the fallback; the proposal changes only private implementation,not their contracts. Maintainer acceptance is unknown. Production distribution and weighted aggregate success remain unmeasured limits,not Case gates.

When the logger uses its private built-in text formatter and supplemental data is empty, the combined line depends only on the fixed AccessEntry/request fields. A per-call map-free message can retain Logrus's emission, context, global buffer-pool use, synchronized writes and errors; custom/JSON/supplemental calls can preserve the original pipeline unchanged.

Pair frozen baseline and Candidate at complete Proxy.ServeHTTP with real combined log output. Require >=10% lower whole-handler B/op on each required native two/three-filter inline row, documented418 inline row, basics setQuery/local12B network row and common-use-case one/two-filter308 redirect rows, without time/op or allocation-count regressions. Reject this implementation if replacement costs consume the budget or exact line/newline,field,query,context,selection,error,pool,value-copy synchronization,HTTP behavior or concurrent/race controls differ. JSON/custom/nonempty supplemental/map-mask/unsupported-field cases must keep current behavior and are fallback controls, not benefiting coverage. No production-frequency gate is required.

No optimized Candidate was implemented or measured. Earlier retained files preserve the original fixed-reply and forwarding-control profiles/fixtures. Their provisional stop is superseded by this expanded population and second mechanism. Final source-defined fixture/profile/file versions could not be recaptured after the16-distinct-file limit; exact later commands/results and source-grounded conditions remain in this run, and Case must reproduce baseline costs. No production weights or remote-site response distribution is inferred. Native logging/accesslog and focused filter/log controls passed; explicitly enabled TestStreaming passed. Unmodified TestAccessLogOnFailedRequest reproduced407 rather than502 with two persistent-connection goroutines; session egress interaction is suspected,not established. Full CI,lint,race,Candidate validation and classification remain. Earlier Oracle-only estimates and the final adviser's reported semantic probes(buffer pool,override/custom context,error,16concurrent calls/value copies) are unconfirmed reports,not parent-verified or Case proof. Parent independently verified the relevant pinned and installed-source mechanisms. The map-free representation/preserve-emitter design was adviser-suggested; expected net gain,escape costs and exact output parity remain open. Recent/in-flight search is bounded; no universal novelty or maintainer agreement is asserted.

Change to test: Format default combined access lines without constructing and copying populated field maps when supplemental data is empty, while retaining the same private Logrus emission, context, buffering and synchronized write/error path. Keep the existing fields-based path for JSON,custom formatters and supplemental data, with no new public API.

Where it lives

perfloop-oss/skipper · proxy/proxy.go

Evidence

Proxy.ServeHTTP with a logged status-200 inline response and 10-byte body · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 18115 15410 −14.9% (−2705) −2705 to −2705 < −1812 PASSED
ns/op 27727 23459 −15.3% (−4252) −6287 to −3409 ≤ 0 PASSED
allocs/op 127 108 −15% (−19) −19 to −19 ≤ 0 PASSED

Proxy.ServeHTTP with enableAccessLog(1,200,3), status 200 and 10-byte inline body · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 19779 17075 −13.7% (−2704) −2704 to −2704 < −1978 PASSED
ns/op 30713 26305 −14.6% (−4486) −6086 to −3504 ≤ 0 PASSED
allocs/op 143 124 −13.3% (−19) −19 to −19 ≤ 0 PASSED

Proxy.ServeHTTP with the documented status-418, 28-byte inline response · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 18091 15386 −15% (−2705) −2705 to −2705 < −1809 PASSED
ns/op 26766 23233 −13% (−3479) −5419 to −2418 ≤ 0 PASSED
allocs/op 128 109 −14.8% (−19) −19 to −19 ≤ 0 PASSED

Proxy.ServeHTTP for the basics setQuery(lang,pt) route and its 12-byte local backend response · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 25474 22753 −10.7% (−2721) −2721 to −2721 < −2547 PASSED
ns/op 173524 162305 −7.1% (−12370) −21913 to −8690 ≤ 0 PASSED
allocs/op 234 214 −8.5% (−20) −20 to −20 ≤ 0 PASSED

Proxy.ServeHTTP for the common-use-case GET /foo 308 redirect · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 16691 13970 −16.3% (−2721) −2721 to −2721 < −1669 PASSED
ns/op 25606 21559 −16.6% (−4245) −5003 to −2813 ≤ 0 PASSED
allocs/op 112 92 −17.9% (−20) −20 to −20 ≤ 0 PASSED

Proxy.ServeHTTP for GET /foo with modPath before the common-use-case 308 redirect · 10 sample pairs

metric baseline candidate paired median change confidence range required result
B/op 18084 15364 −15% (−2720) −2721 to −2720 < −1808 PASSED
ns/op 28781 24251 −17.6% (−5066) −10586 to −2873 ≤ 0 PASSED
allocs/op 130 110 −15.4% (−20) −20 to −20 ≤ 0 PASSED

Checks: 6 of 6 passed. Verification: no defect found.

Timeline