http3: qlog sent and received GOAWAY frames (#5376)

http3/conn.go

@@ -14,6 +14,7 @@ import (
 	"time"
 
 	"github.com/quic-go/quic-go"
+	"github.com/quic-go/quic-go/http3/qlog"
 	"github.com/quic-go/quic-go/qlogwriter"
 	"github.com/quic-go/quic-go/quicvarint"
 
@@ -379,6 +380,12 @@ func (c *Conn) handleControlStream(str *quic.ReceiveStream) {
 			c.conn.CloseWithError(quic.ApplicationErrorCode(ErrCodeFrameUnexpected), "")
 			return
 		}
+		if c.qlogger != nil {
+			c.qlogger.RecordEvent(qlog.FrameParsed{
+				StreamID: str.StreamID(),
+				Frame:    qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: goaway.StreamID}},
+			})
+		}
 		if goaway.StreamID%4 != 0 { // client-initiated, bidirectional streams
 			c.conn.CloseWithError(quic.ApplicationErrorCode(ErrCodeIDError), "")
 			return

http3/conn_test.go

@@ -8,7 +8,9 @@ import (
 	"time"
 
 	"github.com/quic-go/quic-go"
+	"github.com/quic-go/quic-go/http3/qlog"
 	"github.com/quic-go/quic-go/quicvarint"
+	"github.com/quic-go/quic-go/testutils/events"
 
 	"github.com/stretchr/testify/require"
 )
@@ -161,15 +163,18 @@ func TestConnGoAwayFailures(t *testing.T) {
 		b = (&settingsFrame{Other: map[uint64]uint64{settingExtendedConnect: 1337}}).Append(b)
 		testConnControlStreamFailures(t, b, nil, ErrCodeFrameError)
 	})
+
 	t.Run("not a GOAWAY", func(t *testing.T) {
 		b := (&settingsFrame{}).Append(nil)
 		// GOAWAY is the only allowed frame type after SETTINGS
 		b = (&headersFrame{}).Append(b)
 		testConnControlStreamFailures(t, b, nil, ErrCodeFrameUnexpected)
 	})
+
 	t.Run("stream closed before GOAWAY", func(t *testing.T) {
 		testConnControlStreamFailures(t, (&settingsFrame{}).Append(nil), io.EOF, ErrCodeClosedCriticalStream)
 	})
