Skip to content

perf: short-circuit NR interceptors, add error-only response time logging#28

Merged
ankurs merged 5 commits intomainfrom
perf/throughput-improvements
Apr 3, 2026
Merged

perf: short-circuit NR interceptors, add error-only response time logging#28
ankurs merged 5 commits intomainfrom
perf/throughput-improvements

Conversation

@ankurs
Copy link
Copy Markdown
Member

@ankurs ankurs commented Apr 2, 2026

Summary

  • NR short-circuit: NewRelicInterceptor, NewRelicClientInterceptor, and stream client interceptor return pass-through when GetNewRelicApp() is nil. Eliminates all NR overhead for services without a license key.
  • Error-only logging: New SetResponseTimeLogErrorOnly(bool) API. When enabled, ResponseTimeLoggingInterceptor only logs requests that return errors. Default behavior unchanged.

Test plan

  • go test -race ./... passes
  • Verify NR pass-through with nil app doesn't break existing behavior
  • Verify error-only mode skips success logs

Summary by CodeRabbit

  • New Features

    • Added a configurable option with a public setter to only log response times for requests that result in errors.
  • Performance Improvements

    • External instrumentation now skips initialization when not configured; core metrics collection remains enabled.
  • Testing

    • Tests reset logging state between runs and add benchmarks covering interceptors and response-time logging scenarios.

… time logging

- NewRelicInterceptor, NewRelicClientInterceptor: return pass-through
  when GetNewRelicApp() is nil (no license key). Eliminates all NR
  overhead for services without NewRelic configured.
- DefaultClientStreamInterceptors: skip nrgrpc.StreamClientInterceptor
  when NR app is nil.
- Add SetResponseTimeLogErrorOnly(bool): when enabled, only log
  response time for requests that return an error.
- Add responseTimeLogErrorOnly package var with setter.
@coderabbitai
Copy link
Copy Markdown
Contributor

coderabbitai Bot commented Apr 2, 2026

Warning

Rate limit exceeded

@ankurs has exceeded the limit for the number of commits that can be reviewed per hour. Please wait 29 minutes and 10 seconds before requesting another review.

Your organization is not enrolled in usage-based pricing. Contact your admin to enable usage-based pricing to continue reviews beyond the rate limit, or try again in 29 minutes and 10 seconds.

⌛ How to resolve this issue?

After the wait time has elapsed, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

We recommend that you space out your commits to avoid hitting the rate limit.

🚦 How do rate limits work?

CodeRabbit enforces hourly rate limits for each developer per organization.

Our paid plans have higher rate limits than the trial, open-source and free plans. In all cases, we re-allow further reviews after a brief timeout.

Please see our FAQ for further information.

ℹ️ Review info
⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro

Run ID: 174c5928-5c7e-4e97-b25e-477d02397f4d

📥 Commits

Reviewing files that changed from the base of the PR and between bc5a2d1 and 73bcee7.

📒 Files selected for processing (1)
  • interceptors.go
📝 Walkthrough

Walkthrough

Added a runtime flag and exported setter to control response-time logging for successful unary calls, made New Relic interceptors pass-through when no New Relic app is present, adjusted default client stream interceptor composition, and added benchmarks plus test-state resets for the new controls.

Changes

Cohort / File(s) Summary
Interceptors core
interceptors.go
Added package flag responseTimeLogErrorOnly and exported setter SetResponseTimeLogErrorOnly(bool); ResponseTimeLoggingInterceptor skips logging for successful unary responses when the flag is enabled; NewRelicInterceptor and NewRelicClientInterceptor act as pass-through when nrutil.GetNewRelicApp() is nil; DefaultClientStreamInterceptors only includes New Relic stream interceptor if app exists; adjusted log arg construction.
Tests & Benchmarks
interceptors_test.go
Imported github.com/go-coldbrew/log/loggers; extended resetGlobals() to reset responseTimeLogErrorOnly and responseTimeLogLevel; added benchmark helpers (noopHandler, errHandler, benchInfo) and three benchmarks: BenchmarkNewRelicInterceptor_NilApp, BenchmarkResponseTimeLogging, and BenchmarkDefaultInterceptors.
Module deps
go.mod
Bumped github.com/go-coldbrew/log from v0.2.7 to v0.2.8; removed two indirect requirements (github.com/go-kit/log, github.com/go-logfmt/logfmt).

Sequence Diagram(s)

