http2: discard DATA frames with higher stream IDs during graceful shutdown

If the server sends a GOAWAY at the same time that a client sends
HEADERS+DATA, the server will discard the HEADERS, but error on the DATA
frame. Luckily, the server doesn't turn this into a connection error
because it's already in a GOAWAY state. It just logs the PROTOCOL_ERROR,
but that produces a confusing log message.

This change effectively suppresses the log message by discarding the
DATA frame rather than erroring on it. Also, we now discard any frames for
streams with identifiers higher than the identified last stream. This is
done as per section 6.8 of the HTTP2 spec.

I also updated some stale documentation while I was trying to understand
the logic.

This is CL 188360 with a test

Fixes golang/go#32112

Co-authored-by: Yunchi Luo <[email protected]>
Co-authored-by: Michael Fraenkel <[email protected]>

Change-Id: I612c2bd82e37551e813af0961b16a98d14e77c38
Reviewed-on: https://go-review.googlesource.com/c/net/+/237957
Run-TryBot: Agniva De Sarker <[email protected]>
Run-TryBot: Emmanuel Odeke <[email protected]>
Reviewed-by: Emmanuel Odeke <[email protected]>
TryBot-Result: Go Bot <[email protected]>
Trust: Damien Neil <[email protected]>

Author: ashishbhate

http2/server.go

@@ -1293,7 +1293,9 @@ func (sc *serverConn) startGracefulShutdown() {
 	sc.shutdownOnce.Do(func() { sc.sendServeMsg(gracefulShutdownMsg) })
 }
 
-// After sending GOAWAY, the connection will close after goAwayTimeout.
+// After sending GOAWAY with an error code (non-graceful shutdown), the
+// connection will close after goAwayTimeout.
+//
 // If we close the connection immediately after sending GOAWAY, there may
 // be unsent data in our kernel receive buffer, which will cause the kernel
 // to send a TCP RST on close() instead of a FIN. This RST will abort the
@@ -1629,23 +1631,37 @@ func (sc *serverConn) processSettingInitialWindowSize(val uint32) error {
 
 func (sc *serverConn) processData(f *DataFrame) error {
 	sc.serveG.check()
-	if sc.inGoAway && sc.goAwayCode != ErrCodeNo {
+	id := f.Header().StreamID
+	if sc.inGoAway && (sc.goAwayCode != ErrCodeNo || id > sc.maxClientStreamID) {
+		// Discard all DATA frames if the GOAWAY is due to an
+		// error, or:
+		//
+		// Section 6.8: After sending a GOAWAY frame, the sender
+		// can discard frames for streams initiated by the
+		// receiver with identifiers higher than the identified
+		// last stream.
 		return nil
 	}
-	data := f.Data()
 
-	// "If a DATA frame is received whose stream is not in "open"
-	// or "half closed (local)" state, the recipient MUST respond
-	// with a stream error (Section 5.4.2) of type STREAM_CLOSED."
-	id := f.Header().StreamID
+	data := f.Data()
 	state, st := sc.state(id)
 	if id == 0 || state == stateIdle {
+		// Section 6.1: "DATA frames MUST be associated with a
+		// stream. If a DATA frame is received whose stream
+		// identifier field is 0x0, the recipient MUST respond
+		// with a connection error (Section 5.4.1) of type
+		// PROTOCOL_ERROR."
+		//
 		// Section 5.1: "Receiving any frame other than HEADERS
 		// or PRIORITY on a stream in this state MUST be
 		// treated as a connection error (Section 5.4.1) of
 		// type PROTOCOL_ERROR."
 		return ConnectionError(ErrCodeProtocol)
 	}
+
+	// "If a DATA frame is received whose stream is not in "open"
+	// or "half closed (local)" state, the recipient MUST respond
+	// with a stream error (Section 5.4.2) of type STREAM_CLOSED."
 	if st == nil || state != stateOpen || st.gotTrailerHeader || st.resetQueued {
 		// This includes sending a RST_STREAM if the stream is
 		// in stateHalfClosedLocal (which currently means that

http2/server_test.go

@@ -43,14 +43,37 @@ func stderrv() io.Writer {
 	return ioutil.Discard
 }
 
+type safeBuffer struct {
+	b bytes.Buffer
+	m sync.Mutex
+}
+
+func (sb *safeBuffer) Write(d []byte) (int, error) {
+	sb.m.Lock()
+	defer sb.m.Unlock()
+	return sb.b.Write(d)
+}
+
+func (sb *safeBuffer) Bytes() []byte {
+	sb.m.Lock()
+	defer sb.m.Unlock()
+	return sb.b.Bytes()
+}
+
+func (sb *safeBuffer) Len() int {
+	sb.m.Lock()
+	defer sb.m.Unlock()
+	return sb.b.Len()
+}
+
 type serverTester struct {
 	cc             net.Conn // client conn
 	t              testing.TB
 	ts             *httptest.Server
 	fr             *Framer
-	serverLogBuf   bytes.Buffer // logger for httptest.Server
-	logFilter      []string     // substrings to filter out
-	scMu           sync.Mutex   // guards sc
+	serverLogBuf   safeBuffer // logger for httptest.Server
+	logFilter      []string   // substrings to filter out
+	scMu           sync.Mutex // guards sc
 	sc             *serverConn
 	hpackDec       *hpack.Decoder
 	decodedHeaders [][2]string
@@ -4267,3 +4290,44 @@ func TestServerWindowUpdateOnBodyClose(t *testing.T) {
 		t.Error(err)
 	}
 }
+
+func TestNoErrorLoggedOnPostAfterGOAWAY(t *testing.T) {
+	st := newServerTester(t, func(w http.ResponseWriter, r *http.Request) {})
+	defer st.Close()
+
+	st.greet()
+
+	content := "some content"
+	st.writeHeaders(HeadersFrameParam{
+		StreamID: 1,
+		BlockFragment: st.encodeHeader(
+			":method", "POST",
+			"content-length", strconv.Itoa(len(content)),
+		),
+		EndStream:  false,
+		EndHeaders: true,
+	})
+	st.wantHeaders()
+
+	st.sc.startGracefulShutdown()
+	for {
+		f, err := st.readFrame()
+		if err == io.EOF {
+			st.t.Fatal("got a EOF; want *GoAwayFrame")
+		}
+		if err != nil {
+			t.Fatal(err)
+		}
+		if gf, ok := f.(*GoAwayFrame); ok && gf.StreamID == 0 {
+			break
+		}
+	}
+
+	st.writeData(1, true, []byte(content))
+	time.Sleep(200 * time.Millisecond)
+	st.Close()
+
+	if bytes.Contains(st.serverLogBuf.Bytes(), []byte("PROTOCOL_ERROR")) {
+		t.Error("got protocol error")
+	}
+}