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

diff --git a/http3/conn.go b/http3/conn.go
index 4ca9a38593120a6fe59db937dc1c6aeee6e3fe71..037ea8157e8918d00e3c46789f3b04de4aab063a 100644 (file)
--- a/http3/conn.go
+++ b/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

diff --git a/http3/conn_test.go b/http3/conn_test.go
index d781eefd4778b48e1b32a5055462c358981b84ea..6d49adc59fd2967038320bb3c8879f5e1ff9d4af 100644 (file)
--- a/http3/conn_test.go
+++ b/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) {

diff --git a/http3/qlog/event.go b/http3/qlog/event.go
index 7fe1051cb7432efa7ed75aa06c7d9adc4b10379c..f311d813f0392553496784376d15f7fbd0e8da75 100644 (file)
--- a/http3/qlog/event.go
+++ b/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 {

diff --git a/http3/qlog/frame.go b/http3/qlog/frame.go
index a3a1fb5e302c817239090730ccdecaed4223a9de..92c6992c57e1c61ce0af2c881c403570feb36928 100644 (file)
--- a/http3/qlog/frame.go
+++ b/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
+}

diff --git a/http3/qlog/frame_test.go b/http3/qlog/frame_test.go
index a3c9e6e92fb733b3cd7b04cf73ed7601dc6e927f..2901a3679ab1ceb23b867db201f97fdc03daffc2 100644 (file)
--- a/http3/qlog/frame_test.go
+++ b/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,
+       })
+}

diff --git a/http3/server.go b/http3/server.go
index 60fccc8459e3ec719f291b22c0a82c535babeb3f..467e5626b88977f1151698c40945e80d9e123b6c 100644 (file)
--- a/http3/server.go
+++ b/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.