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

Ensure spans created by httptrace client tracer reflect operation structure #618

Merged
merged 5 commits into from
Apr 7, 2020
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
65 changes: 51 additions & 14 deletions plugin/httptrace/clienttrace.go
Original file line number Diff line number Diff line change
Expand Up @@ -37,20 +37,35 @@ var (
HTTPLocalAddr = key.New("http.local")
)

var (
hookMap = map[string]string{
"http.dns": "http.getconn",
"http.connect": "http.getconn",
"http.tls": "http.getconn",
}
)

func parentHook(hook string) string {
if strings.HasPrefix(hook, "http.connect") {
return hookMap["http.connect"]
}
return hookMap[hook]
}

type clientTracer struct {
context.Context

tr trace.Tracer

activeHooks map[string]trace.Span
activeHooks map[string]context.Context
root trace.Span
mtx sync.Mutex
}

func NewClientTrace(ctx context.Context) *httptrace.ClientTrace {
ct := &clientTracer{
Context: ctx,
activeHooks: make(map[string]trace.Span),
activeHooks: make(map[string]context.Context),
}

ct.tr = global.Tracer("go.opentelemetry.io/otel/plugin/httptrace")
Expand All @@ -76,25 +91,30 @@ func NewClientTrace(ctx context.Context) *httptrace.ClientTrace {
}

func (ct *clientTracer) start(hook, spanName string, attrs ...core.KeyValue) {
_, sp := ct.tr.Start(ct.Context, spanName, trace.WithAttributes(attrs...), trace.WithSpanKind(trace.SpanKindClient))
ct.mtx.Lock()
defer ct.mtx.Unlock()
if ct.root == nil {
ct.root = sp
}
if _, ok := ct.activeHooks[hook]; ok {
// end was called before start is handled.
sp.End()
delete(ct.activeHooks, hook)

if hookCtx, found := ct.activeHooks[hook]; !found {
var sp trace.Span
ct.activeHooks[hook], sp = ct.tr.Start(ct.getParentContext(hook), spanName, trace.WithAttributes(attrs...), trace.WithSpanKind(trace.SpanKindClient))
if ct.root == nil {
ct.root = sp
}
Aneurysm9 marked this conversation as resolved.
Show resolved Hide resolved
} else {
ct.activeHooks[hook] = sp
// end was called before start finished, add the start attributes and end the span here
span := trace.SpanFromContext(hookCtx)
span.SetAttributes(attrs...)
span.End()

delete(ct.activeHooks, hook)
}
}

func (ct *clientTracer) end(hook string, err error, attrs ...core.KeyValue) {
ct.mtx.Lock()
defer ct.mtx.Unlock()
if span, ok := ct.activeHooks[hook]; ok {
if ctx, ok := ct.activeHooks[hook]; ok {
span := trace.SpanFromContext(ctx)
if err != nil {
span.SetStatus(codes.Unknown, err.Error())
}
Expand All @@ -103,14 +123,31 @@ func (ct *clientTracer) end(hook string, err error, attrs ...core.KeyValue) {
delete(ct.activeHooks, hook)
} else {
// start is not finished before end is called.
ct.activeHooks[hook] = trace.NoopSpan{}
// Start a span here with the ending attributes that will be finished when start finishes.
// Yes, it's backwards. v0v
ctx, span := ct.tr.Start(ct.getParentContext(hook), hook, trace.WithAttributes(attrs...), trace.WithSpanKind(trace.SpanKindClient))
if err != nil {
span.SetStatus(codes.Unknown, err.Error())
}
ct.activeHooks[hook] = ctx
}
}

func (ct *clientTracer) getParentContext(hook string) context.Context {
ctx, ok := ct.activeHooks[parentHook(hook)]
if !ok {
return ct.Context
}
return ctx
}

func (ct *clientTracer) span(hook string) trace.Span {
ct.mtx.Lock()
defer ct.mtx.Unlock()
return ct.activeHooks[hook]
if ctx, ok := ct.activeHooks[hook]; ok {
return trace.SpanFromContext(ctx)
}
return nil
}

func (ct *clientTracer) getConn(host string) {
Expand Down
70 changes: 61 additions & 9 deletions plugin/httptrace/clienttrace_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import (
"context"
"net/http"
"net/http/httptest"
nhtrace "net/http/httptrace"
"sync"
"testing"

Expand Down Expand Up @@ -86,41 +87,59 @@ func TestHTTPRequestWithClientTrace(t *testing.T) {
panic("unexpected error in http request: " + err.Error())
}

getSpan := func(name string) *export.SpanData {
spans, ok := exp.spanMap[name]
if !ok {
t.Fatalf("no spans found with the name %s, %v", name, exp.spanMap)
}

if len(spans) != 1 {
t.Fatalf("Expected exactly one span for %s but found %d", name, len(spans))
}

return spans[0]
}

testLen := []struct {
name string
attributes []core.KeyValue
parent string
}{
{
name: "http.connect",
attributes: []core.KeyValue{key.String("http.remote", address.String())},
parent: "http.getconn",
},
{
name: "http.getconn",
attributes: []core.KeyValue{
key.String("http.remote", address.String()),
key.String("http.host", address.String()),
},
parent: "test",
},
{
name: "http.receive",
name: "http.receive",
parent: "test",
},
{
name: "http.send",
name: "http.send",
parent: "test",
},
{
name: "test",
},
}
for _, tl := range testLen {
spans, ok := exp.spanMap[tl.name]
if !ok {
t.Fatalf("no spans found with the name %s, %v", tl.name, exp.spanMap)
}
span := getSpan(tl.name)

if len(spans) != 1 {
t.Fatalf("Expected exactly one span for %s but found %d", tl.name, len(spans))
if tl.parent != "" {
parentSpan := getSpan(tl.parent)

if span.ParentSpanID != parentSpan.SpanContext.SpanID {
t.Fatalf("[span %s] does not have expected parent span %s", tl.name, tl.parent)
}
}
span := spans[0]

actualAttrs := make(map[core.Key]string)
for _, attr := range span.Attributes {
Expand Down Expand Up @@ -263,3 +282,36 @@ func TestConcurrentConnectionStart(t *testing.T) {
})
}
}

func TestEndBeforeStartCreatesSpan(t *testing.T) {
exp := &testExporter{
spanMap: make(map[string][]*export.SpanData),
}
tp, _ := sdktrace.NewProvider(sdktrace.WithSyncer(exp), sdktrace.WithConfig(sdktrace.Config{DefaultSampler: sdktrace.AlwaysSample()}))
global.SetTraceProvider(tp)

tr := tp.Tracer("httptrace/client")
ctx, span := tr.Start(context.Background(), "test")
defer span.End()

ct := httptrace.NewClientTrace(ctx)

ct.DNSDone(nhtrace.DNSDoneInfo{})
ct.DNSStart(nhtrace.DNSStartInfo{Host: "example.com"})

getSpan := func(name string) *export.SpanData {
spans, ok := exp.spanMap[name]
if !ok {
t.Fatalf("no spans found with the name %s, %v", name, exp.spanMap)
}

if len(spans) != 1 {
t.Fatalf("Expected exactly one span for %s but found %d", name, len(spans))
}

return spans[0]
}

getSpan("http.dns")

}