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

net/http2: orphan http handler when h2 connection closed #37920

Open
detailyang opened this issue Mar 18, 2020 · 7 comments · May be fixed by golang/net#66
Open

net/http2: orphan http handler when h2 connection closed #37920

detailyang opened this issue Mar 18, 2020 · 7 comments · May be fixed by golang/net#66
Milestone

Comments

@detailyang
Copy link

@detailyang detailyang commented Mar 18, 2020

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

$ go version                                                                                                                                                
go version go1.14 darwin/amd64

Does this issue reproduce with the latest release?

Yep

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

go env Output
$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/detailyang/Library/Caches/go-build"
GOENV="/Users/detailyang/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GONOPROXY="**.baidu.com**"
GONOSUMDB="*"
GOOS="darwin"
GOPATH="/Users/detailyang/go"
GOPRIVATE="gitlab.alipay-inc.com"
GOPROXY="https://goproxy.baidu.com,https://goproxy.cn,direct"
GOROOT="/usr/local/go"
GOSUMDB="off"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/detailyang/go/src/github.com/golang/net/go.mod"
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=/var/folders/n3/g3fv953s435gqv0x7557ftyc0000gp/T/go-build680170406=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

Now the http2 server directly exits the connection loop without waiting all handlers done which causes the HTTP handler orphan as the following: https://github.com/golang/net/blob/244492dfa37ae2ce87222fd06250a03160745faa/http2/server.go#L806


func (sc *serverConn) serve() {
	sc.serveG.check()
	defer sc.notePanic()
	defer sc.conn.Close()
	defer sc.closeAllStreamsOnConnClose()
	defer sc.stopShutdownTimer()
	defer close(sc.doneServing) // unblocks handlers trying to send
if VerboseLogs {
	sc.vlogf("http2: server connection from %v on %p", sc.conn.RemoteAddr(), sc.hs)
}

sc.writeFrame(FrameWriteRequest{
	write: writeSettings{
		{SettingMaxFrameSize, sc.srv.maxReadFrameSize()},
		{SettingMaxConcurrentStreams, sc.advMaxStreams},
		{SettingMaxHeaderListSize, sc.maxHeaderListSize()},
		{SettingInitialWindowSize, uint32(sc.srv.initialStreamRecvWindowSize())},
	},
})
sc.unackedSettings++

// Each connection starts with intialWindowSize inflow tokens.
// If a higher value is configured, we add more tokens.
if diff := sc.srv.initialConnRecvWindowSize() - initialWindowSize; diff > 0 {
	sc.sendWindowUpdate(nil, int(diff))
}

if err := sc.readPreface(); err != nil {
	sc.condlogf(err, "http2: server: error reading preface from client %v: %v", sc.conn.RemoteAddr(), err)
	return
}
// Now that we've got the preface, get us out of the
// "StateNew" state. We can't go directly to idle, though.
// Active means we read some data and anticipate a request. We'll
// do another Active when we get a HEADERS frame.
sc.setConnState(http.StateActive)
sc.setConnState(http.StateIdle)

if sc.srv.IdleTimeout != 0 {
	sc.idleTimer = time.AfterFunc(sc.srv.IdleTimeout, sc.onIdleTimer)
	defer sc.idleTimer.Stop()
}

go sc.readFrames() // closed by defer sc.conn.Close above

settingsTimer := time.AfterFunc(firstSettingsTimeout, sc.onSettingsTimer)
defer settingsTimer.Stop()

loopNum := 0
for {
	loopNum++
	select {
	case wr := <-sc.wantWriteFrameCh:
		if se, ok := wr.write.(StreamError); ok {
			sc.resetStream(se)
			break
		}
		sc.writeFrame(wr)
	case res := <-sc.wroteFrameCh:
		sc.wroteFrame(res)
	case res := <-sc.readFrameCh:
		if !sc.processFrameFromReader(res) {
			return
		}
		res.readMore()
		if settingsTimer != nil {
			settingsTimer.Stop()
			settingsTimer = nil
		}
	case m := <-sc.bodyReadCh:
		sc.noteBodyRead(m.st, m.n)
	case msg := <-sc.serveMsgCh:
		switch v := msg.(type) {
		case func(int):
			v(loopNum) // for testing
		case *serverMessage:
			switch v {
			case settingsTimerMsg:
				sc.logf("timeout waiting for SETTINGS frames from %v", sc.conn.RemoteAddr())
				return
			case idleTimerMsg:
				sc.vlogf("connection is idle")
				sc.goAway(ErrCodeNo)
			case shutdownTimerMsg:
				sc.vlogf("GOAWAY close timer fired; closing conn from %v", sc.conn.RemoteAddr())
				return
			case gracefulShutdownMsg:
				sc.startGracefulShutdownInternal()
			default:
				panic("unknown timer")
			}
		case *startPushRequest:
			sc.startPush(v)
		default:
			panic(fmt.Sprintf("unexpected type %T", v))
		}
	}

	// If the peer is causing us to generate a lot of control frames,
	// but not reading them from us, assume they are trying to make us
	// run out of memory.
	if sc.queuedControlFrames > sc.srv.maxQueuedControlFrames() {
		sc.vlogf("http2: too many control frames in send queue, closing connection")
		return
	}

	// Start the shutdown timer after sending a GOAWAY. When sending GOAWAY
	// with no error code (graceful shutdown), don't start the timer until
	// all open streams have been completed.
	sentGoAway := sc.inGoAway && !sc.needToSendGoAway && !sc.writingFrame
	gracefulShutdownComplete := sc.goAwayCode == ErrCodeNo && sc.curOpenStreams() == 0
	if sentGoAway && sc.shutdownTimer == nil && (sc.goAwayCode != ErrCodeNo || gracefulShutdownComplete) {
		sc.shutDownIn(goAwayTimeout)
	}
}

}

