From a1393ef121a2c7cae3d313eb86840ac246493ecd Mon Sep 17 00:00:00 2001 From: PiyushSingh-ZS Date: Tue, 6 Oct 2026 12:23:56 +0530 Subject: [PATCH 1/4] fix(context): fall back to the container logger when logging on a hand-built Context --- pkg/gofr/context_logger.go | 80 +++++++++ pkg/gofr/context_logger_test.go | 265 ++++++++++++++++++++++++++++ pkg/gofr/logging/ctx_logger.go | 6 + pkg/gofr/logging/ctx_logger_test.go | 10 ++ 4 files changed, 361 insertions(+) create mode 100644 pkg/gofr/context_logger.go create mode 100644 pkg/gofr/context_logger_test.go diff --git a/pkg/gofr/context_logger.go b/pkg/gofr/context_logger.go new file mode 100644 index 0000000000..bd6d7acdbf --- /dev/null +++ b/pkg/gofr/context_logger.go @@ -0,0 +1,80 @@ +package gofr + +import "gofr.dev/pkg/gofr/logging" + +// Decision: Context logging methods fall back to the container's logger. +// Context: The embedded ContextLogger is set only by GoFr's own constructors. A Context built as a +// +// struct literal -- in tests, background jobs, and the gRPC wrappers generated by gofr-cli -- +// leaves it zero-valued, so ctx.Errorf dereferenced a nil base logger and panicked, while +// ctx.Logger.Errorf on the same Context worked. +// +// Choice: Define the logging.Logger methods on *Context itself. They shadow the embedded ContextLogger +// +// and use it when it is initialized; otherwise they build one from the Context's own +// context.Context and the injected Container.Logger, so trace IDs are still attached. +// +// Reason: Fixes every hand-built Context without requiring callers or generated code to change, and +// +// leaves the framework-built path untouched. +// +// Alternatives rejected: removing the ContextLogger field (breaks callers that set it in struct +// +// literals and drops trace correlation), making a zero ContextLogger a no-op +// (silently drops logs), falling back to a global logger (ignores the app's +// configured logger and level). +func (c *Context) logger() *logging.ContextLogger { + if c.ContextLogger.IsInitialized() { + return &c.ContextLogger + } + + cl := logging.ContextLoggerFor(c.Context, c.Container.Logger) + + return &cl +} + +// Debug logs at DEBUG level, attaching the request's trace ID when one is present. +func (c *Context) Debug(args ...any) { c.logger().Debug(args...) } + +// Debugf logs a formatted message at DEBUG level, attaching the request's trace ID when one is present. +func (c *Context) Debugf(format string, args ...any) { c.logger().Debugf(format, args...) } + +// Log logs at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Log(args ...any) { c.logger().Log(args...) } + +// Logf logs a formatted message at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Logf(format string, args ...any) { c.logger().Logf(format, args...) } + +// Info logs at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Info(args ...any) { c.logger().Info(args...) } + +// Infof logs a formatted message at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Infof(format string, args ...any) { c.logger().Infof(format, args...) } + +// Notice logs at NOTICE level, attaching the request's trace ID when one is present. +func (c *Context) Notice(args ...any) { c.logger().Notice(args...) } + +// Noticef logs a formatted message at NOTICE level, attaching the request's trace ID when one is present. +func (c *Context) Noticef(format string, args ...any) { c.logger().Noticef(format, args...) } + +// Warn logs at WARN level, attaching the request's trace ID when one is present. +func (c *Context) Warn(args ...any) { c.logger().Warn(args...) } + +// Warnf logs a formatted message at WARN level, attaching the request's trace ID when one is present. +func (c *Context) Warnf(format string, args ...any) { c.logger().Warnf(format, args...) } + +// Error logs at ERROR level, attaching the request's trace ID when one is present. +func (c *Context) Error(args ...any) { c.logger().Error(args...) } + +// Errorf logs a formatted message at ERROR level, attaching the request's trace ID when one is present. +func (c *Context) Errorf(format string, args ...any) { c.logger().Errorf(format, args...) } + +// Fatal logs at FATAL level, attaching the request's trace ID when one is present, and exits the application. +func (c *Context) Fatal(args ...any) { c.logger().Fatal(args...) } + +// Fatalf logs a formatted message at FATAL level, attaching the request's trace ID when one is present, +// and exits the application. +func (c *Context) Fatalf(format string, args ...any) { c.logger().Fatalf(format, args...) } + +// ChangeLevel changes the level of the underlying logger. +func (c *Context) ChangeLevel(level logging.Level) { c.logger().ChangeLevel(level) } diff --git a/pkg/gofr/context_logger_test.go b/pkg/gofr/context_logger_test.go new file mode 100644 index 0000000000..be9f0c24a6 --- /dev/null +++ b/pkg/gofr/context_logger_test.go @@ -0,0 +1,265 @@ +package gofr + +import ( + "context" + "fmt" + "net/http" + "net/http/httptest" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.opentelemetry.io/otel/trace" + + "gofr.dev/pkg/gofr/container" + "gofr.dev/pkg/gofr/logging" +) + +// recordedLog is a single call captured by recordingLogger. +type recordedLog struct { + method string + format string + args []any +} + +// recordingLogger captures every call so tests can assert which logger received +// a message and which arguments (including the trace ID marker) were passed. +type recordingLogger struct { + logs []recordedLog + level logging.Level +} + +func (r *recordingLogger) recordf(method, format string, args ...any) { + r.logs = append(r.logs, recordedLog{method: method, format: format, args: args}) +} + +func (r *recordingLogger) Debug(args ...any) { r.recordf("Debug", "", args...) } +func (r *recordingLogger) Debugf(f string, args ...any) { r.recordf("Debugf", f, args...) } +func (r *recordingLogger) Log(args ...any) { r.recordf("Log", "", args...) } +func (r *recordingLogger) Logf(f string, args ...any) { r.recordf("Logf", f, args...) } +func (r *recordingLogger) Info(args ...any) { r.recordf("Info", "", args...) } +func (r *recordingLogger) Infof(f string, args ...any) { r.recordf("Infof", f, args...) } +func (r *recordingLogger) Notice(args ...any) { r.recordf("Notice", "", args...) } +func (r *recordingLogger) Noticef(f string, args ...any) { r.recordf("Noticef", f, args...) } +func (r *recordingLogger) Warn(args ...any) { r.recordf("Warn", "", args...) } +func (r *recordingLogger) Warnf(f string, args ...any) { r.recordf("Warnf", f, args...) } +func (r *recordingLogger) Error(args ...any) { r.recordf("Error", "", args...) } +func (r *recordingLogger) Errorf(f string, args ...any) { r.recordf("Errorf", f, args...) } +func (r *recordingLogger) Fatal(args ...any) { r.recordf("Fatal", "", args...) } +func (r *recordingLogger) Fatalf(f string, args ...any) { r.recordf("Fatalf", f, args...) } +func (r *recordingLogger) ChangeLevel(level logging.Level) { + r.level = level + r.recordf("ChangeLevel", "") +} + +func tracedTestContext() (ctx context.Context, traceID string) { + sc := trace.NewSpanContext(trace.SpanContextConfig{ + TraceID: trace.TraceID{0x0a, 0x0b, 0x0c, 0x0d, 0x0e, 0x0f, 0x10, 0x11, 0x12, 0x13, 0x14, 0x15, 0x16, 0x17, 0x18, 0x19}, + SpanID: trace.SpanID{0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08}, + TraceFlags: trace.FlagsSampled, + }) + + return trace.ContextWithSpanContext(context.Background(), sc), sc.TraceID().String() +} + +// countTraceMarkers counts the args that render as the given trace ID; the marker +// type is unexported in the logging package, so it is matched by its value. +func countTraceMarkers(args []any, traceID string) int { + n := 0 + + for _, a := range args { + if fmt.Sprint(a) == traceID { + n++ + } + } + + return n +} + +// callAllLogMethods invokes every logging.Logger method once on ctx. +func callAllLogMethods(ctx *Context) { + ctx.Debug("m") + ctx.Debugf("m %s", "a") + ctx.Log("m") + ctx.Logf("m %s", "a") + ctx.Info("m") + ctx.Infof("m %s", "a") + ctx.Notice("m") + ctx.Noticef("m %s", "a") + ctx.Warn("m") + ctx.Warnf("m %s", "a") + ctx.Error("m") + ctx.Errorf("m %s", "a") + ctx.Fatal("m") + ctx.Fatalf("m %s", "a") +} + +func allLogMethods() []string { + return []string{ + "Debug", "Debugf", "Log", "Logf", "Info", "Infof", "Notice", "Noticef", + "Warn", "Warnf", "Error", "Errorf", "Fatal", "Fatalf", + } +} + +func methodsOf(logs []recordedLog) []string { + out := make([]string, 0, len(logs)) + for _, l := range logs { + out = append(out, l.method) + } + + return out +} + +// Hand-built contexts (tests, background jobs, gofr-cli generated gRPC wrappers) +// leave ContextLogger zero-valued. Logging through the context must fall back to +// the container's logger instead of dereferencing a nil base logger. +func TestContext_Logging_HandBuiltContextFallsBackToContainerLogger(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + + tests := []struct { + desc string + stdCtx context.Context + wantMarkers int + }{ + {desc: "background context logs without a trace marker", stdCtx: context.Background(), wantMarkers: 0}, + {desc: "traced context keeps the trace ID", stdCtx: tracedCtx, wantMarkers: 1}, + {desc: "nil context logs without a trace marker", stdCtx: nil, wantMarkers: 0}, + } + + for _, tc := range tests { + t.Run(tc.desc, func(t *testing.T) { + rec := &recordingLogger{} + ctx := &Context{Context: tc.stdCtx, Container: &container.Container{Logger: rec}} + + require.NotPanics(t, func() { callAllLogMethods(ctx) }) + + require.Equal(t, allLogMethods(), methodsOf(rec.logs)) + + for _, l := range rec.logs { + assert.Equal(t, tc.wantMarkers, countTraceMarkers(l.args, traceID), "method %s", l.method) + } + }) + } +} + +// The gRPC wrapper generated by gofr-cli builds the context with exactly these +// fields; ctx.Errorf in a gRPC handler must not panic. +func TestContext_Logging_GRPCWrapperShapedContext(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + rec := &recordingLogger{} + + ctx := &Context{ + Context: tracedCtx, + Container: &container.Container{Logger: rec}, + Request: nil, + } + + require.NotPanics(t, func() { ctx.Errorf("failed: %v", "boom") }) + require.Len(t, rec.logs, 1) + assert.Equal(t, "Errorf", rec.logs[0].method) + assert.Equal(t, "failed: %v", rec.logs[0].format) + assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) +} + +// Framework-built contexts must keep logging through their ContextLogger: one +// trace marker per call, delivered to the logger the ContextLogger wraps. +func TestContext_Logging_FrameworkContextUsesContextLogger(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + + containerLog := &recordingLogger{} + ctxLog := &recordingLogger{} + + ctx := &Context{ + Context: tracedCtx, + Container: &container.Container{Logger: containerLog}, + ContextLogger: logging.ContextLoggerFor(tracedCtx, ctxLog), + } + + callAllLogMethods(ctx) + + assert.Empty(t, containerLog.logs, "an initialized ContextLogger must not be bypassed") + require.Equal(t, allLogMethods(), methodsOf(ctxLog.logs)) + + for _, l := range ctxLog.logs { + assert.Equal(t, 1, countTraceMarkers(l.args, traceID), "method %s", l.method) + } +} + +func TestContext_Logging_NewHTTPContextKeepsSingleTraceMarker(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + rec := &recordingLogger{} + + req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) + ctx := newHTTPContext(httptest.NewRecorder(), req, &container.Container{Logger: rec}) + + ctx.Infof("hello %s", "world") + + require.Len(t, rec.logs, 1) + assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) +} + +func TestContext_ChangeLevel(t *testing.T) { + t.Run("hand-built context changes the container logger level", func(t *testing.T) { + rec := &recordingLogger{} + ctx := &Context{Context: context.Background(), Container: &container.Container{Logger: rec}} + + require.NotPanics(t, func() { ctx.ChangeLevel(logging.WARN) }) + assert.Equal(t, logging.WARN, rec.level) + }) + + t.Run("framework context changes the wrapped logger level", func(t *testing.T) { + rec := &recordingLogger{} + ctx := newContext(nil, &noopRequest{}, &container.Container{Logger: rec}) + + ctx.ChangeLevel(logging.ERROR) + assert.Equal(t, logging.ERROR, rec.level) + }) +} + +func TestContext_ImplementsLogger(*testing.T) { + var _ logging.Logger = (*Context)(nil) +} + +type discardLogger struct{} + +func (discardLogger) Debug(...any) {} +func (discardLogger) Debugf(string, ...any) {} +func (discardLogger) Log(...any) {} +func (discardLogger) Logf(string, ...any) {} +func (discardLogger) Info(...any) {} +func (discardLogger) Infof(string, ...any) {} +func (discardLogger) Notice(...any) {} +func (discardLogger) Noticef(string, ...any) {} +func (discardLogger) Warn(...any) {} +func (discardLogger) Warnf(string, ...any) {} +func (discardLogger) Error(...any) {} +func (discardLogger) Errorf(string, ...any) {} +func (discardLogger) Fatal(...any) {} +func (discardLogger) Fatalf(string, ...any) {} +func (discardLogger) ChangeLevel(logging.Level) {} + +func BenchmarkContext_Infof(b *testing.B) { + tracedCtx, _ := tracedTestContext() + req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) + c := &container.Container{Logger: discardLogger{}} + + b.Run("framework context", func(b *testing.B) { + ctx := newHTTPContext(httptest.NewRecorder(), req, c) + + b.ReportAllocs() + + for b.Loop() { + ctx.Infof("hello %s", "world") + } + }) + + b.Run("hand-built context", func(b *testing.B) { + ctx := &Context{Context: tracedCtx, Container: c} + + b.ReportAllocs() + + for b.Loop() { + ctx.Infof("hello %s", "world") + } + }) +} diff --git a/pkg/gofr/logging/ctx_logger.go b/pkg/gofr/logging/ctx_logger.go index 0239a9b4c9..34f26129df 100644 --- a/pkg/gofr/logging/ctx_logger.go +++ b/pkg/gofr/logging/ctx_logger.go @@ -48,6 +48,12 @@ func ContextLoggerFor(ctx context.Context, base Logger) ContextLogger { return ContextLogger{base: base, spanCtx: trace.SpanFromContext(ctx).SpanContext()} } +// IsInitialized reports whether the ContextLogger has a base logger to write to. +// A zero-value ContextLogger, such as the one in a hand-built gofr.Context, does not. +func (l *ContextLogger) IsInitialized() bool { + return l.base != nil +} + // withTraceInfo appends the trace ID from the context (if available). // This allows trace IDs to be extracted later during formatting or filtering. // The marker map is precomputed once per ContextLogger, so this only pays for diff --git a/pkg/gofr/logging/ctx_logger_test.go b/pkg/gofr/logging/ctx_logger_test.go index d457c2a8df..624b3b6aef 100644 --- a/pkg/gofr/logging/ctx_logger_test.go +++ b/pkg/gofr/logging/ctx_logger_test.go @@ -380,3 +380,13 @@ func BenchmarkContextLogger_Discarded(b *testing.B) { l.Debug("this entry is below the configured level") } } + +func TestContextLogger_IsInitialized(t *testing.T) { + var zero ContextLogger + + assert.False(t, zero.IsInitialized(), "zero-value ContextLogger has no base logger") + assert.True(t, NewContextLogger(t.Context(), &mockLogger{}).IsInitialized()) + + built := ContextLoggerFor(t.Context(), &mockLogger{}) + assert.True(t, built.IsInitialized()) +} From 547e833d6a7609a40026c5f11e53386589c04fa5 Mon Sep 17 00:00:00 2001 From: PiyushSingh-ZS Date: Tue, 6 Oct 2026 14:55:37 +0530 Subject: [PATCH 2/4] refactor(context): colocate logger methods in context.go and guard every Logger method --- pkg/gofr/context.go | 60 +++++++ pkg/gofr/context_logger.go | 80 ---------- pkg/gofr/context_logger_test.go | 265 ------------------------------- pkg/gofr/context_test.go | 267 ++++++++++++++++++++++++++++++++ 4 files changed, 327 insertions(+), 345 deletions(-) delete mode 100644 pkg/gofr/context_logger.go delete mode 100644 pkg/gofr/context_logger_test.go diff --git a/pkg/gofr/context.go b/pkg/gofr/context.go index 6ab96291aa..3e23b1b92f 100644 --- a/pkg/gofr/context.go +++ b/pkg/gofr/context.go @@ -232,3 +232,63 @@ func newCMDContext(w Responder, r Request, c *container.Container, out terminal. func (c *Context) GetCorrelationID() string { return trace.SpanFromContext(c).SpanContext().TraceID().String() } + +// logger returns the embedded ContextLogger when GoFr initialized it. A Context built as a struct +// literal (in tests, or by gofr-cli generated gRPC wrappers) leaves it zero-valued, so one is built +// from the Context's own context and Container.Logger, keeping the trace ID instead of panicking. +// A Context without a Container or Container.Logger has nothing to log to and panics, as ctx.Logger does. +func (c *Context) logger() *logging.ContextLogger { + if c.ContextLogger.IsInitialized() { + return &c.ContextLogger + } + + cl := logging.ContextLoggerFor(c.Context, c.Container.Logger) + + return &cl +} + +// Debug logs at DEBUG level, attaching the request's trace ID when one is present. +func (c *Context) Debug(args ...any) { c.logger().Debug(args...) } + +// Debugf logs a formatted message at DEBUG level, attaching the request's trace ID when one is present. +func (c *Context) Debugf(format string, args ...any) { c.logger().Debugf(format, args...) } + +// Log logs at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Log(args ...any) { c.logger().Log(args...) } + +// Logf logs a formatted message at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Logf(format string, args ...any) { c.logger().Logf(format, args...) } + +// Info logs at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Info(args ...any) { c.logger().Info(args...) } + +// Infof logs a formatted message at INFO level, attaching the request's trace ID when one is present. +func (c *Context) Infof(format string, args ...any) { c.logger().Infof(format, args...) } + +// Notice logs at NOTICE level, attaching the request's trace ID when one is present. +func (c *Context) Notice(args ...any) { c.logger().Notice(args...) } + +// Noticef logs a formatted message at NOTICE level, attaching the request's trace ID when one is present. +func (c *Context) Noticef(format string, args ...any) { c.logger().Noticef(format, args...) } + +// Warn logs at WARN level, attaching the request's trace ID when one is present. +func (c *Context) Warn(args ...any) { c.logger().Warn(args...) } + +// Warnf logs a formatted message at WARN level, attaching the request's trace ID when one is present. +func (c *Context) Warnf(format string, args ...any) { c.logger().Warnf(format, args...) } + +// Error logs at ERROR level, attaching the request's trace ID when one is present. +func (c *Context) Error(args ...any) { c.logger().Error(args...) } + +// Errorf logs a formatted message at ERROR level, attaching the request's trace ID when one is present. +func (c *Context) Errorf(format string, args ...any) { c.logger().Errorf(format, args...) } + +// Fatal logs at FATAL level, attaching the request's trace ID when one is present, and exits the application. +func (c *Context) Fatal(args ...any) { c.logger().Fatal(args...) } + +// Fatalf logs a formatted message at FATAL level, attaching the request's trace ID when one is present, +// and exits the application. +func (c *Context) Fatalf(format string, args ...any) { c.logger().Fatalf(format, args...) } + +// ChangeLevel changes the level of the underlying logger. +func (c *Context) ChangeLevel(level logging.Level) { c.logger().ChangeLevel(level) } diff --git a/pkg/gofr/context_logger.go b/pkg/gofr/context_logger.go deleted file mode 100644 index bd6d7acdbf..0000000000 --- a/pkg/gofr/context_logger.go +++ /dev/null @@ -1,80 +0,0 @@ -package gofr - -import "gofr.dev/pkg/gofr/logging" - -// Decision: Context logging methods fall back to the container's logger. -// Context: The embedded ContextLogger is set only by GoFr's own constructors. A Context built as a -// -// struct literal -- in tests, background jobs, and the gRPC wrappers generated by gofr-cli -- -// leaves it zero-valued, so ctx.Errorf dereferenced a nil base logger and panicked, while -// ctx.Logger.Errorf on the same Context worked. -// -// Choice: Define the logging.Logger methods on *Context itself. They shadow the embedded ContextLogger -// -// and use it when it is initialized; otherwise they build one from the Context's own -// context.Context and the injected Container.Logger, so trace IDs are still attached. -// -// Reason: Fixes every hand-built Context without requiring callers or generated code to change, and -// -// leaves the framework-built path untouched. -// -// Alternatives rejected: removing the ContextLogger field (breaks callers that set it in struct -// -// literals and drops trace correlation), making a zero ContextLogger a no-op -// (silently drops logs), falling back to a global logger (ignores the app's -// configured logger and level). -func (c *Context) logger() *logging.ContextLogger { - if c.ContextLogger.IsInitialized() { - return &c.ContextLogger - } - - cl := logging.ContextLoggerFor(c.Context, c.Container.Logger) - - return &cl -} - -// Debug logs at DEBUG level, attaching the request's trace ID when one is present. -func (c *Context) Debug(args ...any) { c.logger().Debug(args...) } - -// Debugf logs a formatted message at DEBUG level, attaching the request's trace ID when one is present. -func (c *Context) Debugf(format string, args ...any) { c.logger().Debugf(format, args...) } - -// Log logs at INFO level, attaching the request's trace ID when one is present. -func (c *Context) Log(args ...any) { c.logger().Log(args...) } - -// Logf logs a formatted message at INFO level, attaching the request's trace ID when one is present. -func (c *Context) Logf(format string, args ...any) { c.logger().Logf(format, args...) } - -// Info logs at INFO level, attaching the request's trace ID when one is present. -func (c *Context) Info(args ...any) { c.logger().Info(args...) } - -// Infof logs a formatted message at INFO level, attaching the request's trace ID when one is present. -func (c *Context) Infof(format string, args ...any) { c.logger().Infof(format, args...) } - -// Notice logs at NOTICE level, attaching the request's trace ID when one is present. -func (c *Context) Notice(args ...any) { c.logger().Notice(args...) } - -// Noticef logs a formatted message at NOTICE level, attaching the request's trace ID when one is present. -func (c *Context) Noticef(format string, args ...any) { c.logger().Noticef(format, args...) } - -// Warn logs at WARN level, attaching the request's trace ID when one is present. -func (c *Context) Warn(args ...any) { c.logger().Warn(args...) } - -// Warnf logs a formatted message at WARN level, attaching the request's trace ID when one is present. -func (c *Context) Warnf(format string, args ...any) { c.logger().Warnf(format, args...) } - -// Error logs at ERROR level, attaching the request's trace ID when one is present. -func (c *Context) Error(args ...any) { c.logger().Error(args...) } - -// Errorf logs a formatted message at ERROR level, attaching the request's trace ID when one is present. -func (c *Context) Errorf(format string, args ...any) { c.logger().Errorf(format, args...) } - -// Fatal logs at FATAL level, attaching the request's trace ID when one is present, and exits the application. -func (c *Context) Fatal(args ...any) { c.logger().Fatal(args...) } - -// Fatalf logs a formatted message at FATAL level, attaching the request's trace ID when one is present, -// and exits the application. -func (c *Context) Fatalf(format string, args ...any) { c.logger().Fatalf(format, args...) } - -// ChangeLevel changes the level of the underlying logger. -func (c *Context) ChangeLevel(level logging.Level) { c.logger().ChangeLevel(level) } diff --git a/pkg/gofr/context_logger_test.go b/pkg/gofr/context_logger_test.go deleted file mode 100644 index be9f0c24a6..0000000000 --- a/pkg/gofr/context_logger_test.go +++ /dev/null @@ -1,265 +0,0 @@ -package gofr - -import ( - "context" - "fmt" - "net/http" - "net/http/httptest" - "testing" - - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/require" - "go.opentelemetry.io/otel/trace" - - "gofr.dev/pkg/gofr/container" - "gofr.dev/pkg/gofr/logging" -) - -// recordedLog is a single call captured by recordingLogger. -type recordedLog struct { - method string - format string - args []any -} - -// recordingLogger captures every call so tests can assert which logger received -// a message and which arguments (including the trace ID marker) were passed. -type recordingLogger struct { - logs []recordedLog - level logging.Level -} - -func (r *recordingLogger) recordf(method, format string, args ...any) { - r.logs = append(r.logs, recordedLog{method: method, format: format, args: args}) -} - -func (r *recordingLogger) Debug(args ...any) { r.recordf("Debug", "", args...) } -func (r *recordingLogger) Debugf(f string, args ...any) { r.recordf("Debugf", f, args...) } -func (r *recordingLogger) Log(args ...any) { r.recordf("Log", "", args...) } -func (r *recordingLogger) Logf(f string, args ...any) { r.recordf("Logf", f, args...) } -func (r *recordingLogger) Info(args ...any) { r.recordf("Info", "", args...) } -func (r *recordingLogger) Infof(f string, args ...any) { r.recordf("Infof", f, args...) } -func (r *recordingLogger) Notice(args ...any) { r.recordf("Notice", "", args...) } -func (r *recordingLogger) Noticef(f string, args ...any) { r.recordf("Noticef", f, args...) } -func (r *recordingLogger) Warn(args ...any) { r.recordf("Warn", "", args...) } -func (r *recordingLogger) Warnf(f string, args ...any) { r.recordf("Warnf", f, args...) } -func (r *recordingLogger) Error(args ...any) { r.recordf("Error", "", args...) } -func (r *recordingLogger) Errorf(f string, args ...any) { r.recordf("Errorf", f, args...) } -func (r *recordingLogger) Fatal(args ...any) { r.recordf("Fatal", "", args...) } -func (r *recordingLogger) Fatalf(f string, args ...any) { r.recordf("Fatalf", f, args...) } -func (r *recordingLogger) ChangeLevel(level logging.Level) { - r.level = level - r.recordf("ChangeLevel", "") -} - -func tracedTestContext() (ctx context.Context, traceID string) { - sc := trace.NewSpanContext(trace.SpanContextConfig{ - TraceID: trace.TraceID{0x0a, 0x0b, 0x0c, 0x0d, 0x0e, 0x0f, 0x10, 0x11, 0x12, 0x13, 0x14, 0x15, 0x16, 0x17, 0x18, 0x19}, - SpanID: trace.SpanID{0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08}, - TraceFlags: trace.FlagsSampled, - }) - - return trace.ContextWithSpanContext(context.Background(), sc), sc.TraceID().String() -} - -// countTraceMarkers counts the args that render as the given trace ID; the marker -// type is unexported in the logging package, so it is matched by its value. -func countTraceMarkers(args []any, traceID string) int { - n := 0 - - for _, a := range args { - if fmt.Sprint(a) == traceID { - n++ - } - } - - return n -} - -// callAllLogMethods invokes every logging.Logger method once on ctx. -func callAllLogMethods(ctx *Context) { - ctx.Debug("m") - ctx.Debugf("m %s", "a") - ctx.Log("m") - ctx.Logf("m %s", "a") - ctx.Info("m") - ctx.Infof("m %s", "a") - ctx.Notice("m") - ctx.Noticef("m %s", "a") - ctx.Warn("m") - ctx.Warnf("m %s", "a") - ctx.Error("m") - ctx.Errorf("m %s", "a") - ctx.Fatal("m") - ctx.Fatalf("m %s", "a") -} - -func allLogMethods() []string { - return []string{ - "Debug", "Debugf", "Log", "Logf", "Info", "Infof", "Notice", "Noticef", - "Warn", "Warnf", "Error", "Errorf", "Fatal", "Fatalf", - } -} - -func methodsOf(logs []recordedLog) []string { - out := make([]string, 0, len(logs)) - for _, l := range logs { - out = append(out, l.method) - } - - return out -} - -// Hand-built contexts (tests, background jobs, gofr-cli generated gRPC wrappers) -// leave ContextLogger zero-valued. Logging through the context must fall back to -// the container's logger instead of dereferencing a nil base logger. -func TestContext_Logging_HandBuiltContextFallsBackToContainerLogger(t *testing.T) { - tracedCtx, traceID := tracedTestContext() - - tests := []struct { - desc string - stdCtx context.Context - wantMarkers int - }{ - {desc: "background context logs without a trace marker", stdCtx: context.Background(), wantMarkers: 0}, - {desc: "traced context keeps the trace ID", stdCtx: tracedCtx, wantMarkers: 1}, - {desc: "nil context logs without a trace marker", stdCtx: nil, wantMarkers: 0}, - } - - for _, tc := range tests { - t.Run(tc.desc, func(t *testing.T) { - rec := &recordingLogger{} - ctx := &Context{Context: tc.stdCtx, Container: &container.Container{Logger: rec}} - - require.NotPanics(t, func() { callAllLogMethods(ctx) }) - - require.Equal(t, allLogMethods(), methodsOf(rec.logs)) - - for _, l := range rec.logs { - assert.Equal(t, tc.wantMarkers, countTraceMarkers(l.args, traceID), "method %s", l.method) - } - }) - } -} - -// The gRPC wrapper generated by gofr-cli builds the context with exactly these -// fields; ctx.Errorf in a gRPC handler must not panic. -func TestContext_Logging_GRPCWrapperShapedContext(t *testing.T) { - tracedCtx, traceID := tracedTestContext() - rec := &recordingLogger{} - - ctx := &Context{ - Context: tracedCtx, - Container: &container.Container{Logger: rec}, - Request: nil, - } - - require.NotPanics(t, func() { ctx.Errorf("failed: %v", "boom") }) - require.Len(t, rec.logs, 1) - assert.Equal(t, "Errorf", rec.logs[0].method) - assert.Equal(t, "failed: %v", rec.logs[0].format) - assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) -} - -// Framework-built contexts must keep logging through their ContextLogger: one -// trace marker per call, delivered to the logger the ContextLogger wraps. -func TestContext_Logging_FrameworkContextUsesContextLogger(t *testing.T) { - tracedCtx, traceID := tracedTestContext() - - containerLog := &recordingLogger{} - ctxLog := &recordingLogger{} - - ctx := &Context{ - Context: tracedCtx, - Container: &container.Container{Logger: containerLog}, - ContextLogger: logging.ContextLoggerFor(tracedCtx, ctxLog), - } - - callAllLogMethods(ctx) - - assert.Empty(t, containerLog.logs, "an initialized ContextLogger must not be bypassed") - require.Equal(t, allLogMethods(), methodsOf(ctxLog.logs)) - - for _, l := range ctxLog.logs { - assert.Equal(t, 1, countTraceMarkers(l.args, traceID), "method %s", l.method) - } -} - -func TestContext_Logging_NewHTTPContextKeepsSingleTraceMarker(t *testing.T) { - tracedCtx, traceID := tracedTestContext() - rec := &recordingLogger{} - - req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) - ctx := newHTTPContext(httptest.NewRecorder(), req, &container.Container{Logger: rec}) - - ctx.Infof("hello %s", "world") - - require.Len(t, rec.logs, 1) - assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) -} - -func TestContext_ChangeLevel(t *testing.T) { - t.Run("hand-built context changes the container logger level", func(t *testing.T) { - rec := &recordingLogger{} - ctx := &Context{Context: context.Background(), Container: &container.Container{Logger: rec}} - - require.NotPanics(t, func() { ctx.ChangeLevel(logging.WARN) }) - assert.Equal(t, logging.WARN, rec.level) - }) - - t.Run("framework context changes the wrapped logger level", func(t *testing.T) { - rec := &recordingLogger{} - ctx := newContext(nil, &noopRequest{}, &container.Container{Logger: rec}) - - ctx.ChangeLevel(logging.ERROR) - assert.Equal(t, logging.ERROR, rec.level) - }) -} - -func TestContext_ImplementsLogger(*testing.T) { - var _ logging.Logger = (*Context)(nil) -} - -type discardLogger struct{} - -func (discardLogger) Debug(...any) {} -func (discardLogger) Debugf(string, ...any) {} -func (discardLogger) Log(...any) {} -func (discardLogger) Logf(string, ...any) {} -func (discardLogger) Info(...any) {} -func (discardLogger) Infof(string, ...any) {} -func (discardLogger) Notice(...any) {} -func (discardLogger) Noticef(string, ...any) {} -func (discardLogger) Warn(...any) {} -func (discardLogger) Warnf(string, ...any) {} -func (discardLogger) Error(...any) {} -func (discardLogger) Errorf(string, ...any) {} -func (discardLogger) Fatal(...any) {} -func (discardLogger) Fatalf(string, ...any) {} -func (discardLogger) ChangeLevel(logging.Level) {} - -func BenchmarkContext_Infof(b *testing.B) { - tracedCtx, _ := tracedTestContext() - req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) - c := &container.Container{Logger: discardLogger{}} - - b.Run("framework context", func(b *testing.B) { - ctx := newHTTPContext(httptest.NewRecorder(), req, c) - - b.ReportAllocs() - - for b.Loop() { - ctx.Infof("hello %s", "world") - } - }) - - b.Run("hand-built context", func(b *testing.B) { - ctx := &Context{Context: tracedCtx, Container: c} - - b.ReportAllocs() - - for b.Loop() { - ctx.Infof("hello %s", "world") - } - }) -} diff --git a/pkg/gofr/context_test.go b/pkg/gofr/context_test.go index bbace4c45c..636688e168 100644 --- a/pkg/gofr/context_test.go +++ b/pkg/gofr/context_test.go @@ -6,6 +6,7 @@ import ( "fmt" "net/http" "net/http/httptest" + "reflect" "sync" "testing" "time" @@ -18,6 +19,7 @@ import ( "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/sdk/trace" "go.opentelemetry.io/otel/sdk/trace/tracetest" + oteltrace "go.opentelemetry.io/otel/trace" "gofr.dev/pkg/gofr/config" "gofr.dev/pkg/gofr/container" @@ -552,3 +554,268 @@ func firstMessageBeforeEnd(t *testing.T, conn *gofrWebsocket.Connection, receive return "" } } + +// recordedLog is a single call captured by recordingLogger. +type recordedLog struct { + method string + format string + args []any +} + +// recordingLogger captures every call so tests can assert which logger received +// a message and which arguments (including the trace ID marker) were passed. +type recordingLogger struct { + logs []recordedLog + level logging.Level +} + +func (r *recordingLogger) recordf(method, format string, args ...any) { + r.logs = append(r.logs, recordedLog{method: method, format: format, args: args}) +} + +func (r *recordingLogger) Debug(args ...any) { r.recordf("Debug", "", args...) } +func (r *recordingLogger) Debugf(f string, args ...any) { r.recordf("Debugf", f, args...) } +func (r *recordingLogger) Log(args ...any) { r.recordf("Log", "", args...) } +func (r *recordingLogger) Logf(f string, args ...any) { r.recordf("Logf", f, args...) } +func (r *recordingLogger) Info(args ...any) { r.recordf("Info", "", args...) } +func (r *recordingLogger) Infof(f string, args ...any) { r.recordf("Infof", f, args...) } +func (r *recordingLogger) Notice(args ...any) { r.recordf("Notice", "", args...) } +func (r *recordingLogger) Noticef(f string, args ...any) { r.recordf("Noticef", f, args...) } +func (r *recordingLogger) Warn(args ...any) { r.recordf("Warn", "", args...) } +func (r *recordingLogger) Warnf(f string, args ...any) { r.recordf("Warnf", f, args...) } +func (r *recordingLogger) Error(args ...any) { r.recordf("Error", "", args...) } +func (r *recordingLogger) Errorf(f string, args ...any) { r.recordf("Errorf", f, args...) } +func (r *recordingLogger) Fatal(args ...any) { r.recordf("Fatal", "", args...) } +func (r *recordingLogger) Fatalf(f string, args ...any) { r.recordf("Fatalf", f, args...) } +func (r *recordingLogger) ChangeLevel(level logging.Level) { + r.level = level + r.recordf("ChangeLevel", "") +} + +func tracedTestContext() (ctx context.Context, traceID string) { + sc := oteltrace.NewSpanContext(oteltrace.SpanContextConfig{ + TraceID: oteltrace.TraceID{0x0a, 0x0b, 0x0c, 0x0d, 0x0e, 0x0f, 0x10, 0x11, 0x12, 0x13, 0x14, 0x15, 0x16, 0x17, 0x18, 0x19}, + SpanID: oteltrace.SpanID{0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08}, + TraceFlags: oteltrace.FlagsSampled, + }) + + return oteltrace.ContextWithSpanContext(context.Background(), sc), sc.TraceID().String() +} + +// countTraceMarkers counts the args that render as the given trace ID; the marker +// type is unexported in the logging package, so it is matched by its value. +func countTraceMarkers(args []any, traceID string) int { + n := 0 + + for _, a := range args { + if fmt.Sprint(a) == traceID { + n++ + } + } + + return n +} + +// callAllLogMethods invokes every logging.Logger method once on ctx. +func callAllLogMethods(ctx *Context) { + ctx.Debug("m") + ctx.Debugf("m %s", "a") + ctx.Log("m") + ctx.Logf("m %s", "a") + ctx.Info("m") + ctx.Infof("m %s", "a") + ctx.Notice("m") + ctx.Noticef("m %s", "a") + ctx.Warn("m") + ctx.Warnf("m %s", "a") + ctx.Error("m") + ctx.Errorf("m %s", "a") + ctx.Fatal("m") + ctx.Fatalf("m %s", "a") +} + +func allLogMethods() []string { + return []string{ + "Debug", "Debugf", "Log", "Logf", "Info", "Infof", "Notice", "Noticef", + "Warn", "Warnf", "Error", "Errorf", "Fatal", "Fatalf", + } +} + +func methodsOf(logs []recordedLog) []string { + out := make([]string, 0, len(logs)) + for _, l := range logs { + out = append(out, l.method) + } + + return out +} + +// Hand-built contexts (tests, background jobs, gofr-cli generated gRPC wrappers) +// leave ContextLogger zero-valued. Logging through the context must fall back to +// the container's logger instead of dereferencing a nil base logger. +func TestContext_Logging_HandBuiltContextFallsBackToContainerLogger(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + + tests := []struct { + desc string + stdCtx context.Context + wantMarkers int + }{ + {desc: "background context logs without a trace marker", stdCtx: context.Background(), wantMarkers: 0}, + {desc: "traced context keeps the trace ID", stdCtx: tracedCtx, wantMarkers: 1}, + {desc: "nil context logs without a trace marker", stdCtx: nil, wantMarkers: 0}, + } + + for _, tc := range tests { + t.Run(tc.desc, func(t *testing.T) { + rec := &recordingLogger{} + ctx := &Context{Context: tc.stdCtx, Container: &container.Container{Logger: rec}} + + require.NotPanics(t, func() { callAllLogMethods(ctx) }) + + require.Equal(t, allLogMethods(), methodsOf(rec.logs)) + + for _, l := range rec.logs { + assert.Equal(t, tc.wantMarkers, countTraceMarkers(l.args, traceID), "method %s", l.method) + } + }) + } +} + +// The gRPC wrapper generated by gofr-cli builds the context with exactly these +// fields; ctx.Errorf in a gRPC handler must not panic. +func TestContext_Logging_GRPCWrapperShapedContext(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + rec := &recordingLogger{} + + ctx := &Context{ + Context: tracedCtx, + Container: &container.Container{Logger: rec}, + Request: nil, + } + + require.NotPanics(t, func() { ctx.Errorf("failed: %v", "boom") }) + require.Len(t, rec.logs, 1) + assert.Equal(t, "Errorf", rec.logs[0].method) + assert.Equal(t, "failed: %v", rec.logs[0].format) + assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) +} + +// Framework-built contexts must keep logging through their ContextLogger: one +// trace marker per call, delivered to the logger the ContextLogger wraps. +func TestContext_Logging_FrameworkContextUsesContextLogger(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + + containerLog := &recordingLogger{} + ctxLog := &recordingLogger{} + + ctx := &Context{ + Context: tracedCtx, + Container: &container.Container{Logger: containerLog}, + ContextLogger: logging.ContextLoggerFor(tracedCtx, ctxLog), + } + + callAllLogMethods(ctx) + + assert.Empty(t, containerLog.logs, "an initialized ContextLogger must not be bypassed") + require.Equal(t, allLogMethods(), methodsOf(ctxLog.logs)) + + for _, l := range ctxLog.logs { + assert.Equal(t, 1, countTraceMarkers(l.args, traceID), "method %s", l.method) + } +} + +func TestContext_Logging_NewHTTPContextKeepsSingleTraceMarker(t *testing.T) { + tracedCtx, traceID := tracedTestContext() + rec := &recordingLogger{} + + req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) + ctx := newHTTPContext(httptest.NewRecorder(), req, &container.Container{Logger: rec}) + + ctx.Infof("hello %s", "world") + + require.Len(t, rec.logs, 1) + assert.Equal(t, 1, countTraceMarkers(rec.logs[0].args, traceID)) +} + +func TestContext_ChangeLevel(t *testing.T) { + t.Run("hand-built context changes the container logger level", func(t *testing.T) { + rec := &recordingLogger{} + ctx := &Context{Context: context.Background(), Container: &container.Container{Logger: rec}} + + require.NotPanics(t, func() { ctx.ChangeLevel(logging.WARN) }) + assert.Equal(t, logging.WARN, rec.level) + }) + + t.Run("framework context changes the wrapped logger level", func(t *testing.T) { + rec := &recordingLogger{} + ctx := newContext(nil, &noopRequest{}, &container.Container{Logger: rec}) + + ctx.ChangeLevel(logging.ERROR) + assert.Equal(t, logging.ERROR, rec.level) + }) +} + +type discardLogger struct{} + +func (discardLogger) Debug(...any) {} +func (discardLogger) Debugf(string, ...any) {} +func (discardLogger) Log(...any) {} +func (discardLogger) Logf(string, ...any) {} +func (discardLogger) Info(...any) {} +func (discardLogger) Infof(string, ...any) {} +func (discardLogger) Notice(...any) {} +func (discardLogger) Noticef(string, ...any) {} +func (discardLogger) Warn(...any) {} +func (discardLogger) Warnf(string, ...any) {} +func (discardLogger) Error(...any) {} +func (discardLogger) Errorf(string, ...any) {} +func (discardLogger) Fatal(...any) {} +func (discardLogger) Fatalf(string, ...any) {} +func (discardLogger) ChangeLevel(logging.Level) {} + +// Every logging.Logger method must work on a hand-built Context. A method added to the interface +// later but not defined on *Context would be promoted from the zero ContextLogger and panic. +func TestContext_HandBuiltContextHandlesEveryLoggerMethod(t *testing.T) { + ctx := reflect.ValueOf(&Context{Context: t.Context(), Container: &container.Container{Logger: discardLogger{}}}) + loggerType := reflect.TypeFor[logging.Logger]() + + for i := range loggerType.NumMethod() { + name := loggerType.Method(i).Name + method := ctx.MethodByName(name) + args := make([]reflect.Value, method.Type().NumIn()) + + for j := range args { + args[j] = reflect.Zero(method.Type().In(j)) + } + + // Fatal and Fatalf are included: the discard logger does not exit the process. + assert.NotPanics(t, func() { method.Call(args) }, name) + } +} + +func BenchmarkContext_Infof(b *testing.B) { + tracedCtx, _ := tracedTestContext() + req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) + c := &container.Container{Logger: discardLogger{}} + + b.Run("framework context", func(b *testing.B) { + ctx := newHTTPContext(httptest.NewRecorder(), req, c) + + b.ReportAllocs() + + for b.Loop() { + ctx.Infof("hello %s", "world") + } + }) + + b.Run("hand-built context", func(b *testing.B) { + ctx := &Context{Context: tracedCtx, Container: c} + + b.ReportAllocs() + + for b.Loop() { + ctx.Infof("hello %s", "world") + } + }) +} From 09fb092ffe82273decb8ddb24e89635e09c53ea3 Mon Sep 17 00:00:00 2001 From: PiyushSingh-ZS Date: Tue, 6 Oct 2026 15:42:56 +0530 Subject: [PATCH 3/4] refactor(logging): make IsInitialized a function so it is not promoted onto Context --- pkg/gofr/context.go | 2 +- pkg/gofr/context_test.go | 7 +++++++ pkg/gofr/logging/ctx_logger.go | 11 +++++++---- pkg/gofr/logging/ctx_logger_test.go | 23 +++++++++++++++++------ 4 files changed, 32 insertions(+), 11 deletions(-) diff --git a/pkg/gofr/context.go b/pkg/gofr/context.go index 3e23b1b92f..76705f7d14 100644 --- a/pkg/gofr/context.go +++ b/pkg/gofr/context.go @@ -238,7 +238,7 @@ func (c *Context) GetCorrelationID() string { // from the Context's own context and Container.Logger, keeping the trace ID instead of panicking. // A Context without a Container or Container.Logger has nothing to log to and panics, as ctx.Logger does. func (c *Context) logger() *logging.ContextLogger { - if c.ContextLogger.IsInitialized() { + if logging.IsInitialized(&c.ContextLogger) { return &c.ContextLogger } diff --git a/pkg/gofr/context_test.go b/pkg/gofr/context_test.go index 636688e168..6e0ca628c8 100644 --- a/pkg/gofr/context_test.go +++ b/pkg/gofr/context_test.go @@ -794,6 +794,13 @@ func TestContext_HandBuiltContextHandlesEveryLoggerMethod(t *testing.T) { } } +// The initialization check must not become part of Context's API: an exported method on the +// embedded ContextLogger would be promoted onto every *Context. +func TestContext_DoesNotExposeIsInitialized(t *testing.T) { + _, ok := reflect.TypeFor[*Context]().MethodByName("IsInitialized") + assert.False(t, ok, "IsInitialized must not be promoted onto *gofr.Context") +} + func BenchmarkContext_Infof(b *testing.B) { tracedCtx, _ := tracedTestContext() req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) diff --git a/pkg/gofr/logging/ctx_logger.go b/pkg/gofr/logging/ctx_logger.go index 34f26129df..7972dbf4b6 100644 --- a/pkg/gofr/logging/ctx_logger.go +++ b/pkg/gofr/logging/ctx_logger.go @@ -48,10 +48,13 @@ func ContextLoggerFor(ctx context.Context, base Logger) ContextLogger { return ContextLogger{base: base, spanCtx: trace.SpanFromContext(ctx).SpanContext()} } -// IsInitialized reports whether the ContextLogger has a base logger to write to. -// A zero-value ContextLogger, such as the one in a hand-built gofr.Context, does not. -func (l *ContextLogger) IsInitialized() bool { - return l.base != nil +// IsInitialized reports whether l has a base logger to write to. A nil or zero-value +// ContextLogger, such as the one in a hand-built gofr.Context, does not. +// +// It is a function rather than a method so that it is not promoted onto gofr.Context, +// which embeds ContextLogger. +func IsInitialized(l *ContextLogger) bool { + return l != nil && l.base != nil } // withTraceInfo appends the trace ID from the context (if available). diff --git a/pkg/gofr/logging/ctx_logger_test.go b/pkg/gofr/logging/ctx_logger_test.go index 624b3b6aef..18fc1338bd 100644 --- a/pkg/gofr/logging/ctx_logger_test.go +++ b/pkg/gofr/logging/ctx_logger_test.go @@ -381,12 +381,23 @@ func BenchmarkContextLogger_Discarded(b *testing.B) { } } -func TestContextLogger_IsInitialized(t *testing.T) { - var zero ContextLogger +func TestIsInitialized(t *testing.T) { + built := ContextLoggerFor(t.Context(), &mockLogger{}) - assert.False(t, zero.IsInitialized(), "zero-value ContextLogger has no base logger") - assert.True(t, NewContextLogger(t.Context(), &mockLogger{}).IsInitialized()) + tests := []struct { + desc string + l *ContextLogger + want bool + }{ + {desc: "nil ContextLogger", l: nil, want: false}, + {desc: "zero-value ContextLogger has no base logger", l: &ContextLogger{}, want: false}, + {desc: "NewContextLogger", l: NewContextLogger(t.Context(), &mockLogger{}), want: true}, + {desc: "ContextLoggerFor", l: &built, want: true}, + } - built := ContextLoggerFor(t.Context(), &mockLogger{}) - assert.True(t, built.IsInitialized()) + for _, tc := range tests { + t.Run(tc.desc, func(t *testing.T) { + assert.Equal(t, tc.want, IsInitialized(tc.l)) + }) + } } From 479e805df8c4780f08ebd3ce4e09b35d518d7bb6 Mon Sep 17 00:00:00 2001 From: PiyushSingh-ZS Date: Tue, 6 Oct 2026 22:04:53 +0530 Subject: [PATCH 4/4] refactor(logging): store the trace ID in ContextLogger and drop IsInitialized --- pkg/gofr/context.go | 2 +- pkg/gofr/context_test.go | 7 ------- pkg/gofr/logging/ctx_logger.go | 27 +++++++++++++-------------- pkg/gofr/logging/ctx_logger_test.go | 29 ++++------------------------- 4 files changed, 18 insertions(+), 47 deletions(-) diff --git a/pkg/gofr/context.go b/pkg/gofr/context.go index 76705f7d14..ebb592a572 100644 --- a/pkg/gofr/context.go +++ b/pkg/gofr/context.go @@ -238,7 +238,7 @@ func (c *Context) GetCorrelationID() string { // from the Context's own context and Container.Logger, keeping the trace ID instead of panicking. // A Context without a Container or Container.Logger has nothing to log to and panics, as ctx.Logger does. func (c *Context) logger() *logging.ContextLogger { - if logging.IsInitialized(&c.ContextLogger) { + if c.ContextLogger != (logging.ContextLogger{}) { return &c.ContextLogger } diff --git a/pkg/gofr/context_test.go b/pkg/gofr/context_test.go index 6e0ca628c8..636688e168 100644 --- a/pkg/gofr/context_test.go +++ b/pkg/gofr/context_test.go @@ -794,13 +794,6 @@ func TestContext_HandBuiltContextHandlesEveryLoggerMethod(t *testing.T) { } } -// The initialization check must not become part of Context's API: an exported method on the -// embedded ContextLogger would be promoted onto every *Context. -func TestContext_DoesNotExposeIsInitialized(t *testing.T) { - _, ok := reflect.TypeFor[*Context]().MethodByName("IsInitialized") - assert.False(t, ok, "IsInitialized must not be promoted onto *gofr.Context") -} - func BenchmarkContext_Infof(b *testing.B) { tracedCtx, _ := tracedTestContext() req := httptest.NewRequestWithContext(tracedCtx, http.MethodGet, "/", http.NoBody) diff --git a/pkg/gofr/logging/ctx_logger.go b/pkg/gofr/logging/ctx_logger.go index 7972dbf4b6..7a9898b95b 100644 --- a/pkg/gofr/logging/ctx_logger.go +++ b/pkg/gofr/logging/ctx_logger.go @@ -13,8 +13,10 @@ import ( // trace information is available. type ContextLogger struct { base Logger - // spanCtx is the request's SpanContext, kept as a value (it allocates - // nothing) rather than a formatted trace ID. + // traceID is the request's trace ID, zero when the context has no valid span. It is kept as + // the raw [16]byte (it allocates nothing) rather than a formatted string, and rather than the + // full SpanContext, whose TraceState would make ContextLogger non-comparable: gofr.Context + // compares its embedded ContextLogger with the zero value to detect a hand-built Context. // // Formatting the trace ID costs a 32-character string, and wrapping it for // the log args costs another allocation. Both were paid when the logger was @@ -25,7 +27,7 @@ type ContextLogger struct { // They are now built in withTraceInfo, per log call. A handler logging once // pays exactly what it did before; one logging repeatedly pays per call, // which is the deliberate trade for making the silent path free. - spanCtx trace.SpanContext + traceID trace.TraceID } // NewContextLogger creates a new ContextLogger that wraps the provided base logger @@ -45,16 +47,13 @@ func NewContextLogger(ctx context.Context, base Logger) *ContextLogger { // that need a pointer keep using NewContextLogger; callers that store a value // use this and allocate nothing for the wrapper itself. func ContextLoggerFor(ctx context.Context, base Logger) ContextLogger { - return ContextLogger{base: base, spanCtx: trace.SpanFromContext(ctx).SpanContext()} -} + cl := ContextLogger{base: base} -// IsInitialized reports whether l has a base logger to write to. A nil or zero-value -// ContextLogger, such as the one in a hand-built gofr.Context, does not. -// -// It is a function rather than a method so that it is not promoted onto gofr.Context, -// which embeds ContextLogger. -func IsInitialized(l *ContextLogger) bool { - return l != nil && l.base != nil + if sc := trace.SpanFromContext(ctx).SpanContext(); sc.IsValid() { + cl.traceID = sc.TraceID() + } + + return cl } // withTraceInfo appends the trace ID from the context (if available). @@ -62,11 +61,11 @@ func IsInitialized(l *ContextLogger) bool { // The marker map is precomputed once per ContextLogger, so this only pays for // the slice append, not a fresh map allocation on every call. func (l *ContextLogger) withTraceInfo(args ...any) []any { - if !l.spanCtx.IsValid() { + if !l.traceID.IsValid() { return args } - return append(args, traceIDMarker(l.spanCtx.TraceID().String())) + return append(args, traceIDMarker(l.traceID.String())) } func (l *ContextLogger) logWithTraceID(lf func(args ...any), args ...any) { diff --git a/pkg/gofr/logging/ctx_logger_test.go b/pkg/gofr/logging/ctx_logger_test.go index 18fc1338bd..5ab4392bca 100644 --- a/pkg/gofr/logging/ctx_logger_test.go +++ b/pkg/gofr/logging/ctx_logger_test.go @@ -242,7 +242,7 @@ func TestContextLogger_NoTrace_NoMarker(t *testing.T) { base := newBufLogger(buf) cl := NewContextLogger(context.Background(), base) - assert.False(t, cl.spanCtx.IsValid(), "no valid span means no marker will be attached") + assert.False(t, cl.traceID.IsValid(), "no valid span means no marker will be attached") cl.Info("x") @@ -289,8 +289,8 @@ func TestContextLoggerForMatchesPointerConstructor(t *testing.T) { ptr := NewContextLogger(ctx, base) val := ContextLoggerFor(ctx, base) - require.Equal(t, ptr.spanCtx, val.spanCtx) - require.True(t, val.spanCtx.IsValid()) + require.Equal(t, ptr.traceID, val.traceID) + require.True(t, val.traceID.IsValid()) require.Equal(t, ptr.withTraceInfo("m"), val.withTraceInfo("m"), "both constructors must attach the same marker") } @@ -299,7 +299,7 @@ func TestContextLoggerForMatchesPointerConstructor(t *testing.T) { func TestContextLoggerForNoTrace(t *testing.T) { val := ContextLoggerFor(context.Background(), newBufLogger(&bytes.Buffer{})) - require.False(t, val.spanCtx.IsValid()) + require.False(t, val.traceID.IsValid()) require.Equal(t, []any{"m"}, val.withTraceInfo("m"), "no marker without a valid span") } @@ -380,24 +380,3 @@ func BenchmarkContextLogger_Discarded(b *testing.B) { l.Debug("this entry is below the configured level") } } - -func TestIsInitialized(t *testing.T) { - built := ContextLoggerFor(t.Context(), &mockLogger{}) - - tests := []struct { - desc string - l *ContextLogger - want bool - }{ - {desc: "nil ContextLogger", l: nil, want: false}, - {desc: "zero-value ContextLogger has no base logger", l: &ContextLogger{}, want: false}, - {desc: "NewContextLogger", l: NewContextLogger(t.Context(), &mockLogger{}), want: true}, - {desc: "ContextLoggerFor", l: &built, want: true}, - } - - for _, tc := range tests { - t.Run(tc.desc, func(t *testing.T) { - assert.Equal(t, tc.want, IsInitialized(tc.l)) - }) - } -}