sequenceDiagram
  participant Client as Client
  participant Chain as Interceptors Chain
  participant RT as ResponseTimeLogger
  participant NR as NewRelic (optional)
  participant Prom as Prometheus
  participant Handler as Unary Handler

  Client->>Chain: Invoke unary RPC
  Chain->>RT: start timing
  RT-->>Chain: proceed
  Chain->>NR: invoke (only if NR app != nil)
  alt New Relic present
    NR->>Handler: forward request
  else New Relic absent
    Chain->>Handler: forward request (pass-through)
  end
  Handler-->>Chain: response / error
  Chain->>RT: stop timing
  alt responseTimeLogErrorOnly == true and error == nil
    RT-->>Chain: suppress log/metric
  else
    RT->>Prom: emit metric / log
  end
  Chain-->>Client: return response / error
Loading

Estimated code review effort

🎯 3 (Moderate) | ⏱️ ~20 minutes

Possibly related PRs

Poem

🐇 I timed my hop with careful cheer,
Quiet on wins, loud when faults appear.
If New Relic naps, I bound on through,
Benchmarks clap as metrics renew.
🥕✨

🚥 Pre-merge checks | ✅ 2 | ❌ 1

❌ Failed checks (1 warning)

Check name Status Explanation Resolution
Docstring Coverage ⚠️ Warning Docstring coverage is 50.00% which is insufficient. The required threshold is 80.00%. Write docstrings for the functions missing them to satisfy the coverage threshold.
✅ Passed checks (2 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title accurately and concisely describes the two main changes: optimizing New Relic interceptors to short-circuit when unavailable, and adding error-only response time logging capability.

✏️ Tip: You can configure your own custom pre-merge checks in the settings.

✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch perf/throughput-improvements

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.

❤️ Share

Comment @coderabbitai help to get the list of available commands and usage tips.

Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR reduces overhead for services that don’t have New Relic configured and adds an option to suppress response-time logs for successful unary RPCs.

Changes:

  • Short-circuit New Relic unary server/client interceptors (and stream client interceptor inclusion) when nrutil.GetNewRelicApp() is nil.
  • Add SetResponseTimeLogErrorOnly(bool) to only log unary response times for requests that return errors.
  • Update tests’ global reset to restore the new response-time logging globals.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 4 comments.

File Description
interceptors.go Adds error-only unary response-time logging and avoids NR interceptor overhead when no NR app is configured.
interceptors_test.go Resets newly introduced response-time logging globals in test setup.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread interceptors.go
Comment thread interceptors.go
Comment thread interceptors.go Outdated
Comment thread interceptors.go
Copy link
Copy Markdown
Contributor

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick comments (2)
interceptors.go (1)

486-492: Cache the New Relic app pointer once per interceptor constructor.

Line 486/Line 491 and Line 547 currently call nrutil.GetNewRelicApp() more than once. Capture it once locally and reuse for consistency and lower overhead.

Suggested refactor
 func NewRelicInterceptor() grpc.UnaryServerInterceptor {
-    if nrutil.GetNewRelicApp() == nil {
+    app := nrutil.GetNewRelicApp()
+    if app == nil {
         return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
             return handler(ctx, req)
         }
     }
-    nrh := nrgrpc.UnaryServerInterceptor(nrutil.GetNewRelicApp())
+    nrh := nrgrpc.UnaryServerInterceptor(app)
     return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp interface{}, err error) {
         if defaultFilterFunc(ctx, info.FullMethod) {
             return nrh(ctx, req, info, handler)
@@
 func NewRelicClientInterceptor() grpc.UnaryClientInterceptor {
-    if nrutil.GetNewRelicApp() == nil {
+    app := nrutil.GetNewRelicApp()
+    if app == nil {
         return func(ctx context.Context, method string, req, reply interface{}, cc *grpc.ClientConn, invoker grpc.UnaryInvoker, opts ...grpc.CallOption) error {
             return invoker(ctx, method, req, reply, cc, opts...)
         }
     }
     return func(ctx context.Context, method string, req, reply interface{}, cc *grpc.ClientConn, invoker grpc.UnaryInvoker, opts ...grpc.CallOption) error {

Also applies to: 547-552

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@interceptors.go` around lines 486 - 492, Cache the New Relic app pointer once
at the start of each interceptor constructor instead of calling
nrutil.GetNewRelicApp() multiple times; e.g., retrieve app :=
nrutil.GetNewRelicApp(), return the no-op interceptor if app == nil, and pass
app into nrgrpc.UnaryServerInterceptor to create nrh (and likewise for the other
interceptor block around lines 547-552), so the code uses the same app variable
for nil checks and for creating the nrgrpc interceptor.
interceptors_test.go (1)

30-43: Add explicit tests for the two new feature paths.

resetGlobals() is updated correctly, but this file still lacks direct assertions for (1) SetResponseTimeLogErrorOnly(true) suppressing success logs and (2) NR interceptors becoming pass-through when GetNewRelicApp() is nil. Those are core PR behaviors and should be regression-tested.

Proposed test additions (outline)
+func TestResponseTimeLoggingInterceptor_ErrorOnly_SkipsSuccess(t *testing.T) {
+    defer resetGlobals()
+    SetResponseTimeLogErrorOnly(true)
+    // invoke interceptor with nil error and assert no log emission (via test logger hook)
+}
+
+func TestNewRelicInterceptors_NoApp_ArePassThrough(t *testing.T) {
+    defer resetGlobals()
+    // with nil NR app, assert handler/invoker is called directly and returns unchanged result/error
+}
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@interceptors_test.go` around lines 30 - 43, Add two unit tests: one that
calls resetGlobals(), then SetResponseTimeLogErrorOnly(true), invokes the code
path that would log a successful response and asserts no success-level response
time log was emitted (but errors still log); and another that ensures when
GetNewRelicApp() returns nil the NR wrappers become pass-through by calling
NewRelicUnaryServerInterceptor and NewRelicStreamServerInterceptor (and client
equivalents if present) and asserting they invoke the next handler directly (no
NR instrumentation side-effects). Use the package-level resetGlobals and
responseTimeLogErrorOnly flag to prepare state and reference
SetResponseTimeLogErrorOnly, GetNewRelicApp, NewRelicUnaryServerInterceptor and
NewRelicStreamServerInterceptor (and NewRelicUnaryClientInterceptor /
NewRelicStreamClientInterceptor if available) to locate the code to test.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Nitpick comments:
In `@interceptors_test.go`:
- Around line 30-43: Add two unit tests: one that calls resetGlobals(), then
SetResponseTimeLogErrorOnly(true), invokes the code path that would log a
successful response and asserts no success-level response time log was emitted
(but errors still log); and another that ensures when GetNewRelicApp() returns
nil the NR wrappers become pass-through by calling
NewRelicUnaryServerInterceptor and NewRelicStreamServerInterceptor (and client
equivalents if present) and asserting they invoke the next handler directly (no
NR instrumentation side-effects). Use the package-level resetGlobals and
responseTimeLogErrorOnly flag to prepare state and reference
SetResponseTimeLogErrorOnly, GetNewRelicApp, NewRelicUnaryServerInterceptor and
NewRelicStreamServerInterceptor (and NewRelicUnaryClientInterceptor /
NewRelicStreamClientInterceptor if available) to locate the code to test.

In `@interceptors.go`:
- Around line 486-492: Cache the New Relic app pointer once at the start of each
interceptor constructor instead of calling nrutil.GetNewRelicApp() multiple
times; e.g., retrieve app := nrutil.GetNewRelicApp(), return the no-op
interceptor if app == nil, and pass app into nrgrpc.UnaryServerInterceptor to
create nrh (and likewise for the other interceptor block around lines 547-552),
so the code uses the same app variable for nil checks and for creating the
nrgrpc interceptor.

ℹ️ Review info
⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro

Run ID: b10c06ac-6ba3-4025-843e-9f1cd03a505d

📥 Commits

Reviewing files that changed from the base of the PR and between e5a235e and a65b3f0.

📒 Files selected for processing (2)
  • interceptors.go
  • interceptors_test.go

ankurs added 2 commits April 3, 2026 09:11
…ll chain

Results on Apple M1 Pro:
- NR interceptor (nil app): 2.2ns/0 allocs — pure pass-through
- ResponseTimeLogging default/success: 542ns/18 allocs
- ResponseTimeLogging error_only/success: 420ns/15 allocs (22% faster)
- Full interceptor chain: 5.8µs/84 allocs per request
- Bump go-coldbrew/log v0.2.7 -> v0.2.8 to use slog as default logger
  instead of deprecated gokit (which allocates heavily per log call).
- Remove empty-key AddToOptions/AddToLogContext calls in
  ResponseTimeLoggingInterceptor — downstream interceptors create
  these lazily when needed.

Full interceptor chain benchmark improvement:
  Before: 5,905 ns/op, 4,064 B/op, 84 allocs/op
  After:  4,605 ns/op, 1,760 B/op, 49 allocs/op
  (22% faster, 57% less memory, 42% fewer allocs)
Copy link
Copy Markdown
Contributor

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick comments (2)
interceptors.go (2)

483-489: Avoid duplicate GetNewRelicApp() call.

nrutil.GetNewRelicApp() is called twice: once for the nil check and again to create the interceptor. While likely inexpensive, capturing the result in a local variable is cleaner.

♻️ Suggested refactor
 func NewRelicInterceptor() grpc.UnaryServerInterceptor {
-	if nrutil.GetNewRelicApp() == nil {
+	app := nrutil.GetNewRelicApp()
+	if app == nil {
 		return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
 			return handler(ctx, req)
 		}
 	}
-	nrh := nrgrpc.UnaryServerInterceptor(nrutil.GetNewRelicApp())
+	nrh := nrgrpc.UnaryServerInterceptor(app)
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@interceptors.go` around lines 483 - 489, The code calls
nrutil.GetNewRelicApp() twice inside NewRelicInterceptor; capture its result in
a local variable (e.g., app := nrutil.GetNewRelicApp()) then use that variable
for the nil check and to create nrh via nrgrpc.UnaryServerInterceptor(app) to
avoid duplicate calls and make the logic clearer; update references to use the
local variable and remove the second direct nrutil.GetNewRelicApp() invocation.

74-79: Consider adding context.Context parameter for API consistency.

Other setter functions in this package (e.g., SetResponseTimeLogLevel, SetFilterMethods, SetFilterFunc) accept a context.Context as the first parameter. While unused, this maintains a consistent API surface.

♻️ Suggested change for consistency
-func SetResponseTimeLogErrorOnly(errorOnly bool) {
+func SetResponseTimeLogErrorOnly(ctx context.Context, errorOnly bool) {
 	responseTimeLogErrorOnly = errorOnly
 }
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@interceptors.go` around lines 74 - 79, SetResponseTimeLogErrorOnly lacks a
context.Context parameter, breaking API consistency with other setters like
SetResponseTimeLogLevel, SetFilterMethods, and SetFilterFunc; update the
SetResponseTimeLogErrorOnly signature to accept a first parameter ctx
context.Context (even if unused), adjust internal usage to ignore ctx, and
update any call sites to pass through an existing context so the package
maintains a uniform setter API surface.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Nitpick comments:
In `@interceptors.go`:
- Around line 483-489: The code calls nrutil.GetNewRelicApp() twice inside
NewRelicInterceptor; capture its result in a local variable (e.g., app :=
nrutil.GetNewRelicApp()) then use that variable for the nil check and to create
nrh via nrgrpc.UnaryServerInterceptor(app) to avoid duplicate calls and make the
logic clearer; update references to use the local variable and remove the second
direct nrutil.GetNewRelicApp() invocation.
- Around line 74-79: SetResponseTimeLogErrorOnly lacks a context.Context
parameter, breaking API consistency with other setters like
SetResponseTimeLogLevel, SetFilterMethods, and SetFilterFunc; update the
SetResponseTimeLogErrorOnly signature to accept a first parameter ctx
context.Context (even if unused), adjust internal usage to ignore ctx, and
update any call sites to pass through an existing context so the package
maintains a uniform setter API surface.

ℹ️ Review info
⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro

Run ID: 0b46f97e-0f75-46a6-b769-09db23ada02c

📥 Commits

Reviewing files that changed from the base of the PR and between ffd0309 and a7128ad.

⛔ Files ignored due to path filters (1)
  • go.sum is excluded by !**/*.sum
📒 Files selected for processing (2)
  • go.mod
  • interceptors.go

Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 3 out of 4 changed files in this pull request and generated 3 comments.


💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread interceptors.go
Comment thread interceptors.go
Comment thread interceptors_test.go
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 3 out of 4 changed files in this pull request and generated 2 comments.


💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread interceptors.go
Comment thread interceptors.go
@ankurs ankurs merged commit 5af44ee into main Apr 3, 2026
15 checks passed
@ankurs ankurs deleted the perf/throughput-improvements branch April 3, 2026 07:46
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants