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

x/net/http2: curGoroutineID is called in production #13691

Closed
jeffallen opened this issue Dec 19, 2015 · 2 comments
Closed

x/net/http2: curGoroutineID is called in production #13691

jeffallen opened this issue Dec 19, 2015 · 2 comments

Comments

@jeffallen
Copy link
Contributor

When I was looking at http2 benchmark profiles, I found calls to curGoroutineID. This should not happen unless DEBUG_HTTP2_GOROUTINES=1, but it is inexplicably happening anyway.

All three calls to curGoroutineID are in gotrack.go, and all three are protected by the boolean. If you make the following patch to gotrack.go, so that the boolean is unambiguously false:

git diff gotrack.go 
diff --git a/http2/gotrack.go b/http2/gotrack.go
index 9933c9f..57196da 100644
--- a/http2/gotrack.go
+++ b/http2/gotrack.go
@@ -11,13 +11,12 @@ import (
    "bytes"
    "errors"
    "fmt"
-   "os"
    "runtime"
    "strconv"
    "sync"
 )

-var DebugGoroutines = os.Getenv("DEBUG_HTTP2_GOROUTINES") == "1"
+var DebugGoroutines = false

 type goroutineLock uint64

@@ -49,6 +48,8 @@ func (g goroutineLock) checkNotOn() {
 var goroutineSpace = []byte("goroutine ")

 func curGoroutineID() uint64 {
+   panic("how can we possibly be getting here?")
+
    bp := littleBuf.Get().(*[]byte)
    defer littleBuf.Put(bp)
    b := *bp

And then you run the benchmarks, the panic happens:

$ go test -c && ./http2.test -test.cpuprofile=prof -test.bench=BenchmarkServerPosts -test.run=XXX
BenchmarkServerPosts-4  --- FAIL: BenchmarkServerPosts-4
    http2_test.go:64: 2015/12/19 16:38:31 http: panic serving 127.0.0.1:54702: how can we possibly be getting here?
        goroutine 9 [running]:
        net/http.(*conn).serve.func1(0xc820ad6000)
            /Users/jra/go/src/net/http/server.go:1380 +0xc1
        golang.org/x/net/http2.curGoroutineID(0x0)
            /Users/jra/src/golang.org/x/net/http2/gotrack.go:51 +0x6e
        golang.org/x/net/http2.newGoroutineLock(0x38c620)
            /Users/jra/src/golang.org/x/net/http2/gotrack.go:27 +0x2f
        golang.org/x/net/http2.(*Server).handleConn(0xc8200e2660, 0xc82007a180, 0x949e90, 0xc820ad4000, 0xb26d80, 0xc8203c4080)
            /Users/jra/src/golang.org/x/net/http2/server.go:222 +0x23a

This is with: go version devel +97f854c Sat Dec 19 10:00:04 2015 +0000 darwin/amd64

(I am profiling on MacOS 10.10 with rsc's kernel patch installed. The profile looks correct in all other aspects.)

@jeffallen
Copy link
Contributor Author

I just noticed that TestGoroutineLock leaves DebugGoroutines set to true incorrectly, but in my tests above I was using -test.run=XXX to disable it anyway.

@jeffallen
Copy link
Contributor Author

Sorry, I missed the fact that DebugGoroutines is set in http2_test.go. That explains the behavior that confused me.

@golang golang locked and limited conversation to collaborators Dec 29, 2016
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

2 participants