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

testing: Benchmark calls during benchmarks deadlock #29727

Open
empijei opened this issue Jan 14, 2019 · 3 comments
Open

testing: Benchmark calls during benchmarks deadlock #29727

empijei opened this issue Jan 14, 2019 · 3 comments
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@empijei
Copy link
Contributor

empijei commented Jan 14, 2019

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

$ go version
go version go1.11.2 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="REDACTED"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="REDACTED"
GOPROXY=""
GORACE=""
GOROOT="/usr/lib/google-golang"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/google-golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build117573359=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Called testing.Benchmark in a Benchmark. The reason for this is that I wanted to check during benchmarks which one of two possible implementations would be faster on the current machine and for a set of given inputs.

Here is a minimal repro that should be run as a benchmark to crash (must be in *_test.go and should be run with go test -bench=. )

package foo

func Foo(n int) {
	// Dummy function to benchmark
	for i := 0; i < n; i++ {
		time.Sleep(time.Nanosecond)
	}
}

func BenchmarkFoo(b *testing.B) {
	res1 := testing.Benchmark(func(b *testing.B) {
		for i := 0; i < b.N; i++ {
			Foo(1)
		}
	})
	res2 := testing.Benchmark(func(b *testing.B) {
		for i := 0; i < b.N; i++ {
			Foo(2)
		}
	})
	b.Logf("Difference between executions is ~%dns", res2.NsPerOp()-res1.NsPerOp())
}

What did you expect to see?

"Difference between executions is ~1ns

What did you see instead?

goroutine 1 [chan receive]:
testing.(*B).run1(0xc000096000, 0xc000096000)
        /usr/lib/google-golang/src/testing/benchmark.go:216 +0x9e
testing.(*B).Run(0xc000096340, 0x5358f5, 0xc, 0x53d380, 0x4abe00)
        /usr/lib/google-golang/src/testing/benchmark.go:514 +0x26c
testing.runBenchmarks.func1(0xc000096340)
        /usr/lib/google-golang/src/testing/benchmark.go:416 +0x78
testing.(*B).runN(0xc000096340, 0x1)
        /usr/lib/google-golang/src/testing/benchmark.go:141 +0xb2
testing.runBenchmarks(0x0, 0x0, 0xc00007e060, 0x616150, 0x1, 0x1, 0x80)
        /usr/lib/google-golang/src/testing/benchmark.go:422 +0x323
testing.(*M).Run(0xc0000b4000, 0x0)
        /usr/lib/google-golang/src/testing/testing.go:1042 +0x37c
main.main()
        _testmain.go:42 +0x13d

goroutine 7 [chan receive]:
testing.(*B).run1(0xc0000964e0, 0xc0000964e0)
        /usr/lib/google-golang/src/testing/benchmark.go:216 +0x9e
testing.Benchmark(0x53d370, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/lib/google-golang/src/testing/benchmark.go:658 +0xd6
_/MYHOME/tmp/benchbug.BenchmarkFoo(0xc000096000)
        /MYHOME/tmp/benchbug/foo_test.go:16 +0x3f
testing.(*B).runN(0xc000096000, 0x1)
        /usr/lib/google-golang/src/testing/benchmark.go:141 +0xb2
testing.(*B).run1.func1(0xc000096000)
        /usr/lib/google-golang/src/testing/benchmark.go:214 +0x5a
created by testing.(*B).run1
        /usr/lib/google-golang/src/testing/benchmark.go:207 +0x7d

goroutine 22 [semacquire]:
sync.runtime_SemacquireMutex(0x639c04, 0x0)
        /usr/lib/google-golang/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0x639c00)
        /usr/lib/google-golang/src/sync/mutex.go:134 +0xff
testing.(*B).runN(0xc0000964e0, 0x1)
        /usr/lib/google-golang/src/testing/benchmark.go:131 +0x31
testing.(*B).run1.func1(0xc0000964e0)
        /usr/lib/google-golang/src/testing/benchmark.go:214 +0x5a
created by testing.(*B).run1
        /usr/lib/google-golang/src/testing/benchmark.go:207 +0x7d
exit status 2
FAIL    _/MYHOME/tmp/benchbug       0.022s

Probable cause

During the first iteration of benchFunc run1 is executed. run1 invokes runN which will run run1. The issue is that runN tries to acquire a global lock while holding it, causing the deadlock.

Source for runN:

// runN runs a single benchmark for the specified number of iterations.
func (b *B) runN(n int) {
	benchmarkLock.Lock() // ← acquiring global mutex
	defer benchmarkLock.Unlock()
	// Try to get a comparable environment for each run
	// by clearing garbage from previous runs.
	runtime.GC()
	b.raceErrors = -race.Errors()
	b.N = n
	b.parallelism = 1
	b.ResetTimer()
	b.StartTimer()
	b.benchFunc(b) // ← This will run run1, which will call runN, which will deadlock

Source for run1:

// run1 runs the first iteration of benchFunc. It returns whether more
// iterations of this benchmarks should be run.
func (b *B) run1() bool {
	if ctx := b.context; ctx != nil {
		// Extend maxLen, if needed.
		if n := len(b.name) + ctx.extLen + 1; n > ctx.maxLen {
			ctx.maxLen = n + 8 // Add additional slack to avoid too many jumps in size.
		}
	}
	go func() {
		// Signal that we're done whether we return normally
		// or by FailNow's runtime.Goexit.
		defer func() {
			b.signal <- true
		}()

		b.runN(1) // ← Running runN
	}()
	<-b.signal
@empijei empijei changed the title testing: Benchmark calls in benchmarks run deadlock testing: Benchmark calls during benchmarks deadlock Jan 14, 2019
@mvdan
Copy link
Member

mvdan commented Jan 14, 2019

Are calls to testing.Benchmark within a benchmark supported? But I agree that something is wrong. Even if they're not supported, the testing package should error properly instead of deadlocking.

@mvdan mvdan added the NeedsFix The path to resolution is known, but the work has not been done. label Jan 14, 2019
@empijei
Copy link
Contributor Author

empijei commented Jan 14, 2019

Current doc states

Benchmark benchmarks a single function. Useful for creating custom benchmarks that do not use the "go test" command.

Should this be corrected to something that specifies it should only be used for those cases that do not use "go test" or it is clear enough and I just misread it?

@dtracers
Copy link

What is the proper way to compare speeds of functions as a part of go test?

If I want to average a bunch of separate benchmarks together for example of different file sizes what would be the proper way to do it?

@seankhliao seankhliao added this to the Unplanned milestone Aug 20, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Development

No branches or pull requests

4 participants