Skip to content

Commit

Permalink
feat: add DD trace id to the logs (#3107)
Browse files Browse the repository at this point in the history
Only works for the go runtime at the moment, as the JVM logging needs to
be cleaned up to match the go format.

fixes: #3105

---------

Co-authored-by: github-actions[bot] <github-actions[bot]@users.noreply.github.com>
  • Loading branch information
stuartwdouglas and github-actions[bot] authored Oct 15, 2024
1 parent e0092ff commit 097415d
Show file tree
Hide file tree
Showing 5 changed files with 45 additions and 2 deletions.
2 changes: 1 addition & 1 deletion backend/controller/observability/calls.go
Original file line number Diff line number Diff line change
Expand Up @@ -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{
Expand Down
4 changes: 3 additions & 1 deletion backend/controller/observability/controller.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 (
Expand All @@ -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...)))
}
2 changes: 2 additions & 0 deletions backend/runner/runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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)
Expand Down
1 change: 1 addition & 0 deletions go-runtime/server/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down
38 changes: 38 additions & 0 deletions internal/observability/logger.go
Original file line number Diff line number Diff line change
@@ -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
Expand Down Expand Up @@ -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)
}

0 comments on commit 097415d

Please sign in to comment.