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.

Sign up for GitHub

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

Fix and detect race condition in clienttrace.go #5700

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open

Fix and detect race condition in clienttrace.go #5700

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
647b6f3
Fix and detect race condition in clienttrace.go
gregorynisbet-google Jun 1, 2024
b0dce52
Merge branch 'open-telemetry:main' into 2024-05-31-fix-race-condition
gregorynisbet-google Jun 21, 2024
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
18 changes: 13 additions & 5 deletions instrumentation/net/http/httptrace/otelhttptrace/clienttrace.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -186,6 +186,9 @@ func NewClientTrace(ctx context.Context, opts ...ClientTraceOption) *httptrace.C
}

func (ct *clientTracer) start(hook, spanName string, attrs ...attribute.KeyValue) {
ct.mtx.Lock()
defer ct.mtx.Unlock()

if !ct.useSpans {
if ct.root == nil {
ct.root = trace.SpanFromContext(ct.Context)
Expand All @@ -194,9 +197,6 @@ func (ct *clientTracer) start(hook, spanName string, attrs ...attribute.KeyValue
return
}

ct.mtx.Lock()
defer ct.mtx.Unlock()

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))
Expand All @@ -214,6 +214,13 @@ func (ct *clientTracer) start(hook, spanName string, attrs ...attribute.KeyValue
}

func (ct *clientTracer) end(hook string, err error, attrs ...attribute.KeyValue) {
ct.mtx.Lock()
defer ct.mtx.Unlock()

if ct.root == nil {
return
}
Comment on lines +220 to +222
Copy link
Contributor

Choose a reason for hiding this comment

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

It looks like this is what is breaking

opentelemetry-go-contrib/instrumentation/net/http/httptrace/otelhttptrace/test/clienttrace_test.go

Lines 239 to 251 in b0dce52

func TestEndBeforeStartCreatesSpan(t *testing.T) {
sr := tracetest.NewSpanRecorder()
tp := trace.NewTracerProvider(trace.WithSpanProcessor(sr))
otel.SetTracerProvider(tp)
ct := otelhttptrace.NewClientTrace(context.Background())
ct.DNSDone(httptrace.DNSDoneInfo{})
ct.DNSStart(httptrace.DNSStartInfo{Host: "example.com"})
name := "http.dns"
spans := getSpansFromRecorder(sr, name)
require.Len(t, spans, 1)
}

https://github.com/open-telemetry/opentelemetry-go-contrib/actions/runs/9620444944/job/26539940748?pr=5700


if !ct.useSpans {
if err != nil {
attrs = append(attrs, attribute.String(hook+".error", err.Error()))
Expand All @@ -222,8 +229,6 @@ func (ct *clientTracer) end(hook string, err error, attrs ...attribute.KeyValue)
return
}

ct.mtx.Lock()
defer ct.mtx.Unlock()
if ctx, ok := ct.activeHooks[hook]; ok {
span := trace.SpanFromContext(ctx)
if err != nil {
Expand Down Expand Up @@ -321,6 +326,9 @@ func (ct *clientTracer) tlsHandshakeDone(_ tls.ConnectionState, err error) {
}

func (ct *clientTracer) wroteHeaderField(k string, v []string) {
if ct.root == nil {
return
}
if ct.useSpans && ct.span("http.headers") == nil {
ct.start("http.headers", "http.headers")
}
Expand Down
44 changes: 44 additions & 0 deletions instrumentation/net/http/httptrace/otelhttptrace/clienttrace_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@ import (
"fmt"
"net/http"
"net/http/httptrace"
"sync"
"testing"

"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)
Expand All @@ -32,3 +34,45 @@ func ExampleNewClientTrace() {

fmt.Println(resp.Status)
}

type zeroTripper struct{}

func (zeroTripper) RoundTrip(_ *http.Request) (*http.Response, error) {
return &http.Response{StatusCode: 200}, nil
}

var _ http.RoundTripper = zeroTripper{}

// TestNewClientParallelismWithoutSubspans tests running many Gets on a client simultaneously,
// which would trigger a race condition if root were not protected by a mutex.
func TestNewClientParallelismWithoutSubspans(t *testing.T) {
Copy link
Contributor

Choose a reason for hiding this comment

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

This test passes when run against main:

$ go test -race -count=20 .
ok  	go.opentelemetry.io/contrib/instrumentation/net/http/httptrace/otelhttptrace	5.443s

It does not seem to be testing the fix being applied here.

t.Parallel()

makeClientTrace := func(ctx context.Context) *httptrace.ClientTrace {
return NewClientTrace(ctx, WithoutSubSpans())
}

client := http.Client{
Transport: otelhttp.NewTransport(
zeroTripper{},
otelhttp.WithClientTrace(makeClientTrace),
),
}

var wg sync.WaitGroup

for i := 1; i < 10000; i++ {
Copy link
Contributor

Choose a reason for hiding this comment

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

This is a lot of goroutines being spawned here. What's the reasoning behind this? It is making this test quite resource intensive.

wg.Add(1)
go func() {
resp, err := client.Get("}}}}}")
if err != nil {
t.Error(err)
return
}
resp.Body.Close()
wg.Done()
}()
}

wg.Wait()
}
Loading