Skip to content
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ require (
github.com/newrelic/go-agent/v3 v3.42.0
github.com/newrelic/go-agent/v3/integrations/nrgrpc v1.4.7
github.com/prometheus/client_golang v1.23.2
go.uber.org/goleak v1.3.0
google.golang.org/grpc v1.79.3
)

Expand Down
21 changes: 21 additions & 0 deletions goleak_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
package interceptors

import (
"testing"

"go.uber.org/goleak"
)

func TestMain(m *testing.M) {
goleak.VerifyTestMain(m,
// rollbar-go creates a global async client at package init time
// (rollbar.go:39: std = NewAsync(...)), starting a background goroutine
// unconditionally when the package is imported. Cannot be avoided.
goleak.IgnoreTopFunction("github.com/rollbar/rollbar-go.NewAsyncTransport.func1"),
// hystrix-go starts metric exchange and pool metric goroutines when a
// circuit breaker is first used in tests. These are global singletons
// with no cleanup API.
goleak.IgnoreTopFunction("github.com/afex/hystrix-go/hystrix.(*metricExchange).Monitor"),
goleak.IgnoreTopFunction("github.com/afex/hystrix-go/hystrix.(*poolMetrics).Monitor"),
)
}
62 changes: 62 additions & 0 deletions interceptors.go
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ import (
newrelic "github.com/newrelic/go-agent/v3/newrelic"
"github.com/prometheus/client_golang/prometheus"
"google.golang.org/grpc"
"google.golang.org/grpc/metadata"
"google.golang.org/grpc/status"
)

Expand Down Expand Up @@ -69,6 +70,8 @@ var (
srvMetrics *grpcprom.ServerMetrics
cltMetricsOnce sync.Once
cltMetrics *grpcprom.ClientMetrics
disableDebugLogInterceptor bool
debugLogHeaderName = "x-debug-log-level"
)

// SetResponseTimeLogLevel sets the log level for response time logging.
Expand Down Expand Up @@ -430,6 +433,9 @@ func DefaultInterceptors() []grpc.UnaryServerInterceptor {
ResponseTimeLoggingInterceptor(defaultFilterFunc),
TraceIdInterceptor(),
)
if !disableDebugLogInterceptor {
ints = append(ints, DebugLogInterceptor())
}
if !disableProtoValidate {
ints = append(ints, ProtoValidateInterceptor())
}
Expand Down Expand Up @@ -798,3 +804,59 @@ func TraceIdInterceptor() grpc.UnaryServerInterceptor {
return handler(ctx, req)
}
}

// SetDisableDebugLogInterceptor disables the DebugLogInterceptor in the default
// interceptor chain. Must be called during initialization, before the server starts.
func SetDisableDebugLogInterceptor(disable bool) {
disableDebugLogInterceptor = disable
}

// SetDebugLogHeaderName sets the gRPC metadata header name that triggers
// per-request log level override. Default is "x-debug-log-level". The header
// value should be a valid log level (e.g., "debug"). Empty names are ignored.
// Must be called during initialization.
func SetDebugLogHeaderName(name string) {
name = strings.ToLower(strings.TrimSpace(name))
if name == "" {
return
}
debugLogHeaderName = name
}

// GetDebugLogHeaderName returns the current debug log header name.
func GetDebugLogHeaderName() string {
return debugLogHeaderName
}

// DebugLogInterceptor enables per-request log level override based on a proto
// field or gRPC metadata header. It checks (in order):
// 1. Proto field: GetDebug() bool or GetEnableDebug() bool — always sets DebugLevel
// 2. Metadata header: configurable via SetDebugLogHeaderName (default "x-debug-log-level")
// — the header value is parsed as a log level, allowing any valid level (debug, info, warn, error)
//
// Combined with ColdBrew's trace ID propagation, this allows enabling debug
// logging for a single request and following it across services via trace ID.
func DebugLogInterceptor() grpc.UnaryServerInterceptor {
Comment thread
ankurs marked this conversation as resolved.
return func(ctx context.Context, req any, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp any, err error) {
// Check proto field first
if req != nil {
if r, ok := req.(interface{ GetDebug() bool }); ok && r.GetDebug() {
ctx = log.OverrideLogLevel(ctx, loggers.DebugLevel)
return handler(ctx, req)
}
if r, ok := req.(interface{ GetEnableDebug() bool }); ok && r.GetEnableDebug() {
ctx = log.OverrideLogLevel(ctx, loggers.DebugLevel)
return handler(ctx, req)
}
}
// Check gRPC metadata header
if md, ok := metadata.FromIncomingContext(ctx); ok {
if vals := md.Get(debugLogHeaderName); len(vals) > 0 {
if level, err := loggers.ParseLevel(vals[0]); err == nil {
ctx = log.OverrideLogLevel(ctx, level)
}
}
}
Comment thread
ankurs marked this conversation as resolved.
return handler(ctx, req)
}
}
169 changes: 169 additions & 0 deletions interceptors_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"testing"
"time"

