Navigation Menu

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

runtime/pprof: race detected between goroutines?debug=1 and setting goroutine labels #50292

Closed
tbg opened this issue Dec 21, 2021 · 2 comments
Closed
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.

Comments

@tbg
Copy link

tbg commented Dec 21, 2021

What version of Go are you using (go version)?

$ go version
go version go1.17.3 darwin/amd64

Does this issue reproduce with the latest release?

yes, same with 1.17.5 (just checked)

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/tobias/Library/Caches/go-build"
GOENV="/Users/tobias/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/tobias/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/tobias/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.17.5"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/nm/j0343rr1275fpm9r3bk3vr200000gq/T/go-build2415583411=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

go test -race foo_test.go

var labelSet = pprof.Labels("foo", "bar")

func TestRace(t *testing.T) {
	go func(ctx context.Context) {
		ctx = pprof.WithLabels(ctx, labelSet)
		pprof.SetGoroutineLabels(ctx)
	}(context.Background())
	require.NoError(t, pprof.Lookup("goroutine").WriteTo(io.Discard, 1))
}

What did you expect to see?

Passing test and no data race.

What did you see instead?

=== RUN   TestRace
==================
WARNING: DATA RACE
Read at 0x00c000124020 by goroutine 22:
  runtime/pprof.(*labelMap).String()
      /usr/local/go/src/runtime/pprof/label.go:46 +0x53
  runtime/pprof.printCountProfile.func1()
      /usr/local/go/src/runtime/pprof/pprof.go:415 +0x178
  runtime/pprof.printCountProfile()
      /usr/local/go/src/runtime/pprof/pprof.go:424 +0x2f1
  runtime/pprof.writeRuntimeProfile()
      /usr/local/go/src/runtime/pprof/pprof.go:732 +0x1b8
  runtime/pprof.writeGoroutine()
      /usr/local/go/src/runtime/pprof/pprof.go:684 +0x8f
  runtime/pprof.(*Profile).WriteTo()
      /usr/local/go/src/runtime/pprof/pprof.go:331 +0x1b0
  github.com/cockroachdb/cockroach/pkg/util/stop.TestRace()
      /Users/tobias/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/tc_test.go:29 +0x129
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1259 +0x22f
  testing.(*T).Run·dwrap·21()
      /usr/local/go/src/testing/testing.go:1306 +0x47

Previous write at 0x00c000124020 by goroutine 23:
  runtime/pprof.WithLabels()
      /usr/local/go/src/runtime/pprof/label.go:60 +0x88
  github.com/cockroachdb/cockroach/pkg/util/stop.TestRace.func1()
      /Users/tobias/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/tc_test.go:26 +0x57
  github.com/cockroachdb/cockroach/pkg/util/stop.TestRace·dwrap·20()
      /Users/tobias/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/tc_test.go:28 +0x58
@dmitshur dmitshur added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Dec 21, 2021
@tbg
Copy link
Author

tbg commented Dec 22, 2021

I see that there's already some special casing around labels:

go/src/runtime/profbuf.go

Lines 545 to 558 in 90fb5a4

b.rNext = br.addCountsAndClearFlags(skip+di, ti)
if raceenabled {
// Match racereleasemerge in runtime_setProfLabel,
// so that the setting of the labels in runtime_setProfLabel
// is treated as happening before any use of the labels
// by our caller. The synchronization on labelSync itself is a fiction
// for the race detector. The actual synchronization is handled
// by the fact that the signal handler only reads from the current
// goroutine and uses atomics to write the updated queue indices,
// and then the read-out from the signal handler buffer uses
// atomics to read those queue indices.
raceacquire(unsafe.Pointer(&labelSync))
}

//go:linkname runtime_setProfLabel runtime/pprof.runtime_setProfLabel
func runtime_setProfLabel(labels unsafe.Pointer) {
// Introduce race edge for read-back via profile.
// This would more properly use &getg().labels as the sync address,
// but we do the read in a signal handler and can't call the race runtime then.
//
// This uses racereleasemerge rather than just racerelease so
// the acquire in profBuf.read synchronizes with *all* prior
// setProfLabel operations, not just the most recent one. This
// is important because profBuf.read will observe different
// labels set by different setProfLabel operations on
// different goroutines, so it needs to synchronize with all
// of them (this wouldn't be an issue if we could synchronize
// on &getg().labels since we would synchronize with each
// most-recent labels write separately.)
//
// racereleasemerge is like a full read-modify-write on
// labelSync, rather than just a store-release, so it carries
// a dependency on the previous racereleasemerge, which
// ultimately carries forward to the acquire in profBuf.read.
if raceenabled {
racereleasemerge(unsafe.Pointer(&labelSync))
}

Perhaps this isn't quite working out as intended.

@gopherbot
Copy link

Change https://go.dev/cl/385660 mentions this issue: runtime/pprof: add race annotations for goroutine profiles

@golang golang locked and limited conversation to collaborators May 3, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

3 participants