Merge pull request #423 from elisasre/feat/tracelogger

add tracing to logger

v2/go.mod

@@ -32,6 +32,7 @@ require (
 	go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.31.0
 	go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.31.0
 	go.opentelemetry.io/otel/sdk v1.31.0
+	go.opentelemetry.io/otel/trace v1.31.0
 	golang.org/x/oauth2 v0.23.0
 	google.golang.org/grpc v1.67.1
 	gorm.io/driver/postgres v1.5.9
@@ -352,7 +353,6 @@ require (
 	go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetrichttp v0.42.0 // indirect
 	go.opentelemetry.io/otel/metric v1.31.0 // indirect
 	go.opentelemetry.io/otel/sdk/metric v1.28.0 // indirect
-	go.opentelemetry.io/otel/trace v1.31.0 // indirect
 	go.opentelemetry.io/proto/otlp v1.3.1 // indirect
 	go.uber.org/automaxprocs v1.5.3 // indirect
 	go.uber.org/mock v0.4.0 // indirect

v2/log/logger.go

@@ -2,11 +2,20 @@
 package log
 
 import (
+	"context"
 	"io"
 	"log/slog"
 	"os"
 	"path/filepath"
 	"strings"
+
+	"go.opentelemetry.io/otel/trace"
+)
+
+var (
+	TraceID      = "trace_id"
+	SpanID       = "span_id"
+	TraceSampled = "trace_sampled"
 )
 
 // NewDefaultEnvLogger creates new slog.Logger using sane default configuration and sets it as a default logger.
@@ -32,12 +41,41 @@ func NewDefaultEnvLogger(opts ...Opt) *slog.Logger {
 		opt(b)
 	}
 
-	logger := slog.New(b.handlerFn(b.output, b.opts))
+	instrumentedHandler := handlerWithSpanContext(b.handlerFn(b.output, b.opts))
+	logger := slog.New(instrumentedHandler)
 	slog.SetDefault(logger)
 
 	return logger
 }
 
+func handlerWithSpanContext(handler slog.Handler) *spanContextLogHandler {
+	return &spanContextLogHandler{Handler: handler}
+}
+
+// spanContextLogHandler is an slog.Handler which adds attributes from the
+// span context.
+type spanContextLogHandler struct {
+	slog.Handler
+}
+
+// Handle overrides slog.Handler's Handle method. This adds attributes from the
+// span context to the slog.Record.
+func (t *spanContextLogHandler) Handle(ctx context.Context, record slog.Record) error {
+	s := trace.SpanContextFromContext(ctx)
+	if s.IsValid() {
+		record.AddAttrs(
+			slog.Any(TraceID, s.TraceID()),
+		)
+		record.AddAttrs(
+			slog.Any(SpanID, s.SpanID()),
+		)
+		record.AddAttrs(
+			slog.Bool(TraceSampled, s.TraceFlags().IsSampled()),
+		)
+	}
+	return t.Handler.Handle(ctx, record)
+}
+
 type builder struct {
 	handlerFn HandlerFn
 	opts      *slog.HandlerOptions
@@ -84,6 +122,35 @@ func WithReplacer(fn func([]string, slog.Attr) slog.Attr) Opt {
 	}
 }
 
+// WithGCPReplacer sets slog.HandlerOptions.ReplaceAttr to GCP structured logging format.
+// https://cloud.google.com/logging/docs/structured-logging#special-payload-fields
+func WithGCPReplacer(short bool) Opt {
+	return func(b *builder) {
+		b.opts.ReplaceAttr = func(groups []string, a slog.Attr) slog.Attr {
+			switch a.Key {
+			case slog.SourceKey:
+				if short {
+					source, ok := a.Value.Any().(*slog.Source)
+					if ok && source != nil {
+						source.File = filepath.Base(source.File)
+					}
+				}
+			case slog.LevelKey:
+				a.Key = "severity"
+				level, ok := a.Value.Any().(slog.Level)
+				if ok && level == slog.LevelWarn {
+					a.Value = slog.StringValue("WARNING")
+				}
+			case slog.TimeKey:
+				a.Key = "timestamp"
+			case slog.MessageKey:
+				a.Key = "message"
+			}
+			return a
+		}
+	}
+}
+
 // WithHandlerFn can be used to provide slog.Handler lazily.
 func WithHandlerFn(h HandlerFn) Opt {
 	return func(b *builder) {

v2/log/logger_test.go

@@ -11,6 +11,8 @@ import (
 
 	"github.com/elisasre/go-common/v2/log"
 	"github.com/stretchr/testify/assert"
+	"go.opentelemetry.io/otel"
+	"go.opentelemetry.io/otel/trace"
 )
 
 func TestParseLogLevel(t *testing.T) {
@@ -130,3 +132,23 @@ func TestRefreshLogLevel(t *testing.T) {
 	debugEnabled = logger.Handler().Enabled(context.Background(), slog.LevelDebug)
 	assert.True(t, debugEnabled)
 }
+
+func TestTracing(t *testing.T) {
+	buf := &bytes.Buffer{}
+	logger := log.NewDefaultEnvLogger(log.WithOutput(buf), log.WithGCPReplacer(true))
+
+	tracer := otel.Tracer("github.com/elisasre/go-common")
+
+	spanCtx := trace.ContextWithSpanContext(context.Background(), trace.NewSpanContext(trace.SpanContextConfig{
+		TraceID: trace.TraceID([16]byte{1}),
+		SpanID:  trace.SpanID([8]byte{1}),
+		Remote:  true,
+	}))
+	ctx, span := tracer.Start(spanCtx, "tracetest")
+	logger.ErrorContext(ctx, "foo")
+	logger.WarnContext(ctx, "bar")
+	span.End()
+	assert.Contains(t, buf.String(), "span_id")
+	assert.Contains(t, buf.String(), "trace_id")
+	assert.Contains(t, buf.String(), "WARNING")
+}