"github.com/go-coldbrew/log"
"github.com/go-coldbrew/log/loggers"
"github.com/grpc-ecosystem/grpc-gateway/v2/runtime"
"google.golang.org/grpc"
Expand Down Expand Up @@ -46,6 +47,8 @@ func resetGlobals() {
defaultTimeout = 60 * time.Second
httpToGRPCOnce = sync.Once{}
httpToGRPCInterceptor = nil
disableDebugLogInterceptor = false
debugLogHeaderName = "x-debug-log-level"
}

func TestFilterMethodsFunc(t *testing.T) {
Expand Down Expand Up @@ -1137,3 +1140,169 @@ func TestDefaultInterceptors_IncludesTimeout(t *testing.T) {
t.Error("expected first CB interceptor (DefaultTimeoutInterceptor) to set a deadline")
}
}

// --- DebugLogInterceptor tests ---

type debugRequest struct{ debug bool }

func (r *debugRequest) GetDebug() bool { return r.debug }

type enableDebugRequest struct{ enable bool }

func (r *enableDebugRequest) GetEnableDebug() bool { return r.enable }

type plainRequest struct{}

func TestDebugLogInterceptor_ProtoFieldDebug(t *testing.T) {
resetGlobals()
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/Debug"}

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(context.Background(), &debugRequest{debug: true}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
level, found := log.GetOverridenLogLevel(capturedCtx)
if !found || level != loggers.DebugLevel {
t.Errorf("expected debug level override, found=%v level=%v", found, level)
}
}

func TestDebugLogInterceptor_ProtoFieldEnableDebug(t *testing.T) {
resetGlobals()
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/Debug"}

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(context.Background(), &enableDebugRequest{enable: true}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
level, found := log.GetOverridenLogLevel(capturedCtx)
if !found || level != loggers.DebugLevel {
t.Errorf("expected debug level override, found=%v level=%v", found, level)
}
}

func TestDebugLogInterceptor_NoField(t *testing.T) {
resetGlobals()
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/NoDebug"}

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(context.Background(), &plainRequest{}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
_, found := log.GetOverridenLogLevel(capturedCtx)
if found {
t.Error("expected no log level override for request without debug field")
}
}

func TestDebugLogInterceptor_DebugFalse(t *testing.T) {
resetGlobals()
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/Debug"}

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(context.Background(), &debugRequest{debug: false}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
_, found := log.GetOverridenLogLevel(capturedCtx)
if found {
t.Error("expected no log level override when debug=false")
}
}

func TestDebugLogInterceptor_Metadata(t *testing.T) {
resetGlobals()
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/MetadataDebug"}

md := grpcmd.New(map[string]string{"x-debug-log-level": "debug"})
ctx := grpcmd.NewIncomingContext(context.Background(), md)

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(ctx, &plainRequest{}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
level, found := log.GetOverridenLogLevel(capturedCtx)
if !found || level != loggers.DebugLevel {
t.Errorf("expected debug level from metadata, found=%v level=%v", found, level)
}
}

func TestDebugLogInterceptor_CustomHeaderName(t *testing.T) {
resetGlobals()
SetDebugLogHeaderName("X-My-Debug")
interceptor := DebugLogInterceptor()
info := &grpc.UnaryServerInfo{FullMethod: "/test/CustomHeader"}

md := grpcmd.New(map[string]string{"x-my-debug": "debug"})
ctx := grpcmd.NewIncomingContext(context.Background(), md)

var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}

_, err := interceptor(ctx, &plainRequest{}, info, handler)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
level, found := log.GetOverridenLogLevel(capturedCtx)
if !found || level != loggers.DebugLevel {
t.Errorf("expected debug level from custom header, found=%v level=%v", found, level)
}
}

func TestDebugLogInterceptor_Disabled(t *testing.T) {
resetGlobals()
SetDisableDebugLogInterceptor(true)

ints := DefaultInterceptors()
for _, interceptor := range ints {
info := &grpc.UnaryServerInfo{FullMethod: "/test/Disabled"}
var capturedCtx context.Context
handler := func(ctx context.Context, req any) (any, error) {
capturedCtx = ctx
return "ok", nil
}
_, _ = interceptor(context.Background(), &debugRequest{debug: true}, info, handler)
if capturedCtx != nil {
if _, found := log.GetOverridenLogLevel(capturedCtx); found {
t.Error("expected no debug override when interceptor is disabled")
}
}
}
}
Loading