Skip to content

Commit

Permalink
ddtrace/tracer: encode span IDs in execution traces efficiently (#2268)
Browse files Browse the repository at this point in the history
We were previously encoding span IDs into execution traces as base-10
strings. This is wasteful, in terms of CPU time to encode the ID and
more importantly in terms of how much of the limited execution trace
data the profiler collects will be taken up by span IDs. They can be
encoded directly as 8-byte unsigned integers.
  • Loading branch information
nsrip-dd authored Oct 23, 2023
1 parent e1a2437 commit 5e9b0b1
Show file tree
Hide file tree
Showing 2 changed files with 102 additions and 1 deletion.
95 changes: 95 additions & 0 deletions ddtrace/tracer/exec_tracer_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
// Unless explicitly stated otherwise all files in this repository are licensed
// under the Apache License Version 2.0.
// This product includes software developed at Datadog (https://www.datadoghq.com/).
// Copyright 2016 Datadog, Inc.

// Tests in this file rely on parsing execution tracer data, which can change
// formats across Go releases. This guard should be updated as the Go trace
// parser library is upgraded to support new versions.
//go:build !go1.21

package tracer

import (
"bytes"
"context"
"encoding/binary"
rt "runtime/trace"
"testing"

"github.com/stretchr/testify/assert"
gotraceui "honnef.co/go/gotraceui/trace"
)

func TestExecutionTraceSpans(t *testing.T) {
if rt.IsEnabled() {
t.Skip("runtime execution tracing is already enabled")
}

buf := new(bytes.Buffer)
if err := rt.Start(buf); err != nil {
t.Fatal(err)
}
// Ensure we unconditionally stop tracing. It's safe to call this
// multiple times.
defer rt.Stop()

_, _, _, stop := startTestTracer(t)
defer stop()

root, ctx := StartSpanFromContext(context.Background(), "root")
child, _ := StartSpanFromContext(ctx, "child")
root.Finish()
child.Finish()

rt.Stop()

execTrace, err := gotraceui.Parse(buf, nil)
if err != nil {
t.Fatalf("parsing trace: %s", err)
}

type traceSpan struct {
name string
parent string
spanID uint64
}

spans := make(map[int]*traceSpan)
for _, ev := range execTrace.Events {
switch ev.Type {
case gotraceui.EvUserTaskCreate:
id := int(ev.Args[0])
name := execTrace.Strings[ev.Args[2]]
var parent string
if p, ok := spans[int(ev.Args[1])]; ok {
parent = p.name
}
spans[id] = &traceSpan{
name: name,
parent: parent,
}
case gotraceui.EvUserLog:
id := int(ev.Args[0])
span, ok := spans[id]
if !ok {
continue
}
key := execTrace.Strings[ev.Args[1]]
if key == "datadog.uint64_span_id" {
span.spanID = binary.LittleEndian.Uint64([]byte(execTrace.Strings[ev.Args[3]]))
}
}
}

want := []traceSpan{
{name: "root", spanID: root.Context().SpanID()},
{name: "child", parent: "root", spanID: child.Context().SpanID()},
}
var got []traceSpan
for _, v := range spans {
got = append(got, *v)
}

assert.ElementsMatch(t, want, got)
}
8 changes: 7 additions & 1 deletion ddtrace/tracer/tracer.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ package tracer

import (
gocontext "context"
"encoding/binary"
"os"
"runtime/pprof"
rt "runtime/trace"
Expand Down Expand Up @@ -702,7 +703,12 @@ func startExecutionTracerTask(ctx gocontext.Context, span *span) (gocontext.Cont
// skipped.
ctx = globalinternal.WithExecutionNotTraced(ctx)
}
rt.Log(ctx, "span id", strconv.FormatUint(span.SpanID, 10))
var b [8]byte
binary.LittleEndian.PutUint64(b[:], span.SpanID)
// TODO: can we make string(b[:]) not allocate? e.g. with unsafe
// shenanigans? rt.Log won't retain the message string, though perhaps
// we can't assume that will always be the case.
rt.Log(ctx, "datadog.uint64_span_id", string(b[:]))
return ctx, end
}

Expand Down

0 comments on commit 5e9b0b1

Please sign in to comment.