Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: add DD trace id to the logs #3107

Merged
merged 2 commits into from
Oct 15, 2024
Merged
Show file tree
Hide file tree
Changes from all 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
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() {
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess an open question here is if we should be hard coding DD specific attributes. I don't think it matters for now, but we may need to revisit in future.

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)
}