Online Go Play Here: https://play.golang.org/p/m6m2aKIlRCJ

Shouldn't we wait for all handlers finished then exit?

What did you expect to see?

See the output "handler stop"

What did you see instead?

nothing

detailyang added a commit to detailyang/net that referenced this issue Mar 18, 2020
Fixes golang/go#37920

Signed-off-by: detailyang <detailyang@gmail.com>
@detailyang detailyang linked a pull request that will close this issue Mar 18, 2020
@gopherbot
Copy link

@gopherbot gopherbot commented Mar 18, 2020

Change https://golang.org/cl/223899 mentions this issue: bugfix:http2:avoid orphan handler

@cagedmantis cagedmantis added this to the Backlog milestone Mar 23, 2020
@cagedmantis
Copy link
Contributor

@cagedmantis cagedmantis commented Mar 23, 2020

@networkimprov
Copy link

@networkimprov networkimprov commented Mar 23, 2020

@fraenkel
Copy link
Contributor

@fraenkel fraenkel commented Mar 24, 2020

@detailyang I am struggling with where you think the issue lies. In both the play link and your testcase, you have opted to use ServeConn which states that it will block until the connection is no longer readable.
You have configured a client with a very short timeout, which means the connection will break before the handler completes. This intern will cause ServeConn to exit as expected.

@detailyang
Copy link
Author

@detailyang detailyang commented Mar 24, 2020

@fraenkel AFAIK, The lifecycle of HTTP handlers should be the same as the ServeConn.

@fraenkel
Copy link
Contributor

@fraenkel fraenkel commented Mar 24, 2020

From the documentation (https://godoc.org/golang.org/x/net/http2#Server.ServeConn)
ServeConn serves HTTP/2 requests on the provided connection and blocks until the connection is no longer readable.

@detailyang
Copy link
Author

@detailyang detailyang commented Mar 24, 2020

@fraenkel the ServeConn should block until the connection is no longer readable and all the handler finished, more detail see the PR golang/net#66

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

5 participants
You can’t perform that action at this time.