http3: qlog the frame length and payload length of parsed frames (#5380)

This commit is contained in:
Marten Seemann
2025-10-12 16:58:32 +08:00
committed by GitHub
parent ce12204bc3
commit b7d987f5e4
12 changed files with 132 additions and 76 deletions

View File

@@ -22,7 +22,7 @@ func TestResponseBodyReading(t *testing.T) {
str.EXPECT().Read(gomock.Any()).DoAndReturn(buf.Read).AnyTimes()
reqDone := make(chan struct{})
rb := newResponseBody(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil),
-1,
reqDone,
)
@@ -39,7 +39,7 @@ func TestResponseBodyReadError(t *testing.T) {
str.EXPECT().Read(gomock.Any()).Return(0, assert.AnError).Times(2)
reqDone := make(chan struct{})
rb := newResponseBody(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil),
-1,
reqDone,
)
@@ -63,7 +63,7 @@ func TestResponseBodyClose(t *testing.T) {
str.EXPECT().CancelRead(quic.StreamErrorCode(ErrCodeRequestCanceled)).Times(2)
reqDone := make(chan struct{})
rb := newResponseBody(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil),
-1,
reqDone,
)
@@ -85,7 +85,7 @@ func TestResponseBodyConcurrentClose(t *testing.T) {
str.EXPECT().CancelRead(quic.StreamErrorCode(ErrCodeRequestCanceled)).MaxTimes(3)
reqDone := make(chan struct{})
rb := newResponseBody(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil),
-1,
reqDone,
)
@@ -126,7 +126,7 @@ func testResponseBodyLengthLimiting(t *testing.T, alongFrameBoundary bool) {
str.EXPECT().CancelWrite(quic.StreamErrorCode(ErrCodeMessageError))
str.EXPECT().Read(gomock.Any()).DoAndReturn(buf.Read).AnyTimes()
rb := newResponseBody(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil),
l,
make(chan struct{}),
)

View File

@@ -24,29 +24,16 @@ func (r *exactReader) Read(b []byte) (int, error) {
return n, err
}
type countingByteReader struct {
io.ByteReader
Read int
}
func (r *countingByteReader) ReadByte() (byte, error) {
b, err := r.ByteReader.ReadByte()
if err == nil {
r.Read++
}
return b, err
}
// ParseCapsule parses the header of a Capsule.
// It returns an io.Reader that can be used to read the Capsule value.
// The Capsule value must be read entirely (i.e. until the io.EOF) before using r again.
func ParseCapsule(r quicvarint.Reader) (CapsuleType, io.Reader, error) {
cbr := countingByteReader{ByteReader: r}
cbr := countingByteReader{Reader: r}
ct, err := quicvarint.Read(&cbr)
if err != nil {
// If an io.EOF is returned without consuming any bytes, return it unmodified.
// Otherwise, return an io.ErrUnexpectedEOF.
if err == io.EOF && cbr.Read > 0 {
if err == io.EOF && cbr.NumRead > 0 {
return 0, nil, io.ErrUnexpectedEOF
}
return 0, nil, err

View File

@@ -81,7 +81,7 @@ func encodeResponse(t *testing.T, status int) []byte {
rstr := NewMockDatagramStream(mockCtrl)
rstr.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
rstr.EXPECT().Write(gomock.Any()).Do(buf.Write).AnyTimes()
rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw := newResponseWriter(newStream(rstr, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil), nil, false, nil)
rw.WriteHeader(status)
rw.Flush()
return buf.Bytes()
@@ -347,7 +347,7 @@ func testClient1xxHandling(t *testing.T, numEarlyHints int, terminalStatus int,
rstr := NewMockDatagramStream(gomock.NewController(t))
rstr.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
rstr.EXPECT().Write(gomock.Any()).Do(rspBuf.Write).AnyTimes()
rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw := newResponseWriter(newStream(rstr, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil), nil, false, nil)
rw.header.Add("Link", "foo")
rw.header.Add("Link", "bar")
for range numEarlyHints {
@@ -427,7 +427,7 @@ func testClientGzip(t *testing.T,
rstr := NewMockDatagramStream(gomock.NewController(t))
rstr.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
rstr.EXPECT().Write(gomock.Any()).Do(rspBuf.Write).AnyTimes()
rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw := newResponseWriter(newStream(rstr, nil, nil, func(io.Reader, *headersFrame) error { return nil }, nil), nil, false, nil)
rw.WriteHeader(http.StatusOK)
if responseAddContentEncoding {
rw.header.Add("Content-Encoding", "gzip")

View File

@@ -176,8 +176,8 @@ func (c *Conn) openRequestStream(
rsp := &http.Response{}
trace := httptrace.ContextClientTrace(ctx)
return newRequestStream(
newStream(hstr, c, trace, func(r io.Reader, l uint64) error {
hdr, err := c.decodeTrailers(r, str.StreamID(), l, maxHeaderBytes)
newStream(hstr, c, trace, func(r io.Reader, hf *headersFrame) error {
hdr, err := c.decodeTrailers(r, str.StreamID(), hf, maxHeaderBytes)
if err != nil {
return err
}
@@ -193,23 +193,23 @@ func (c *Conn) openRequestStream(
), nil
}
func (c *Conn) decodeTrailers(r io.Reader, streamID quic.StreamID, l, maxHeaderBytes uint64) (http.Header, error) {
if l > maxHeaderBytes {
maybeQlogInvalidHeadersFrame(c.qlogger, streamID, l)
return nil, fmt.Errorf("HEADERS frame too large: %d bytes (max: %d)", l, maxHeaderBytes)
func (c *Conn) decodeTrailers(r io.Reader, streamID quic.StreamID, hf *headersFrame, maxHeaderBytes uint64) (http.Header, error) {
if hf.Length > maxHeaderBytes {
maybeQlogInvalidHeadersFrame(c.qlogger, streamID, hf.Length)
return nil, fmt.Errorf("HEADERS frame too large: %d bytes (max: %d)", hf.Length, maxHeaderBytes)
}
b := make([]byte, l)
b := make([]byte, hf.Length)
if _, err := io.ReadFull(r, b); err != nil {
return nil, err
}
fields, err := c.decoder.DecodeFull(b)
if err != nil {
maybeQlogInvalidHeadersFrame(c.qlogger, streamID, l)
maybeQlogInvalidHeadersFrame(c.qlogger, streamID, hf.Length)
return nil, err
}
if c.qlogger != nil {
qlogParsedHeadersFrame(c.qlogger, streamID, l, fields)
qlogParsedHeadersFrame(c.qlogger, streamID, hf, fields)
}
return parseTrailers(fields)
}

View File

@@ -29,11 +29,12 @@ func TestConnReceiveSettings(t *testing.T) {
0,
)
b := quicvarint.Append(nil, streamTypeControlStream)
b = (&settingsFrame{
sf := &settingsFrame{
Datagram: true,
ExtendedConnect: true,
Other: map[uint64]uint64{1337: 42},
}).Append(b)
}
b = sf.Append(b)
controlStr, err := clientConn.OpenUniStream()
require.NoError(t, err)
_, err = controlStr.Write(b)
@@ -54,11 +55,12 @@ func TestConnReceiveSettings(t *testing.T) {
require.True(t, settings.EnableExtendedConnect)
require.Equal(t, map[uint64]uint64{1337: 42}, settings.Other)
expectedLen, expectedPayloadLen := expectedFrameLength(t, sf)
require.Equal(t,
[]qlogwriter.Event{
qlog.FrameParsed{
StreamID: controlStr.StreamID(),
Raw: qlog.RawInfo{PayloadLength: len(b) - 3}, // type and length
Raw: qlog.RawInfo{Length: expectedLen, PayloadLength: expectedPayloadLen},
Frame: qlog.Frame{Frame: qlog.SettingsFrame{Datagram: pointer(true), ExtendedConnect: pointer(true), Other: map[uint64]uint64{1337: 42}}},
},
},
@@ -335,10 +337,12 @@ func testConnGoAway(t *testing.T, withStream bool) {
t.Fatal("timeout waiting for close")
}
expectedLen, expectedPayloadLen := expectedFrameLength(t, &goAwayFrame{StreamID: 8})
require.Equal(t,
[]qlogwriter.Event{
qlog.FrameParsed{
StreamID: 3,
Raw: qlog.RawInfo{PayloadLength: expectedPayloadLen, Length: expectedLen},
Frame: qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: 8}},
},
},

View File

@@ -22,6 +22,29 @@ type frame any
var errHijacked = errors.New("hijacked")
type countingByteReader struct {
quicvarint.Reader
NumRead int
}
func (r *countingByteReader) ReadByte() (byte, error) {
b, err := r.Reader.ReadByte()
if err == nil {
r.NumRead++
}
return b, err
}
func (r *countingByteReader) Read(b []byte) (int, error) {
n, err := r.Reader.Read(b)
r.NumRead += n
return n, err
}
func (r *countingByteReader) Reset() {
r.NumRead = 0
}
type frameParser struct {
r io.Reader
streamID quic.StreamID
@@ -30,9 +53,9 @@ type frameParser struct {
}
func (p *frameParser) ParseNext(qlogger qlogwriter.Recorder) (frame, error) {
qr := quicvarint.NewReader(p.r)
r := &countingByteReader{Reader: quicvarint.NewReader(p.r)}
for {
t, err := quicvarint.Read(qr)
t, err := quicvarint.Read(r)
if err != nil {
if p.unknownFrameHandler != nil {
hijacked, err := p.unknownFrameHandler(0, err)
@@ -56,36 +79,46 @@ func (p *frameParser) ParseNext(qlogger qlogwriter.Recorder) (frame, error) {
}
// If the unknownFrameHandler didn't process the frame, it is our responsibility to skip it.
}
l, err := quicvarint.Read(qr)
l, err := quicvarint.Read(r)
if err != nil {
return nil, err
}
switch t {
case 0x0:
case 0x0: // DATA
if qlogger != nil {
qlogger.RecordEvent(qlog.FrameParsed{
StreamID: p.streamID,
Raw: qlog.RawInfo{PayloadLength: int(l)},
Frame: qlog.Frame{Frame: qlog.DataFrame{}},
Raw: qlog.RawInfo{
Length: int(l) + r.NumRead,
PayloadLength: int(l),
},
Frame: qlog.Frame{Frame: qlog.DataFrame{}},
})
}
return &dataFrame{Length: l}, nil
case 0x1:
return &headersFrame{Length: l}, nil
case 0x4:
return parseSettingsFrame(p.r, l, p.streamID, qlogger)
case 0x1: // HEADERS
return &headersFrame{
Length: l,
headerLen: r.NumRead,
}, nil
case 0x4: // SETTINGS
return parseSettingsFrame(r, l, p.streamID, qlogger)
case 0x3: // CANCEL_PUSH
case 0x5: // PUSH_PROMISE
case 0x7:
f, err := parseGoAwayFrame(qr, l)
case 0x7: // GOAWAY
f, err := parseGoAwayFrame(r, l)
if err != nil {
return nil, err
}
if qlogger != nil {
qlogger.RecordEvent(qlog.FrameParsed{
StreamID: p.streamID,
Frame: qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: f.StreamID}},
Raw: qlog.RawInfo{
Length: r.NumRead,
PayloadLength: int(l),
},
Frame: qlog.Frame{Frame: qlog.GoAwayFrame{StreamID: f.StreamID}},
})
}
return f, nil
@@ -95,9 +128,10 @@ func (p *frameParser) ParseNext(qlogger qlogwriter.Recorder) (frame, error) {
return nil, fmt.Errorf("http3: reserved frame type: %d", t)
}
// skip over unknown frames
if _, err := io.CopyN(io.Discard, qr, int64(l)); err != nil {
if _, err := io.CopyN(io.Discard, r, int64(l)); err != nil {
return nil, err
}
r.Reset()
}
}
@@ -111,7 +145,8 @@ func (f *dataFrame) Append(b []byte) []byte {
}
type headersFrame struct {
Length uint64
Length uint64
headerLen int // number of bytes read for type and length field
}
func (f *headersFrame) Append(b []byte) []byte {
@@ -137,7 +172,7 @@ func pointer[T any](v T) *T {
return &v
}
func parseSettingsFrame(r io.Reader, l uint64, streamID quic.StreamID, qlogger qlogwriter.Recorder) (*settingsFrame, error) {
func parseSettingsFrame(r *countingByteReader, l uint64, streamID quic.StreamID, qlogger qlogwriter.Recorder) (*settingsFrame, error) {
if l > 8*(1<<10) {
return nil, fmt.Errorf("unexpected size for SETTINGS frame: %d", l)
}
@@ -202,8 +237,11 @@ func parseSettingsFrame(r io.Reader, l uint64, streamID quic.StreamID, qlogger q
qlogger.RecordEvent(qlog.FrameParsed{
StreamID: streamID,
Raw: qlog.RawInfo{PayloadLength: len(buf)},
Frame: qlog.Frame{Frame: settingsFrame},
Raw: qlog.RawInfo{
Length: r.NumRead,
PayloadLength: int(l),
},
Frame: qlog.Frame{Frame: settingsFrame},
})
}
return frame, nil
@@ -241,14 +279,14 @@ type goAwayFrame struct {
StreamID quic.StreamID
}
func parseGoAwayFrame(r io.ByteReader, l uint64) (*goAwayFrame, error) {
func parseGoAwayFrame(r *countingByteReader, l uint64) (*goAwayFrame, error) {
frame := &goAwayFrame{}
cbr := countingByteReader{ByteReader: r}
id, err := quicvarint.Read(&cbr)
startLen := r.NumRead
id, err := quicvarint.Read(r)
if err != nil {
return nil, err
}
if cbr.Read != int(l) {
if r.NumRead-startLen != int(l) {
return nil, errors.New("GOAWAY frame: inconsistent length")
}
frame.StreamID = quic.StreamID(id)

View File

@@ -24,6 +24,7 @@ import (
"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"
"github.com/stretchr/testify/require"
)
@@ -328,3 +329,27 @@ func filterQlogEventsForFrame(events []qlogwriter.Event, frame any) []qlogwriter
}
return filtered
}
func expectedFrameLength(t *testing.T, frame any) (length, payloadLength int) {
t.Helper()
switch f := frame.(type) {
case *dataFrame:
return len(f.Append(nil)) + int(f.Length), int(f.Length)
case *headersFrame:
return len(f.Append(nil)) + int(f.Length), int(f.Length)
case *goAwayFrame:
return len(f.Append(nil)), quicvarint.Len(uint64(f.StreamID))
case *settingsFrame:
data := f.Append(nil)
r := bytes.NewReader(data)
_, err := quicvarint.Read(r) // type
require.NoError(t, err)
_, err = quicvarint.Read(r) // length
require.NoError(t, err)
return len(data), r.Len()
default:
t.Fatalf("unexpected frame type: %T", frame)
}
panic("unreachable")
}

View File

@@ -18,7 +18,7 @@ func maybeQlogInvalidHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.Str
}
}
func qlogParsedHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID, l uint64, hfs []qpack.HeaderField) {
func qlogParsedHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID, hf *headersFrame, hfs []qpack.HeaderField) {
headerFields := make([]qlog.HeaderField, len(hfs))
for i, hf := range hfs {
headerFields[i] = qlog.HeaderField{
@@ -28,7 +28,10 @@ func qlogParsedHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID,
}
qlogger.RecordEvent(qlog.FrameParsed{
StreamID: streamID,
Raw: qlog.RawInfo{PayloadLength: int(l)},
Raw: qlog.RawInfo{
Length: int(hf.Length) + hf.headerLen,
PayloadLength: int(hf.Length),
},
Frame: qlog.Frame{Frame: qlog.HeadersFrame{
HeaderFields: headerFields,
}},

View File

@@ -87,7 +87,7 @@ func newTestResponseWriter(t *testing.T) *testResponseWriter {
str.EXPECT().SetReadDeadline(gomock.Any()).Return(nil).AnyTimes()
str.EXPECT().SetWriteDeadline(gomock.Any()).Return(nil).AnyTimes()
rw := newResponseWriter(
newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, &eventRecorder),
newStream(str, nil, nil, func(io.Reader, *headersFrame) error { return nil }, &eventRecorder),
nil,
false,
nil,

View File

@@ -628,7 +628,7 @@ func (s *Server) handleRequest(
return
}
if qlogger != nil {
qlogParsedHeadersFrame(qlogger, str.StreamID(), hf.Length, hfs)
qlogParsedHeadersFrame(qlogger, str.StreamID(), hf, hfs)
}
req, err := requestFromHeaders(hfs)
if err != nil {

View File

@@ -45,7 +45,7 @@ type Stream struct {
qlogger qlogwriter.Recorder
parseTrailer func(io.Reader, uint64) error
parseTrailer func(io.Reader, *headersFrame) error
parsedTrailer bool
}
@@ -53,7 +53,7 @@ func newStream(
str datagramStream,
conn *Conn,
trace *httptrace.ClientTrace,
parseTrailer func(io.Reader, uint64) error,
parseTrailer func(io.Reader, *headersFrame) error,
qlogger qlogwriter.Recorder,
) *Stream {
return &Stream{
@@ -94,7 +94,7 @@ func (s *Stream) Read(b []byte) (int, error) {
return 0, errors.New("additional HEADERS frame received after trailers")
}
s.parsedTrailer = true
return 0, s.parseTrailer(s.datagramStream, f.Length)
return 0, s.parseTrailer(s.datagramStream, f)
default:
s.conn.CloseWithError(quic.ApplicationErrorCode(ErrCodeFrameUnexpected), "")
// parseNextFrame skips over unknown frame types
@@ -350,7 +350,7 @@ func (s *RequestStream) ReadResponse() (*http.Response, error) {
return nil, fmt.Errorf("http3: failed to decode response headers: %w", err)
}
if s.str.qlogger != nil {
qlogParsedHeadersFrame(s.str.qlogger, s.str.StreamID(), hf.Length, hfs)
qlogParsedHeadersFrame(s.str.qlogger, s.str.StreamID(), hf, hfs)
}
res := s.response
if err := updateResponseFromHeaders(res, hfs); err != nil {

View File

@@ -49,7 +49,7 @@ func TestStreamReadDataFrames(t *testing.T) {
0,
),
nil,
func(r io.Reader, u uint64) error { return nil },
func(io.Reader, *headersFrame) error { return nil },
&eventRecorder,
)
@@ -64,11 +64,12 @@ func TestStreamReadDataFrames(t *testing.T) {
require.Equal(t, 3, n)
require.Equal(t, []byte("bar"), b)
expectedLen, _ := expectedFrameLength(t, &dataFrame{Length: 6})
require.Equal(t,
[]qlogwriter.Event{
qlog.FrameParsed{
StreamID: 42,
Raw: qlog.RawInfo{PayloadLength: 6},
Raw: qlog.RawInfo{Length: expectedLen, PayloadLength: 6},
Frame: qlog.Frame{Frame: qlog.DataFrame{}},
},
},
@@ -117,7 +118,7 @@ func TestStreamInvalidFrame(t *testing.T) {
qstr,
newConnection(context.Background(), clientConn, false, false, nil, 0),
nil,
func(r io.Reader, u uint64) error { return nil },
func(io.Reader, *headersFrame) error { return nil },
nil,
)
@@ -141,26 +142,24 @@ func TestStreamWrite(t *testing.T) {
qstr.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
qstr.EXPECT().Write(gomock.Any()).DoAndReturn(buf.Write).AnyTimes()
var eventRecorder events.Recorder
str := newStream(qstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, &eventRecorder)
str := newStream(qstr, nil, nil, func(io.Reader, *headersFrame) error { return nil }, &eventRecorder)
str.Write([]byte("foo"))
str.Write([]byte("foobar"))
startLen := buf.Len()
fp := frameParser{r: &buf}
f, err := fp.ParseNext(nil)
require.NoError(t, err)
f1Len := startLen - buf.Len()
f1Len, f1PayloadLen := expectedFrameLength(t, &dataFrame{Length: 3})
require.Equal(t, &dataFrame{Length: 3}, f)
b := make([]byte, 3)
_, err = io.ReadFull(&buf, b)
require.NoError(t, err)
require.Equal(t, []byte("foo"), b)
startLen = buf.Len()
fp = frameParser{r: &buf}
f, err = fp.ParseNext(nil)
require.NoError(t, err)
f2Len := startLen - buf.Len()
f2Len, f2PayloadLen := expectedFrameLength(t, &dataFrame{Length: 6})
require.Equal(t, &dataFrame{Length: 6}, f)
b = make([]byte, 6)
_, err = io.ReadFull(&buf, b)
@@ -171,12 +170,12 @@ func TestStreamWrite(t *testing.T) {
[]qlogwriter.Event{
qlog.FrameCreated{
StreamID: 42,
Raw: qlog.RawInfo{Length: f1Len + 3, PayloadLength: 3},
Raw: qlog.RawInfo{Length: f1Len, PayloadLength: f1PayloadLen},
Frame: qlog.Frame{Frame: qlog.DataFrame{}},
},
qlog.FrameCreated{
StreamID: 42,
Raw: qlog.RawInfo{Length: f2Len + 6, PayloadLength: 6},
Raw: qlog.RawInfo{Length: f2Len, PayloadLength: f2PayloadLen},
Frame: qlog.Frame{Frame: qlog.DataFrame{}},
},
},
@@ -195,7 +194,7 @@ func TestRequestStream(t *testing.T) {
qstr,
newConnection(context.Background(), clientConn, false, false, nil, 0),
&httptrace.ClientTrace{},
func(r io.Reader, u uint64) error { return nil },
func(io.Reader, *headersFrame) error { return nil },
nil,
),
requestWriter,