+
 	t.Run("stream reset before GOAWAY", func(t *testing.T) {
 		testConnControlStreamFailures(t,
 			(&settingsFrame{}).Append(nil),
@@ -177,11 +182,13 @@ func TestConnGoAwayFailures(t *testing.T) {
 			ErrCodeClosedCriticalStream,
 		)
 	})
+
 	t.Run("invalid stream ID", func(t *testing.T) {
 		data := (&settingsFrame{}).Append(nil)
 		data = (&goAwayFrame{StreamID: 1}).Append(data)
 		testConnControlStreamFailures(t, data, nil, ErrCodeIDError)
 	})
+
 	t.Run("increased stream ID", func(t *testing.T) {
 		data := (&settingsFrame{}).Append(nil)
 		data = (&goAwayFrame{StreamID: 4}).Append(data)
@@ -254,7 +261,8 @@ func TestConnGoAway(t *testing.T) {
 }
 
 func testConnGoAway(t *testing.T, withStream bool) {
-	clientConn, serverConn := newConnPair(t)
+	var clientEventRecorder events.Recorder
+	clientConn, serverConn := newConnPairWithRecorder(t, &clientEventRecorder, nil)
 
 	conn := newConnection(
 		clientConn.Context(),
@@ -313,6 +321,21 @@ func testConnGoAway(t *testing.T, withStream bool) {
 	case <-time.After(time.Second):
 		t.Fatal("timeout waiting for close")
 	}
+
+	framesParsed := clientEventRecorder.Events(qlog.FrameParsed{})
+	var goawayFramesParsed []qlog.FrameParsed
+	for _, ev := range framesParsed {
+		if _, ok := ev.(qlog.FrameParsed).Frame.Frame.(qlog.GoAwayFrame); ok {
+			goawayFramesParsed = append(goawayFramesParsed, ev.(qlog.FrameParsed))
+		}
+	}
+	require.Equal(t,
+		[]qlog.FrameParsed{{
+			StreamID: 3,
+			Frame:    qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: 8}},
+		}},
+		goawayFramesParsed,
+	)
 }
 
 func TestConnRejectPushStream(t *testing.T) {

http3/qlog/event.go

@@ -24,6 +24,10 @@ type RawInfo struct {
 	PayloadLength int // length of the packet payload, excluding AEAD tag
 }
 
+func (i RawInfo) HasValues() bool {
+	return i.Length != 0 || i.PayloadLength != 0
+}
+
 func (i RawInfo) encode(enc *jsontext.Encoder) error {
 	h := encoderHelper{enc: enc}
 	h.WriteToken(jsontext.BeginObject)
@@ -52,9 +56,11 @@ func (e FrameParsed) Encode(enc *jsontext.Encoder, _ time.Time) error {
 	h.WriteToken(jsontext.BeginObject)
 	h.WriteToken(jsontext.String("stream_id"))
 	h.WriteToken(jsontext.Uint(uint64(e.StreamID)))
-	h.WriteToken(jsontext.String("raw"))
-	if err := e.Raw.encode(enc); err != nil {
-		return err
+	if e.Raw.HasValues() {
+		h.WriteToken(jsontext.String("raw"))
+		if err := e.Raw.encode(enc); err != nil {
+			return err
+		}
 	}
 	h.WriteToken(jsontext.String("frame"))
 	if err := e.Frame.encode(enc); err != nil {
@@ -77,9 +83,11 @@ func (e FrameCreated) Encode(enc *jsontext.Encoder, _ time.Time) error {
 	h.WriteToken(jsontext.BeginObject)
 	h.WriteToken(jsontext.String("stream_id"))
 	h.WriteToken(jsontext.Uint(uint64(e.StreamID)))
-	h.WriteToken(jsontext.String("raw"))
-	if err := e.Raw.encode(enc); err != nil {
-		return err
+	if e.Raw.HasValues() {
+		h.WriteToken(jsontext.String("raw"))
+		if err := e.Raw.encode(enc); err != nil {
+			return err
+		}
 	}
 	h.WriteToken(jsontext.String("frame"))
 	if err := e.Frame.encode(enc); err != nil {

http3/qlog/frame.go

@@ -1,6 +1,7 @@
 package qlog
 
 import (
+	"github.com/quic-go/quic-go"
 	"github.com/quic-go/quic-go/qlogwriter/jsontext"
 )
 
@@ -15,6 +16,8 @@ func (f Frame) encode(enc *jsontext.Encoder) error {
 		return frame.encode(enc)
 	case HeadersFrame:
 		return frame.encode(enc)
+	case GoAwayFrame:
+		return frame.encode(enc)
 	}
 	// This shouldn't happen if the code is correctly logging frames.
 	// Write a null token to produce valid JSON.
@@ -64,3 +67,19 @@ func (f *HeadersFrame) encode(enc *jsontext.Encoder) error {
 	h.WriteToken(jsontext.EndObject)
 	return h.err
 }
+
+// A GoAwayFrame is a GOAWAY frame
+type GoAwayFrame struct {
+	StreamID quic.StreamID
+}
+
+func (f *GoAwayFrame) encode(enc *jsontext.Encoder) error {
+	h := encoderHelper{enc: enc}
+	h.WriteToken(jsontext.BeginObject)
+	h.WriteToken(jsontext.String("frame_type"))
+	h.WriteToken(jsontext.String("goaway"))
+	h.WriteToken(jsontext.String("id"))
+	h.WriteToken(jsontext.Uint(uint64(f.StreamID)))
+	h.WriteToken(jsontext.EndObject)
+	return h.err
+}

http3/qlog/frame_test.go

@@ -70,3 +70,10 @@ func TestHeadersFrame(t *testing.T) {
 		},
 	})
 }
+
+func TestGoAwayFrame(t *testing.T) {
+	check(t, GoAwayFrame{StreamID: 1337}, map[string]any{
+		"frame_type": "goaway",
+		"id":         1337,
+	})
+}

http3/server.go

@@ -18,6 +18,7 @@ import (
 	"time"
 
 	"github.com/quic-go/quic-go"
+	"github.com/quic-go/quic-go/http3/qlog"
 	"github.com/quic-go/quic-go/qlogwriter"
 	"github.com/quic-go/quic-go/quicvarint"
 
@@ -518,6 +519,12 @@ func (s *Server) handleConn(conn *quic.Conn) error {
 
 			// gracefully closed, send GOAWAY frame and wait for requests to complete or grace period to end
 			// new requests will be rejected and shouldn't be sent
+			if qlogger != nil {
+				qlogger.RecordEvent(qlog.FrameCreated{
+					StreamID: ctrlStr.StreamID(),
+					Frame:    qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: nextStreamID}},
+				})
+			}
 			wg.Add(1)
 			// Send the GOAWAY frame in a separate Goroutine.
 			// Sending might block if the peer didn't grant enough flow control credit.