Optimize logging hot paths#17
Open
spa5k wants to merge 4 commits into
Open
Conversation
Add typed field storage, adapter fast paths, prepared operation APIs, async sink support, and lower-allocation HTTP integration paths. Keep the public surface focused by hiding internal fast-path interfaces and removing narrow benchmark-only helpers.
|
Warning Review limit reached
More reviews will be available in 27 minutes and 18 seconds. Learn how PR review limits work. Your organization has used up its prepaid credits, and credit purchases are no longer available. Enable the review add-on in the billing tab to keep reviews running — you're only billed for reviews past your plan's rate limits ($0.25/file). ⌛ How to resolve this issue?After more reviews become available, a review can be triggered using the To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based credits. 🚦 How do rate limits work?CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan refill rate. For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, the refill rate gradually slows as usage increases. The highest same-day bursts are limited more strictly. Please see our Fair Usage Limits Policy for further information. ℹ️ Review info⚙️ Run configurationConfiguration used: defaults Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (27)
📝 WalkthroughWalkthroughAdds typed field and borrowed-field contracts, refactors Event/context and operation lifecycle (prepared starts, finish paths, monotonic timing), introduces AsyncSink and sink routing helpers, extends slog/zap/zerolog adapters, rewires HTTP middleware/response-writer tracking, and updates benchmarks, tests, and docs. ChangesRuntime contracts and helpers
Event, pooled contexts, and direct APIs
Sink routing, AsyncSink, and adapters
Operation lifecycle and policies
HTTP integrations and response tracking
Benchmarks, docs, and cleanup
Estimated code review effort🎯 4 (Complex) | ⏱️ ~60 minutes Possibly related PRs
Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 6
🧹 Nitpick comments (4)
async_sink.go (1)
77-91: 💤 Low valueOptional: Avoid redundant field map copy on drop path.
When an entry is dropped,
dropFields()copies the map again (line 90), butfieldsis already a copy from line 83. Since the dropped entry won't be used, you can directly return the existing copy to theOnDropcallback.♻️ Suggested simplification
func (a *AsyncSink) Write(level Level, message string, fields map[string]any) { if a == nil || a.sink == nil { return } fields = copyFieldMap(fields) entry := asyncEntry{ level: level, message: message, fields: fields, } - a.enqueue(entry, func() map[string]any { return copyFieldMap(fields) }) + a.enqueue(entry, func() map[string]any { return fields }) }🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@async_sink.go` around lines 77 - 91, The Write method creates a copy of fields with copyFieldMap and then hands an OnDrop callback that redundantly calls copyFieldMap again via dropFields; update AsyncSink.Write so the enqueue OnDrop callback returns the already-copied fields directly (return the local variable fields) instead of calling copyFieldMap a second time, referencing AsyncSink.Write, enqueue, dropFields and copyFieldMap to locate the change.event.go (1)
472-482: 💤 Low valueRemove unused
fieldValueLockedmethod.Static analysis indicates this method is unused. Consider removing it to reduce code maintenance burden, or add a test/usage if it's intended for future use.
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@event.go` around lines 472 - 482, Remove the unused method Event.fieldValueLocked: locate the method named fieldValueLocked on the Event type (it references e.fieldMap and e.fieldList) and delete the entire function implementation; if the functionality is intended to be kept, instead add a unit test or caller that uses Event.fieldValueLocked so static analysis no longer reports it as unused. Ensure any references to the method are updated/removed accordingly.Source: Linters/SAST tools
integration/std/response_writer.go (1)
22-39: 💤 Low valueConsider adding a code generation comment for the wrapper combinatorics.
The 16 wrapper types and pools correctly cover all combinations of
Flusher,Hijacker,Pusher, andReaderFrom. While this approach is necessary to preserve optional interfaces, a brief comment noting the combinatorial pattern (or indicating this could be code-generated) would help future maintainers understand the structure.Also applies to: 41-81, 83-134
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@integration/std/response_writer.go` around lines 22 - 39, Add a brief code-generation comment above the block that declares the responseWriter* sync.Pool variables (e.g., responseWriterPool ... responseWriterFHPRPool) and the corresponding wrapper types to explain these 16 combinatorial wrappers preserve optional interfaces (Flusher, Hijacker, Pusher, ReaderFrom) and were intentionally enumerated rather than composed at runtime; note that the pattern is combinatorial and could be generated by tooling to aid future maintainers.integration/common/lifecycle_test.go (1)
31-31: ⚡ Quick winUse
httptest.NewRequestWithContextto satisfy noctx linter rule.The static analysis tool flags this line. Since you're immediately calling
.WithContext(base), usingNewRequestWithContextis cleaner:- req := httptest.NewRequest(http.MethodGet, "/x", nil).WithContext(base) + req := httptest.NewRequestWithContext(base, http.MethodGet, "/x", nil)🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@integration/common/lifecycle_test.go` at line 31, Replace the httptest.NewRequest(...).WithContext(base) call with httptest.NewRequestWithContext to satisfy the noctx linter; update the creation of req in the test (the line that currently uses httptest.NewRequest and then .WithContext(base)) to call httptest.NewRequestWithContext(http.MethodGet, "/x", base) so it directly embeds the base context.Source: Linters/SAST tools
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@adapter/slog/benchmark_test.go`:
- Around line 36-38: The benchmark is pre-populating completion-like keys in the
shared field slices (created by fieldListFromMap from benchFieldsSmall and
medium and stored in smallFields and mediumFields) which then get passed again
as completion metadata in the completion-path sub-benchmarks; remove those
completion-related keys (e.g. "http.status", "duration_ms" or any completion
metadata) from the maps used to build smallFields/mediumFields or create
separate field maps for the completion-path benchmarks so the completion
parameters passed to the OperationStart/OperationEnd code are the only source of
completion metadata; update the sub-benchmarks that call
fieldListFromMap(benchFieldsSmall)/fieldListFromMap(medium) to use the
non-completion versions (or new maps) to avoid duplicate/conflicting fields.
In `@adapter/zap/benchmark_test.go`:
- Around line 41-43: The benchmark inputs smallFields and mediumFields are built
from maps (benchFieldsSmall and medium) that include completion-related keys
like "http.status" and "duration_ms", which contaminates the completion-path
benchmarks; update the setup used by the completion benchmarks (where you call
fieldListFromMap to create smallFields and mediumFields and where the completion
metadata is passed) to filter out completion-specific keys (e.g., "http.status",
"duration_ms", or any completion metadata) before creating the slices or else
create dedicated maps for completion benchmarks without those keys so completion
measurements use only non-completion fields.
In `@adapter/zerolog/benchmark_test.go`:
- Around line 35-37: The benchmark is mixing completion metadata into the
baseline field sets: change how smallFields and mediumFields are built so they
don't include completion-like keys (e.g., "http.status", "duration_ms") by
creating separate baseline maps (or stripping those keys from benchFieldsSmall
and medium) and call fieldListFromMap(baselineSmall) /
fieldListFromMap(baselineMedium) for smallFields/mediumFields; keep completion
metadata passed only as explicit args in the completion benchmarks (refer to
fieldListFromMap, benchFieldsSmall, medium, smallFields, mediumFields and
hc.OperationStart).
In `@adapter/zerolog/sink.go`:
- Around line 139-215: The completion write methods
(WriteBorrowedFieldsWithCompletion, WriteFieldsWithOperationCompletion,
WriteBorrowedFieldsWithOperationCompletion) currently append fields in insertion
order and ignore z.deterministicOrder; modify each to check z.deterministicOrder
and, if true, collect field keys/values, sort by key, and append in sorted order
(using appendField/appendBorrowedField for each sorted entry), otherwise keep
the existing loop; ensure appendOperationFields and the duration/op.*/Msg chain
remain unchanged and are applied after appending the (sorted or unsorted)
fields.
In `@event_fields_test.go`:
- Line 10: Tests currently pass nil for a context (triggering SA1012); update
the test calls that use NewContext(nil) to use context.Background() instead
(import context if not present) so replace occurrences like NewContext(nil) in
event_fields_test.go (and any other test calls at the same locations) with
NewContext(context.Background()) to satisfy the linter.
In `@operation_lifecycle.go`:
- Around line 349-351: The sampling decision currently uses result.Code
everywhere and ignores state.statusCode, which can drop StartComplete HTTP
events with 5xx statuses; change the logic in the complete-start fast path to
prefer state.statusCode when present: compute a statusCodeToUse (use
state.statusCode if non-zero/available, otherwise fall back to result.Code), use
that statusCodeToUse when setting hasError (instead of result.Code) and pass
statusCodeToUse into shouldWriteOperationDefaultPrepared (replace both
result.Code args) so sampling reflects the event's actual HTTP status; refer to
state.statusCode, hasError, result.Code, shouldWriteOperationDefaultPrepared,
prepared, OperationPolicy, outcome, and level when making the change.
---
Nitpick comments:
In `@async_sink.go`:
- Around line 77-91: The Write method creates a copy of fields with copyFieldMap
and then hands an OnDrop callback that redundantly calls copyFieldMap again via
dropFields; update AsyncSink.Write so the enqueue OnDrop callback returns the
already-copied fields directly (return the local variable fields) instead of
calling copyFieldMap a second time, referencing AsyncSink.Write, enqueue,
dropFields and copyFieldMap to locate the change.
In `@event.go`:
- Around line 472-482: Remove the unused method Event.fieldValueLocked: locate
the method named fieldValueLocked on the Event type (it references e.fieldMap
and e.fieldList) and delete the entire function implementation; if the
functionality is intended to be kept, instead add a unit test or caller that
uses Event.fieldValueLocked so static analysis no longer reports it as unused.
Ensure any references to the method are updated/removed accordingly.
In `@integration/common/lifecycle_test.go`:
- Line 31: Replace the httptest.NewRequest(...).WithContext(base) call with
httptest.NewRequestWithContext to satisfy the noctx linter; update the creation
of req in the test (the line that currently uses httptest.NewRequest and then
.WithContext(base)) to call httptest.NewRequestWithContext(http.MethodGet, "/x",
base) so it directly embeds the base context.
In `@integration/std/response_writer.go`:
- Around line 22-39: Add a brief code-generation comment above the block that
declares the responseWriter* sync.Pool variables (e.g., responseWriterPool ...
responseWriterFHPRPool) and the corresponding wrapper types to explain these 16
combinatorial wrappers preserve optional interfaces (Flusher, Hijacker, Pusher,
ReaderFrom) and were intentionally enumerated rather than composed at runtime;
note that the pattern is combinatorial and could be generated by tooling to aid
future maintainers.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: defaults
Review profile: CHILL
Plan: Pro
Run ID: cdd9ccec-ea97-4fb5-a108-08032f709536
⛔ Files ignored due to path filters (3)
bench/go.sumis excluded by!**/*.sumcmd/examples/go.sumis excluded by!**/*.sumintegration/std/go.sumis excluded by!**/*.sum
📒 Files selected for processing (53)
BENCHMARK_REPORT.mdREADME.mdadapter/slog/benchmark_test.goadapter/slog/sink.goadapter/zap/benchmark_test.goadapter/zap/sink.goadapter/zerolog/benchmark_test.goadapter/zerolog/sink.goasync_sink.goasync_sink_test.gobench/go.modbench/happycontext_benchmark_test.gobench/integration/router_benchmark_test.gocmd/examples/go.modconfig.gocontext.goevent.goevent_access.goevent_access_test.goevent_fields.goevent_fields_test.goevent_pool.gofast_time.gofield.gofield_mapper.gofield_mapper_test.gofield_test.gohappycontext.gointegration/common/config.gointegration/common/config_test.gointegration/common/lifecycle.gointegration/common/lifecycle_test.gointegration/common/request_context.gointegration/echo/middleware.gointegration/echo/middleware_test.gointegration/gin/middleware.gointegration/gin/middleware_test.gointegration/std/go.modintegration/std/middleware.gointegration/std/middleware_test.gointegration/std/response_writer.gointegration/worker/worker_test.gooperation_fields.gooperation_fields_test.gooperation_lifecycle.gooperation_policy.gooperation_test.gooperation_types.gooptions.goprepared_config.goprepared_operation.gosink.gosink_write.go
💤 Files with no reviewable changes (3)
- bench/go.mod
- cmd/examples/go.mod
- integration/std/go.mod
Comment on lines
+349
to
+351
| hasError := state.hasError || result.Code >= 500 || outcome != OutcomeSuccess | ||
| if !shouldWriteOperationDefaultPrepared(prepared, OperationPolicy{}, hasError, result.Code, result.Code, outcome, level) { | ||
| return true, false |
There was a problem hiding this comment.
Use event status when deciding default sampling in complete-start fast path.
This branch ignores state.statusCode and always evaluates sampling with result.Code, so a StartComplete=true HTTP event can be dropped even when http.status is 5xx.
💡 Proposed fix
- hasError := state.hasError || result.Code >= 500 || outcome != OutcomeSuccess
- if !shouldWriteOperationDefaultPrepared(prepared, OperationPolicy{}, hasError, result.Code, result.Code, outcome, level) {
+ statusCode := result.Code
+ if state.hasStatus {
+ statusCode = state.statusCode
+ }
+ hasError := state.hasError || result.Code >= 500 || statusCode >= 500 || outcome != OutcomeSuccess
+ if !shouldWriteOperationDefaultPrepared(prepared, OperationPolicy{}, hasError, result.Code, statusCode, outcome, level) {
return true, false
}📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
Suggested change
| hasError := state.hasError || result.Code >= 500 || outcome != OutcomeSuccess | |
| if !shouldWriteOperationDefaultPrepared(prepared, OperationPolicy{}, hasError, result.Code, result.Code, outcome, level) { | |
| return true, false | |
| statusCode := result.Code | |
| if state.hasStatus { | |
| statusCode = state.statusCode | |
| } | |
| hasError := state.hasError || result.Code >= 500 || statusCode >= 500 || outcome != OutcomeSuccess | |
| if !shouldWriteOperationDefaultPrepared(prepared, OperationPolicy{}, hasError, result.Code, statusCode, outcome, level) { | |
| return true, false |
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@operation_lifecycle.go` around lines 349 - 351, The sampling decision
currently uses result.Code everywhere and ignores state.statusCode, which can
drop StartComplete HTTP events with 5xx statuses; change the logic in the
complete-start fast path to prefer state.statusCode when present: compute a
statusCodeToUse (use state.statusCode if non-zero/available, otherwise fall back
to result.Code), use that statusCodeToUse when setting hasError (instead of
result.Code) and pass statusCodeToUse into shouldWriteOperationDefaultPrepared
(replace both result.Code args) so sampling reflects the event's actual HTTP
status; refer to state.statusCode, hasError, result.Code,
shouldWriteOperationDefaultPrepared, prepared, OperationPolicy, outcome, and
level when making the change.
There was a problem hiding this comment.
🧹 Nitpick comments (2)
adapter/zerolog/sink.go (1)
141-158: ⚡ Quick winAvoid creating an unused zerolog event on deterministic paths.
On Line 141, Line 171, Line 201, and Line 233,
z.newEvent(level)is called before checkingz.deterministicOrder, but the deterministic branch immediately delegates toz.Write(...)(which creates its own event). Move event creation after the deterministic branch to avoid extra hot-path work.💡 Suggested refactor
func (z *Sink) WriteFieldsWithCompletion(level hc.Level, message string, fields []hc.Field, durationMS int64, code int, outcome hc.Outcome) { - event := z.newEvent(level) - if event == nil { - return - } if message == "" { message = hc.DefaultMessage } if z.deterministicOrder { m := mapFromFields(fields) if m == nil { m = make(map[string]any, 3) } m["duration_ms"] = durationMS m["op.code"] = code m["op.outcome"] = string(outcome) z.Write(level, message, m) return } + event := z.newEvent(level) + if event == nil { + return + } for _, field := range fields { event = appendField(event, field.Key, field.Value) }Apply the same reordering pattern to:
WriteBorrowedFieldsWithCompletionWriteFieldsWithOperationCompletionWriteBorrowedFieldsWithOperationCompletionAlso applies to: 171-188, 201-219, 233-251
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@adapter/zerolog/sink.go` around lines 141 - 158, The code currently calls z.newEvent(level) before checking z.deterministicOrder, causing an unused zerolog event on deterministic paths; move the z.newEvent(level) call to after the deterministicOrder check so the deterministic branch immediately builds the map and calls z.Write(...) without allocating an event. Apply this change in the four affected functions—WriteBorrowedFieldsWithCompletion, WriteFieldsWithOperationCompletion, WriteBorrowedFieldsWithOperationCompletion and the other similar writer—so each function checks z.deterministicOrder first, handles m := mapFromFields(fields)/m initialization, sets duration_ms/op.code/op.outcome and calls z.Write(level, message, m), and only calls z.newEvent(level) when deterministicOrder is false.integration/std/response_writer.go (1)
16-18: 💤 Low valueNote:
http.CloseNotifieris deprecated.The
CloseNotifyinterface is deprecated since Go 1.11 in favor ofhttp.Request.Context(). The preservation here is reasonable for backward compatibility with older middleware or servers, but consider adding a code comment documenting this deprecation context.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@integration/std/response_writer.go` around lines 16 - 18, The closeNotifier interface that defines CloseNotify() is using the deprecated http.CloseNotifier API; update the code by adding a concise comment above the type declaring that CloseNotify is deprecated since Go 1.11 and recommending use of http.Request.Context() for cancellation, mention why the compatibility shim remains (backward compatibility with older middleware/servers) and reference the closeNotifier type and CloseNotify method in that comment so future readers know to prefer request.Context() when possible.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Nitpick comments:
In `@adapter/zerolog/sink.go`:
- Around line 141-158: The code currently calls z.newEvent(level) before
checking z.deterministicOrder, causing an unused zerolog event on deterministic
paths; move the z.newEvent(level) call to after the deterministicOrder check so
the deterministic branch immediately builds the map and calls z.Write(...)
without allocating an event. Apply this change in the four affected
functions—WriteBorrowedFieldsWithCompletion, WriteFieldsWithOperationCompletion,
WriteBorrowedFieldsWithOperationCompletion and the other similar writer—so each
function checks z.deterministicOrder first, handles m := mapFromFields(fields)/m
initialization, sets duration_ms/op.code/op.outcome and calls z.Write(level,
message, m), and only calls z.newEvent(level) when deterministicOrder is false.
In `@integration/std/response_writer.go`:
- Around line 16-18: The closeNotifier interface that defines CloseNotify() is
using the deprecated http.CloseNotifier API; update the code by adding a concise
comment above the type declaring that CloseNotify is deprecated since Go 1.11
and recommending use of http.Request.Context() for cancellation, mention why the
compatibility shim remains (backward compatibility with older
middleware/servers) and reference the closeNotifier type and CloseNotify method
in that comment so future readers know to prefer request.Context() when
possible.
ℹ️ Review info
⚙️ Run configuration
Configuration used: defaults
Review profile: CHILL
Plan: Pro
Run ID: 0c34bd3b-6130-4f2e-b3ef-26e516fc6738
📒 Files selected for processing (9)
adapter/zerolog/sink.goadapter/zerolog/sink_test.goevent.goevent_fields_test.goevent_pool.gointegration/common/lifecycle.gointegration/common/lifecycle_test.gointegration/std/middleware_test.gointegration/std/response_writer.go
💤 Files with no reviewable changes (1)
- event.go
🚧 Files skipped from review as they are similar to previous changes (3)
- event_pool.go
- integration/std/middleware_test.go
- event_fields_test.go
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
1 participant
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.
Summary
Verification
just testgo test -race ./...go test -race ./...inintegration/std,integration/gin,integration/echogo vet ./...in every modulegit diff --checkSummary by CodeRabbit
AsyncSinkwith buffered background writes, optional drop handling,Flush()/Close(), and dropped-event reporting.