Skip to content

x/net/trace: data race using RenderEvents #76402

@marefr

Description

@marefr

Go version

go version go1.24.1 darwin/arm64

Output of go env in your module/workspace:

AR='ar'
CC='cc'
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_ENABLED='1'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
CXX='c++'
GCCGO='gccgo'
GO111MODULE=''
GOARCH='arm64'
GOARM64='v8.0'
GOAUTH='netrc'
GOBIN=''
GOCACHE='/Users/marcus/Library/Caches/go-build'
GOCACHEPROG=''
GODEBUG=''
GOENV='/Users/marcus/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFIPS140='off'
GOFLAGS=''
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/w4/2g0lfwdx05b4n7wcv7wpg9kh0000gn/T/go-build3363630429=/tmp/go-build -gno-record-gcc-switches -fno-common'
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMOD='/Users/marcus/go/src/github.com/marefr/enablebankinggo/go.mod'
GOMODCACHE='/Users/marcus/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='darwin'
GOPATH='/Users/marcus/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/homebrew/Cellar/go/1.24.1/libexec'
GOSUMDB='sum.golang.org'
GOTELEMETRY='on'
GOTELEMETRYDIR='/Users/marcus/Library/Application Support/go/telemetry'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/homebrew/Cellar/go/1.24.1/libexec/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.24.1'
GOWORK=''
PKG_CONFIG='pkg-config'

What did you do?

  1. Writing events to event log using golang.org/x/net/trace
  2. Writing a test to verify eventlog was created using trace.RenderEvents(...)
  3. Running tests with race detector enabled

What did you see happen?

WARNING: DATA RACE
Read at 0x00c000095a70 by goroutine 8:
  golang.org/x/net/trace.RenderEvents()
      /home/runner/go/pkg/mod/golang.org/x/[email protected]/trace/events.go:61 +0x171
  github.com/marefr/go-conntrack/providers/trace_test.fetchTraceEvents()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:89 +0x284
  github.com/marefr/go-conntrack/providers/trace_test.TestDialerTracingCapturedInPage()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:33 +0x29c
  testing.tRunner()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1934 +0x21c
  testing.(*T).Run.gowrap1()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1997 +0x44
Details
==================
WARNING: DATA RACE
Read at 0x00c000095a70 by goroutine 8:
  golang.org/x/net/trace.RenderEvents()
      /home/runner/go/pkg/mod/golang.org/x/[email protected]/trace/events.go:61 +0x171
  github.com/marefr/go-conntrack/providers/trace_test.fetchTraceEvents()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:89 +0x284
  github.com/marefr/go-conntrack/providers/trace_test.TestDialerTracingCapturedInPage()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:33 +0x29c
  testing.tRunner()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1934 +0x21c
  testing.(*T).Run.gowrap1()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1997 +0x44

Previous write at 0x00c000095a70 by goroutine 9:
  runtime.mapassign_faststr()
      /opt/hostedtoolcache/go/1.25.4/x64/src/internal/runtime/maps/runtime_faststr_swiss.go:263 +0x0
  golang.org/x/net/trace.getEventFamily()
      /home/runner/go/pkg/mod/golang.org/x/[email protected]/trace/events.go:162 +0x14f
  golang.org/x/net/trace.NewEventLog()
      /home/runner/go/pkg/mod/golang.org/x/[email protected]/trace/events.go:142 +0x2c5
  github.com/marefr/go-conntrack/providers/trace.trackListenerConnection()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer.go:78 +0x359
  github.com/marefr/go-conntrack/providers/trace.tracer.TrackConnection()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer.go:48 +0xbe
  github.com/marefr/go-conntrack/providers/trace.(*tracer).TrackConnection()
      <autogenerated>:1 +0x64
  github.com/marefr/go-conntrack/v2.(*connTrackListener).Accept()
      /home/runner/work/go-conntrack/go-conntrack/listener_wrapper.go:134 +0xbb1
  net/http.(*onceCloseListener).Accept()
      <autogenerated>:1 +0x43
  net/http.(*Server).Serve()
      /opt/hostedtoolcache/go/1.25.4/x64/src/net/http/server.go:3463 +0x60f
  github.com/marefr/go-conntrack/providers/trace_test.setupServerListener.func2()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:77 +0x70

Goroutine 8 (running) created at:
  testing.(*T).Run()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1997 +0x9d2
  testing.runTests.func1()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:2477 +0x85
  testing.tRunner()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1934 +0x21c
  testing.runTests()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:2475 +0x96c
  testing.(*M).Run()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:2337 +0xed4
  main.main()
      _testmain.go:49 +0x164

Goroutine 9 (running) created at:
  github.com/marefr/go-conntrack/providers/trace_test.setupServerListener()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:76 +0x4a8
  github.com/marefr/go-conntrack/providers/trace_test.TestDialerTracingCapturedInPage()
      /home/runner/work/go-conntrack/go-conntrack/providers/trace/tracer_test.go:26 +0x3e
  testing.tRunner()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1934 +0x21c
  testing.(*T).Run.gowrap1()
      /opt/hostedtoolcache/go/1.25.4/x64/src/testing/testing.go:1997 +0x44
==================
--- FAIL: TestDialerTracingCapturedInPage (0.02s)
    tracer_test.go:38: stopping http.Server at: 127.0.0.1:43071
    testing.go:1617: race detected during execution of test
FAIL
FAIL	github.com/marefr/go-conntrack/providers/trace	0.037s
FAIL

What did you expect to see?

No data race.

There might be problems with my code, however I did notice what seems like a bug in the following lines as pointed out by data race warning /home/runner/go/pkg/mod/golang.org/x/[email protected]/trace/events.go:61 (code):

data.Families = make([]string, 0, len(families))
famMu.RLock()

I'm pretty sure the read lock should happen before since len(families) is a read, i.e.

famMu.RLock()
data.Families = make([]string, 0, len(families))

My code/test in question here: https://github.com/marefr/go-conntrack/blob/v2-poc/providers/trace/tracer_test.go

Additional information:
I did manually change so that the read lock happens before in events.go and the data race goes away.

Metadata

Metadata

Assignees

No one assigned

    Labels

    BugReportIssues describing a possible bug in the Go implementation.NeedsFixThe path to resolution is known, but the work has not been done.

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions