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

@jeffallen jeffallen commented Dec 19, 2015

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

This comment has been minimized.

Copy link
Contributor Author

@jeffallen jeffallen commented Dec 19, 2015

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

This comment has been minimized.

Copy link
Contributor Author

@jeffallen jeffallen commented Dec 19, 2015

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

@jeffallen jeffallen closed this Dec 19, 2015
@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
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
2 participants
You can’t perform that action at this time.