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: contended mutex profiling doesn't work for sync.RWMutex #18496

Closed
vcabbage opened this issue Jan 2, 2017 · 11 comments
Closed

runtime: contended mutex profiling doesn't work for sync.RWMutex #18496

vcabbage opened this issue Jan 2, 2017 · 11 comments
Labels
FrozenDueToAge help wanted NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@vcabbage
Copy link
Member

vcabbage commented Jan 2, 2017

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

go version devel +9def857072 Mon Jan 2 20:21:02 2017 +0000 darwin/amd64

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/kale/go"
GORACE=""
GOROOT="/Users/kale/gomaster"
GOTOOLDIR="/Users/kale/gomaster/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/jv/fp0q8rhx427f6p892mh4mpx40000gn/T/go-build367788226=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

Ran a benchmark with a RWMutex and -mutexprofile enabled.

Example:

func BenchmarkRWMutex(b *testing.B) {
	var mu sync.RWMutex
	b.RunParallel(func(pb *testing.PB) {
		for pb.Next() {
			mu.RLock()
			mu.RUnlock()
		}
	})
}

What did you expect to see?

Mutex contention information.

Example from a similar test using Lock/Unlock:

go tool pprof ./mutex.test mutex.out
Entering interactive mode (type "help" for commands)
(pprof) top10
1.60s of 1.60s total (  100%)
      flat  flat%   sum%        cum   cum%
     1.60s   100%   100%      1.60s   100%  sync.(*Mutex).Unlock
         0     0%   100%      1.60s   100%  github.com/vcabbage/mutexprofile-repro.BenchmarkMutex.func1
         0     0%   100%      1.60s   100%  runtime.goexit
         0     0%   100%      1.60s   100%  testing.(*B).RunParallel.func1

What did you see instead?

go tool pprof ./mutex.test mutex.out
Entering interactive mode (type "help" for commands)
(pprof) top10
profile is empty

I see that sync.Mutex was changed to use runtime_SemacquireMutex instead of runtime_Semacquire in https://golang.org/cl/29650/, but sync.RWMutex continues to use runtime_Semacquire.

I'm unsure if sync.RWMutex was excluded from profiling intentionally, but the lack of profiling information was surprising to me.

@vcabbage vcabbage changed the title runtime: contended mutex profiling doesn't work for RLock/RUnlock runtime: contended mutex profiling doesn't work for sync.RWMutex Jan 2, 2017
@vcabbage
Copy link
Member Author

vcabbage commented Jan 2, 2017

Some profiling information is collected when using the Lock/Unlock methods of a sync.RWMutex, presumably because sync.RWMutex.Lock() locks an underlying sync.Mutex.

@rsc
Copy link
Contributor

rsc commented Jan 4, 2017

This is probably an oversight but I am not willing to change it at this point in the release cycle. Let's fix it early in Go 1.9.

/cc @pjweinb

@rsc rsc added this to the Go1.9Early milestone Jan 4, 2017
@vcabbage
Copy link
Member Author

vcabbage commented Jan 4, 2017

Is it worth a note in the documentation or is this issue good enough?

@rsc
Copy link
Contributor

rsc commented Jan 4, 2017 via email

@gopherbot
Copy link

CL https://golang.org/cl/34831 mentions this issue.

gopherbot pushed a commit that referenced this issue Jan 4, 2017
For #18496.

Change-Id: I50ced7c9f0fe5d9c627eef1f59a7f73be742e04c
Reviewed-on: https://go-review.googlesource.com/34831
Run-TryBot: Russ Cox <rsc@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@pjweinbgo
Copy link
Contributor

I will produce a CL for 1.9.

@bradfitz bradfitz modified the milestones: Go1.10, Go1.9Early May 3, 2017
@bradfitz bradfitz added help wanted NeedsFix The path to resolution is known, but the work has not been done. labels May 3, 2017
@odeke-em
Copy link
Member

How's it going @pjweinbgo, still interested in working on this issue?

@panicfarm
Copy link

panicfarm commented Nov 7, 2017

Has this been fixed? One can use kill -ABRT pid to dump deadlocked goroutines

@pjweinb
Copy link

pjweinb commented Nov 7, 2017 via email

@rsc rsc modified the milestones: Go1.10, Go1.11 Nov 22, 2017
@gopherbot
Copy link

Change https://golang.org/cl/87095 mentions this issue: sync: Enable profiling of RWMutex

@lmb
Copy link
Contributor

lmb commented Jan 10, 2018

I've created a "straw man" CL based on the comments in this issue. Testing with the following makes pprof report contention on both RWMutex.Unlock and RWMutex.RUnlock.

func BenchmarkRWMutex(b *testing.B) {
	var mu sync.RWMutex

	mu.Lock()
	go func() {
		for {
			time.Sleep(10 * time.Millisecond)
			mu.Unlock()
			time.Sleep(10 * time.Millisecond)
			mu.Lock()
		}
	}()

	b.RunParallel(func(pb *testing.PB) {
		for pb.Next() {
			mu.RLock()
			time.Sleep(10 * time.Millisecond)
			mu.RUnlock()
		}
	})
}

I'm not sure whether the measurements are attributed to the right call stack though.

@golang golang locked and limited conversation to collaborators Feb 14, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge help wanted NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Development

No branches or pull requests

9 participants