diff --git a/backend/controller/observability/calls.go b/backend/controller/observability/calls.go index 2e6dbb5479..cebaf46ca5 100644 --- a/backend/controller/observability/calls.go +++ b/backend/controller/observability/calls.go @@ -60,7 +60,7 @@ func (m *CallMetrics) BeginSpan(ctx context.Context, verb *schemapb.Ref) (contex attrs := []attribute.KeyValue{ attribute.String(callVerbRefAttr, schema.RefFromProto(verb).String()), } - return m.callTracer.Start(ctx, callMeterName, trace.WithAttributes(attrs...)) + return observability.AddSpanToLogger(m.callTracer.Start(ctx, callMeterName, trace.WithAttributes(attrs...))) } func (m *CallMetrics) Request(ctx context.Context, verb *schemapb.Ref, startTime time.Time, maybeFailureMode optional.Option[string]) { attrs := []attribute.KeyValue{ diff --git a/backend/controller/observability/controller.go b/backend/controller/observability/controller.go index f3042be2a1..3a32a6a9ad 100644 --- a/backend/controller/observability/controller.go +++ b/backend/controller/observability/controller.go @@ -6,6 +6,8 @@ import ( "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/trace" + + "github.com/TBD54566975/ftl/internal/observability" ) const ( @@ -30,5 +32,5 @@ func (m *ControllerTracing) BeginSpan(ctx context.Context, name string) (context attrs := []attribute.KeyValue{ attribute.String(operation, name), } - return m.polling.Start(ctx, controllerPollingOperation, trace.WithAttributes(attrs...)) + return observability.AddSpanToLogger(m.polling.Start(ctx, controllerPollingOperation, trace.WithAttributes(attrs...))) } diff --git a/backend/runner/runner.go b/backend/runner/runner.go index 0ab02ce5bf..904d0cd56c 100644 --- a/backend/runner/runner.go +++ b/backend/runner/runner.go @@ -35,6 +35,7 @@ import ( "github.com/TBD54566975/ftl/internal/identity" "github.com/TBD54566975/ftl/internal/log" "github.com/TBD54566975/ftl/internal/model" + ftlobservability "github.com/TBD54566975/ftl/internal/observability" "github.com/TBD54566975/ftl/internal/rpc" "github.com/TBD54566975/ftl/internal/schema" "github.com/TBD54566975/ftl/internal/slices" @@ -516,6 +517,7 @@ func (s *Service) getDeploymentLogger(ctx context.Context, deploymentKey model.D if requestKey, _ := rpc.RequestKeyFromContext(ctx); requestKey.Ok() { //nolint:errcheck // best effort attrs["request"] = requestKey.MustGet().String() } + ctx = ftlobservability.AddSpanContextToLogger(ctx) sink := newDeploymentLogsSink(s.deploymentLogQueue) return log.FromContext(ctx).AddSink(sink).Attrs(attrs) diff --git a/go-runtime/server/server.go b/go-runtime/server/server.go index 56f99a6d39..bd3487321f 100644 --- a/go-runtime/server/server.go +++ b/go-runtime/server/server.go @@ -79,6 +79,7 @@ func HandleCall[Req, Resp any](verb any) Handler { if err != nil { return nil, fmt.Errorf("invalid request to verb %s: %w", ref, err) } + ctx = observability.AddSpanContextToLogger(ctx) // Call Verb. resp, err := Call[Req, Resp](ref)(ctx, req) diff --git a/internal/observability/logger.go b/internal/observability/logger.go index d5c3af3876..881e0831cd 100644 --- a/internal/observability/logger.go +++ b/internal/observability/logger.go @@ -1,13 +1,37 @@ package observability import ( + "context" "fmt" + "strconv" "github.com/go-logr/logr" + "go.opentelemetry.io/otel/trace" "github.com/TBD54566975/ftl/internal/log" ) +func AddSpanToLogger(ctx context.Context, span trace.Span) (context.Context, trace.Span) { + ctx = wrapLogger(ctx, span.SpanContext()) + return ctx, span +} + +func AddSpanContextToLogger(ctx context.Context) context.Context { + sc := trace.SpanContextFromContext(ctx) + return wrapLogger(ctx, sc) +} +func wrapLogger(ctx context.Context, sc trace.SpanContext) context.Context { + logger := log.FromContext(ctx) + attributes := map[string]string{} + if sc.HasSpanID() { + attributes["dd.span_id"] = convertTraceID(sc.SpanID().String()) + } + if sc.HasTraceID() { + attributes["dd.trace_id"] = convertTraceID(sc.TraceID().String()) + } + return log.ContextWithLogger(ctx, logger.Attrs(attributes)) +} + type logSink struct { keyValues map[string]interface{} logger *log.Logger @@ -99,3 +123,17 @@ func otelLevelToLevel(level int) log.Level { return log.Trace } } +func convertTraceID(id string) string { + // See https://docs.datadoghq.com/tracing/other_telemetry/connect_logs_and_traces/opentelemetry/?tab=go + if len(id) < 16 { + return "" + } + if len(id) > 16 { + id = id[16:] + } + intValue, err := strconv.ParseUint(id, 16, 64) + if err != nil { + return "" + } + return strconv.FormatUint(intValue, 10) +}