deny:
- pkg: 'github.com/quic-go/quic-go/internal'
desc: 'no dependency on quic-go/internal'
+ allow:
+ - 'github.com/quic-go/quic-go/internal/synctest'
misspell:
ignore-rules:
- ect
connStateMutex sync.Mutex
connState ConnectionState
- logID string
- qlogger qlogwriter.Recorder
- logger utils.Logger
+ logID string
+ qlogTrace qlogwriter.Trace
+ qlogger qlogwriter.Recorder
+ logger utils.Logger
}
var _ streamSender = &Conn{}
tokenGenerator *handshake.TokenGenerator,
clientAddressValidated bool,
rtt time.Duration,
- qlogger qlogwriter.Recorder,
+ qlogTrace qlogwriter.Trace,
logger utils.Logger,
v protocol.Version,
) *wrappedConn {
tokenGenerator: tokenGenerator,
oneRTTStream: newCryptoStream(),
perspective: protocol.PerspectiveServer,
- qlogger: qlogger,
+ qlogTrace: qlogTrace,
logger: logger,
version: v,
}
+ if qlogTrace != nil {
+ s.qlogger = qlogTrace.AddProducer()
+ }
if origDestConnID.Len() > 0 {
s.logID = origDestConnID.String()
} else {
tlsConf,
conf.Allow0RTT,
s.rttStats,
- qlogger,
+ s.qlogger,
logger,
s.version,
)
initialPacketNumber protocol.PacketNumber,
enable0RTT bool,
hasNegotiatedVersion bool,
- qlogger qlogwriter.Recorder,
+ qlogTrace qlogwriter.Trace,
logger utils.Logger,
v protocol.Version,
) *wrappedConn {
perspective: protocol.PerspectiveClient,
logID: destConnID.String(),
logger: logger,
- qlogger: qlogger,
+ qlogTrace: qlogTrace,
versionNegotiated: hasNegotiatedVersion,
version: v,
}
+ if qlogTrace != nil {
+ s.qlogger = qlogTrace.AddProducer()
+ }
+ if s.qlogger != nil {
+ var srcAddr, destAddr *net.UDPAddr
+ if addr, ok := conn.LocalAddr().(*net.UDPAddr); ok {
+ srcAddr = addr
+ }
+ if addr, ok := conn.RemoteAddr().(*net.UDPAddr); ok {
+ destAddr = addr
+ }
+ s.qlogger.RecordEvent(qlog.StartedConnection{
+ SrcAddr: srcAddr,
+ DestAddr: destAddr,
+ SrcConnectionID: srcConnID,
+ DestConnectionID: destConnID,
+ })
+ }
s.connIDManager = newConnIDManager(
destConnID,
func(token protocol.StatelessResetToken) { runner.AddResetToken(token, s) },
tlsConf,
enable0RTT,
s.rttStats,
- qlogger,
+ s.qlogger,
logger,
s.version,
)
return c.handshakeCompleteChan
}
+// QlogTrace returns the qlog trace of the QUIC connection.
+// It is nil if qlog is not enabled.
+func (c *Conn) QlogTrace() qlogwriter.Trace {
+ return c.qlogTrace
+}
+
func (c *Conn) NextConnection(ctx context.Context) (*Conn, error) {
// The handshake might fail after the server rejected 0-RTT.
// This could happen if the Finished message is malformed or never received.
buf := &bytes.Buffer{}
rstr := NewMockDatagramStream(mockCtrl)
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, false, nil)
+ rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw.WriteHeader(status)
rw.Flush()
return buf.Bytes()
var rspBuf bytes.Buffer
rstr := NewMockDatagramStream(gomock.NewController(t))
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, false, nil)
+ rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw.header.Add("Link", "foo")
rw.header.Add("Link", "bar")
for range numEarlyHints {
var rspBuf bytes.Buffer
rstr := NewMockDatagramStream(gomock.NewController(t))
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, false, nil)
+ rw := newResponseWriter(newStream(rstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, nil), nil, false, nil)
rw.WriteHeader(http.StatusOK)
if responseAddContentEncoding {
rw.header.Add("Content-Encoding", "gzip")
"time"
"github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/qlogwriter"
"github.com/quic-go/quic-go/quicvarint"
"github.com/quic-go/qpack"
idleTimeout time.Duration
idleTimer *time.Timer
+
+ qlogger qlogwriter.Recorder
}
func newConnection(
logger *slog.Logger,
idleTimeout time.Duration,
) *Conn {
+ var qlogger qlogwriter.Recorder
+ if qlogTrace := quicConn.QlogTrace(); qlogTrace != nil {
+ qlogger = qlogTrace.AddProducer()
+ }
c := &Conn{
ctx: ctx,
conn: quicConn,
streams: make(map[quic.StreamID]*stateTrackingStream),
maxStreamID: invalidStreamID,
lastStreamID: invalidStreamID,
+ qlogger: qlogger,
}
if idleTimeout > 0 {
c.idleTimer = time.AfterFunc(idleTimeout, c.onIdleTimer)
trace := httptrace.ContextClientTrace(ctx)
return newRequestStream(
newStream(hstr, c, trace, func(r io.Reader, l uint64) error {
- hdr, err := c.decodeTrailers(r, l, maxHeaderBytes)
+ hdr, err := c.decodeTrailers(r, str.StreamID(), l, maxHeaderBytes)
if err != nil {
return err
}
rsp.Trailer = hdr
return nil
- }),
+ }, c.qlogger),
requestWriter,
reqDone,
c.decoder,
), nil
}
-func (c *Conn) decodeTrailers(r io.Reader, l, maxHeaderBytes uint64) (http.Header, error) {
+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)
}
}
fields, err := c.decoder.DecodeFull(b)
if err != nil {
+ maybeQlogInvalidHeadersFrame(c.qlogger, streamID, l)
return nil, err
}
+ if c.qlogger != nil {
+ qlogParsedHeadersFrame(c.qlogger, streamID, l, fields)
+ }
return parseTrailers(fields)
}
"github.com/quic-go/qpack"
"github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/qlogwriter"
"github.com/stretchr/testify/require"
)
func newConnPair(t *testing.T) (client, server *quic.Conn) {
t.Helper()
+ return newConnPairWithRecorder(t, nil, nil)
+}
+
+type qlogTrace struct {
+ recorder qlogwriter.Recorder
+}
+
+func (t *qlogTrace) AddProducer() qlogwriter.Recorder {
+ return t.recorder
+}
+
+func newConnPairWithRecorder(t *testing.T, clientRecorder, serverRecorder qlogwriter.Recorder) (client, server *quic.Conn) {
+ t.Helper()
+
ln, err := quic.ListenEarly(
newUDPConnLocalhost(t),
getTLSConfig(),
&quic.Config{
InitialStreamReceiveWindow: maxByteCount,
InitialConnectionReceiveWindow: maxByteCount,
+ Tracer: func(ctx context.Context, isClient bool, connID quic.ConnectionID) qlogwriter.Trace {
+ return &qlogTrace{recorder: serverRecorder}
+ },
},
)
require.NoError(t, err)
ctx, cancel := context.WithTimeout(context.Background(), time.Second)
defer cancel()
- cl, err := quic.DialEarly(ctx, newUDPConnLocalhost(t), ln.Addr(), getTLSClientConfig(), &quic.Config{})
+ cl, err := quic.DialEarly(
+ ctx,
+ newUDPConnLocalhost(t),
+ ln.Addr(),
+ getTLSClientConfig(),
+ &quic.Config{
+ Tracer: func(ctx context.Context, isClient bool, connID quic.ConnectionID) qlogwriter.Trace {
+ return &qlogTrace{recorder: clientRecorder}
+ },
+ },
+ )
require.NoError(t, err)
t.Cleanup(func() { cl.CloseWithError(0, "") })
--- /dev/null
+package http3
+
+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/qpack"
+)
+
+func maybeQlogInvalidHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID, l uint64) {
+ if qlogger != nil {
+ qlogger.RecordEvent(qlog.FrameParsed{
+ StreamID: streamID,
+ Raw: qlog.RawInfo{PayloadLength: int(l)},
+ Frame: qlog.Frame{Frame: qlog.HeadersFrame{}},
+ })
+ }
+}
+
+func qlogParsedHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID, l uint64, hfs []qpack.HeaderField) {
+ headerFields := make([]qlog.HeaderField, len(hfs))
+ for i, hf := range hfs {
+ headerFields[i] = qlog.HeaderField{
+ Name: hf.Name,
+ Value: hf.Value,
+ }
+ }
+ qlogger.RecordEvent(qlog.FrameParsed{
+ StreamID: streamID,
+ Raw: qlog.RawInfo{PayloadLength: int(l)},
+ Frame: qlog.Frame{Frame: qlog.HeadersFrame{
+ HeaderFields: headerFields,
+ }},
+ })
+}
+
+func qlogCreatedHeadersFrame(qlogger qlogwriter.Recorder, streamID quic.StreamID, length, payloadLength int, hfs []qlog.HeaderField) {
+ headerFields := make([]qlog.HeaderField, len(hfs))
+ for i, hf := range hfs {
+ headerFields[i] = qlog.HeaderField{
+ Name: hf.Name,
+ Value: hf.Value,
+ }
+ }
+ qlogger.RecordEvent(qlog.FrameCreated{
+ StreamID: streamID,
+ Raw: qlog.RawInfo{Length: length, PayloadLength: payloadLength},
+ Frame: qlog.Frame{Frame: qlog.HeadersFrame{
+ HeaderFields: headerFields,
+ }},
+ })
+}
--- /dev/null
+package qlog
+
+import (
+ "time"
+
+ "github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/qlogwriter/jsontext"
+)
+
+type encoderHelper struct {
+ enc *jsontext.Encoder
+ err error
+}
+
+func (h *encoderHelper) WriteToken(t jsontext.Token) {
+ if h.err != nil {
+ return
+ }
+ h.err = h.enc.WriteToken(t)
+}
+
+type RawInfo struct {
+ Length int // full packet length, including header and AEAD authentication tag
+ PayloadLength int // length of the packet payload, excluding AEAD tag
+}
+
+func (i RawInfo) encode(enc *jsontext.Encoder) error {
+ h := encoderHelper{enc: enc}
+ h.WriteToken(jsontext.BeginObject)
+ if i.Length != 0 {
+ h.WriteToken(jsontext.String("length"))
+ h.WriteToken(jsontext.Uint(uint64(i.Length)))
+ }
+ if i.PayloadLength != 0 {
+ h.WriteToken(jsontext.String("payload_length"))
+ h.WriteToken(jsontext.Uint(uint64(i.PayloadLength)))
+ }
+ h.WriteToken(jsontext.EndObject)
+ return h.err
+}
+
+type FrameParsed struct {
+ StreamID quic.StreamID
+ Raw RawInfo
+ Frame Frame
+}
+
+func (e FrameParsed) Name() string { return "http3:frame_parsed" }
+
+func (e FrameParsed) Encode(enc *jsontext.Encoder, _ time.Time) error {
+ h := encoderHelper{enc: enc}
+ h.WriteToken(jsontext.BeginObject)
+ h.WriteToken(jsontext.String("name"))
+ h.WriteToken(jsontext.String("frame_parsed"))
+ 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
+ }
+ h.WriteToken(jsontext.String("frame"))
+ if err := e.Frame.Encode(enc); err != nil {
+ return err
+ }
+ h.WriteToken(jsontext.EndObject)
+ return h.err
+}
+
+type FrameCreated struct {
+ StreamID quic.StreamID
+ Raw RawInfo
+ Frame Frame
+}
+
+func (e FrameCreated) Name() string { return "http3:frame_created" }
+
+func (e FrameCreated) Encode(enc *jsontext.Encoder, _ time.Time) error {
+ h := encoderHelper{enc: enc}
+ h.WriteToken(jsontext.BeginObject)
+ h.WriteToken(jsontext.String("name"))
+ h.WriteToken(jsontext.String("frame_created"))
+ 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
+ }
+ h.WriteToken(jsontext.String("frame"))
+ if err := e.Frame.Encode(enc); err != nil {
+ return err
+ }
+ h.WriteToken(jsontext.EndObject)
+ return h.err
+}
--- /dev/null
+package qlog
+
+import (
+ "bytes"
+ "encoding/json"
+ "io"
+ "testing"
+ "time"
+
+ "github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/internal/synctest"
+ "github.com/quic-go/quic-go/qlogwriter"
+
+ "github.com/stretchr/testify/require"
+)
+
+type nopWriteCloserImpl struct{ io.Writer }
+
+func (nopWriteCloserImpl) Close() error { return nil }
+
+func nopWriteCloser(w io.Writer) io.WriteCloser {
+ return &nopWriteCloserImpl{Writer: w}
+}
+
+func testEventEncoding(t *testing.T, ev qlogwriter.Event) (string, map[string]any) {
+ t.Helper()
+ var buf bytes.Buffer
+
+ synctest.Test(t, func(t *testing.T) {
+ tr := qlogwriter.NewConnectionFileSeq(
+ nopWriteCloser(&buf),
+ true,
+ quic.ConnectionIDFromBytes([]byte{1, 2, 3, 4}),
+ []string{"http3"},
+ )
+ go tr.Run()
+ producer := tr.AddProducer()
+
+ synctest.Wait()
+ time.Sleep(42 * time.Second)
+
+ producer.RecordEvent(ev)
+ producer.Close()
+ })
+
+ return decode(t, buf.String())
+}
+
+func decode(t *testing.T, data string) (string, map[string]any) {
+ t.Helper()
+
+ var result map[string]any
+
+ lines := bytes.Split([]byte(data), []byte{'\n'})
+ require.Len(t, lines, 3) // the first line is the trace header, the second line is the event, the third line is empty
+ require.Empty(t, lines[2])
+ require.Equal(t, qlogwriter.RecordSeparator, lines[1][0], "expected record separator at start of line")
+ require.NoError(t, json.Unmarshal(lines[1][1:], &result))
+ require.Equal(t, 42*time.Second, time.Duration(result["time"].(float64)*1e6)*time.Nanosecond)
+
+ return result["name"].(string), result["data"].(map[string]any)
+}
+
+func TestFrameParsedEvent(t *testing.T) {
+ name, ev := testEventEncoding(t, FrameParsed{
+ StreamID: quic.StreamID(4),
+ Raw: RawInfo{
+ Length: 1500,
+ PayloadLength: 100,
+ },
+ Frame: Frame{Frame: &DataFrame{}},
+ })
+
+ require.Equal(t, "http3:frame_parsed", name)
+ require.Equal(t, float64(4), ev["stream_id"])
+ require.Equal(t, "frame_parsed", ev["name"])
+ require.Contains(t, ev, "frame")
+}
+
+func TestFrameCreatedEvent(t *testing.T) {
+ name, ev := testEventEncoding(t, FrameCreated{
+ StreamID: quic.StreamID(8),
+ Raw: RawInfo{
+ PayloadLength: 200,
+ },
+ Frame: Frame{Frame: &HeadersFrame{
+ HeaderFields: []HeaderField{
+ {Name: ":status", Value: "200"},
+ {Name: "content-type", Value: "text/html"},
+ },
+ }},
+ })
+
+ require.Equal(t, "http3:frame_created", name)
+ require.Equal(t, float64(8), ev["stream_id"])
+ require.Equal(t, "frame_created", ev["name"])
+ require.Contains(t, ev, "frame")
+}
--- /dev/null
+package qlog
+
+import (
+ "github.com/quic-go/quic-go/qlogwriter/jsontext"
+)
+
+// Frame represents an HTTP/3 frame.
+type Frame struct {
+ Frame any
+}
+
+func (f Frame) Encode(enc *jsontext.Encoder) error {
+ switch frame := f.Frame.(type) {
+ case *DataFrame:
+ return frame.encode(enc)
+ case *HeadersFrame:
+ return frame.encode(enc)
+ }
+ return nil
+}
+
+// A DataFrame is a DATA frame
+type DataFrame struct{}
+
+func (f *DataFrame) encode(enc *jsontext.Encoder) error {
+ h := encoderHelper{enc: enc}
+ h.WriteToken(jsontext.BeginObject)
+ h.WriteToken(jsontext.String("frame_type"))
+ h.WriteToken(jsontext.String("data"))
+ h.WriteToken(jsontext.EndObject)
+ return h.err
+}
+
+type HeaderField struct {
+ Name string
+ Value string
+}
+
+// A HeadersFrame is a HEADERS frame
+type HeadersFrame struct {
+ HeaderFields []HeaderField
+}
+
+func (f *HeadersFrame) encode(enc *jsontext.Encoder) error {
+ h := encoderHelper{enc: enc}
+ h.WriteToken(jsontext.BeginObject)
+ h.WriteToken(jsontext.String("frame_type"))
+ h.WriteToken(jsontext.String("headers"))
+ if len(f.HeaderFields) > 0 {
+ h.WriteToken(jsontext.String("header_fields"))
+ h.WriteToken(jsontext.BeginArray)
+ for _, f := range f.HeaderFields {
+ h.WriteToken(jsontext.BeginObject)
+ h.WriteToken(jsontext.String("name"))
+ h.WriteToken(jsontext.String(f.Name))
+ h.WriteToken(jsontext.String("value"))
+ h.WriteToken(jsontext.String(f.Value))
+ h.WriteToken(jsontext.EndObject)
+ }
+ h.WriteToken(jsontext.EndArray)
+ }
+ h.WriteToken(jsontext.EndObject)
+ return h.err
+}
--- /dev/null
+package qlog
+
+import (
+ "bytes"
+ "encoding/json"
+ "testing"
+
+ "github.com/quic-go/quic-go/qlogwriter/jsontext"
+
+ "github.com/stretchr/testify/require"
+)
+
+func check(t *testing.T, f any, expected map[string]any) {
+ var buf bytes.Buffer
+ enc := jsontext.NewEncoder(&buf)
+ require.NoError(t, (Frame{Frame: f}).Encode(enc))
+ data := buf.Bytes()
+ require.True(t, json.Valid(data), "invalid JSON: %s", string(data))
+ checkEncoding(t, data, expected)
+}
+
+func checkEncoding(t *testing.T, data []byte, expected map[string]any) {
+ t.Helper()
+
+ m := make(map[string]any)
+ require.NoError(t, json.Unmarshal(data, &m))
+ require.Len(t, m, len(expected))
+
+ for key, value := range expected {
+ switch v := value.(type) {
+ case bool, string, map[string]any:
+ require.Equal(t, v, m[key])
+ case int:
+ require.Equal(t, float64(v), m[key])
+ case float64:
+ require.Equal(t, v, m[key])
+ case []map[string]any: // used for header fields
+ require.Contains(t, m, key)
+ slice, ok := m[key].([]any)
+ require.True(t, ok)
+ require.Len(t, slice, len(v))
+ for i, expectedField := range v {
+ field, ok := slice[i].(map[string]any)
+ require.True(t, ok)
+ require.Equal(t, expectedField, field)
+ }
+ default:
+ t.Fatalf("unexpected type: %T", v)
+ }
+ }
+}
+
+func TestDataFrame(t *testing.T) {
+ check(t, &DataFrame{}, map[string]any{
+ "frame_type": "data",
+ })
+}
+
+func TestHeadersFrame(t *testing.T) {
+ check(t, &HeadersFrame{
+ HeaderFields: []HeaderField{
+ {Name: ":status", Value: "200"},
+ {Name: "content-type", Value: "application/json"},
+ },
+ }, map[string]any{
+ "frame_type": "headers",
+ "header_fields": []map[string]any{
+ {"name": ":status", "value": "200"},
+ {"name": "content-type", "value": "application/json"},
+ },
+ })
+}
"time"
"github.com/quic-go/qpack"
+ "github.com/quic-go/quic-go/http3/qlog"
+
"golang.org/x/net/http/httpguts"
)
df := &dataFrame{Length: l}
w.buf = w.buf[:0]
w.buf = df.Append(w.buf)
+ if w.str.qlogger != nil {
+ w.str.qlogger.RecordEvent(qlog.FrameCreated{
+ StreamID: w.str.StreamID(),
+ Raw: qlog.RawInfo{Length: len(w.buf) + int(l), PayloadLength: int(l)},
+ Frame: qlog.Frame{Frame: qlog.DataFrame{}},
+ })
+ }
if _, err := w.str.writeUnframed(w.buf); err != nil {
return 0, maybeReplaceError(err)
}
}
func (w *responseWriter) writeHeader(status int) error {
+ var headerFields []qlog.HeaderField // only used for qlog
var headers bytes.Buffer
enc := qpack.NewEncoder(&headers)
if err := enc.WriteField(qpack.HeaderField{Name: ":status", Value: strconv.Itoa(status)}); err != nil {
return err
}
+ if w.str.qlogger != nil {
+ headerFields = append(headerFields, qlog.HeaderField{Name: ":status", Value: strconv.Itoa(status)})
+ }
// Handle trailer fields
if vals, ok := w.header["Trailer"]; ok {
continue
}
for index := range v {
- if err := enc.WriteField(qpack.HeaderField{Name: strings.ToLower(k), Value: v[index]}); err != nil {
+ name := strings.ToLower(k)
+ value := v[index]
+ if err := enc.WriteField(qpack.HeaderField{Name: name, Value: value}); err != nil {
return err
}
+ if w.str.qlogger != nil {
+ headerFields = append(headerFields, qlog.HeaderField{Name: name, Value: value})
+ }
}
}
buf = (&headersFrame{Length: uint64(headers.Len())}).Append(buf)
buf = append(buf, headers.Bytes()...)
+ if w.str.qlogger != nil {
+ qlogCreatedHeadersFrame(w.str.qlogger, w.str.StreamID(), len(buf), headers.Len(), headerFields)
+ }
+
_, err := w.str.writeUnframed(buf)
return err
}
}
var b bytes.Buffer
+ var headerFields []qlog.HeaderField
enc := qpack.NewEncoder(&b)
for trailer := range w.trailers {
trailerName := strings.ToLower(strings.TrimPrefix(trailer, http.TrailerPrefix))
if err := enc.WriteField(qpack.HeaderField{Name: trailerName, Value: val}); err != nil {
return err
}
+ if w.str.qlogger != nil {
+ headerFields = append(headerFields, qlog.HeaderField{Name: trailerName, Value: val})
+ }
}
}
}
buf := make([]byte, 0, frameHeaderLen+b.Len())
buf = (&headersFrame{Length: uint64(b.Len())}).Append(buf)
buf = append(buf, b.Bytes()...)
+ if w.str.qlogger != nil {
+ qlogCreatedHeadersFrame(w.str.qlogger, w.str.StreamID(), len(buf), b.Len(), headerFields)
+ }
_, err := w.str.writeUnframed(buf)
w.trailerWritten = true
return err
"net/http"
"testing"
+ "github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/http3/qlog"
+ "github.com/quic-go/quic-go/testutils/events"
+
"github.com/quic-go/qpack"
+ "github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"go.uber.org/mock/gomock"
)
type testResponseWriter struct {
*responseWriter
- buf *bytes.Buffer
+ eventRecorder *events.Recorder
+ buf *bytes.Buffer
}
-func (rw *testResponseWriter) DecodeHeaders(t *testing.T) map[string][]string {
+func (rw *testResponseWriter) DecodeHeaders(t *testing.T, idx int) map[string][]string {
t.Helper()
rw.Flush()
fields := make(map[string][]string)
decoder := qpack.NewDecoder(nil)
+ startLen := rw.buf.Len()
frame, err := (&frameParser{r: rw.buf}).ParseNext()
require.NoError(t, err)
require.IsType(t, &headersFrame{}, frame)
- data := make([]byte, frame.(*headersFrame).Length)
+ payloadLen := frame.(*headersFrame).Length
+ data := make([]byte, payloadLen)
+ headerFrameLen := startLen - rw.buf.Len() + len(data)
_, err = io.ReadFull(rw.buf, data)
require.NoError(t, err)
hfs, err := decoder.DecodeFull(data)
require.NoError(t, err)
+
+ // check that the decoded header fields are properly logged
+ require.GreaterOrEqual(t, len(rw.eventRecorder.Events(qlog.FrameCreated{})), idx+1)
+ require.IsType(t, qlog.HeadersFrame{}, rw.eventRecorder.Events()[idx].(qlog.FrameCreated).Frame.Frame)
+ ev := rw.eventRecorder.Events()[idx].(qlog.FrameCreated)
+ assert.Equal(t, quic.StreamID(42), ev.StreamID)
+ assert.Equal(t, headerFrameLen, ev.Raw.Length, "raw.Length")
+ assert.Equal(t, int(payloadLen), ev.Raw.PayloadLength, "raw.PayloadLength")
+
for _, p := range hfs {
fields[p.Name] = append(fields[p.Name], p.Value)
+ require.Contains(t,
+ ev.Frame.Frame.(qlog.HeadersFrame).HeaderFields,
+ qlog.HeaderField{Name: p.Name, Value: p.Value},
+ )
}
+
return fields
}
}
func newTestResponseWriter(t *testing.T) *testResponseWriter {
+ var eventRecorder events.Recorder
buf := &bytes.Buffer{}
mockCtrl := gomock.NewController(t)
str := NewMockDatagramStream(mockCtrl)
+ str.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
str.EXPECT().Write(gomock.Any()).DoAndReturn(buf.Write).AnyTimes()
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 }), nil, false, nil)
- return &testResponseWriter{responseWriter: rw, buf: buf}
+ rw := newResponseWriter(
+ newStream(str, nil, nil, func(r io.Reader, u uint64) error { return nil }, &eventRecorder),
+ nil,
+ false,
+ nil,
+ )
+ return &testResponseWriter{
+ responseWriter: rw,
+ eventRecorder: &eventRecorder,
+ buf: buf,
+ }
}
func TestResponseWriterInvalidStatus(t *testing.T) {
// write some data
rw.Write([]byte("foobar"))
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"418"}, fields[":status"])
require.Equal(t, []string{"42"}, fields["content-length"])
require.Equal(t,
rw := newTestResponseWriter(t)
rw.Write([]byte("foobar"))
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"200"}, fields[":status"])
require.Equal(t, []byte("foobar"), rw.DecodeBody(t))
}
require.Zero(t, n)
require.ErrorIs(t, err, http.ErrBodyNotAllowed)
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"304"}, fields[":status"])
require.Empty(t, rw.DecodeBody(t))
}
require.Zero(t, n)
require.ErrorIs(t, err, http.ErrContentLength)
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"200"}, fields[":status"])
require.Equal(t, []string{"6"}, fields["content-length"])
require.Equal(t, []byte("foobar"), rw.DecodeBody(t))
}
rw.Write([]byte("<html></html>"))
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"200"}, fields[":status"])
if expectedContentType == "" {
require.NotContains(t, fields, "content-type")
require.NoError(t, err)
// Early Hints must have been received
- fields := rw.DecodeHeaders(t)
+ fields := rw.DecodeHeaders(t, 0)
require.Equal(t, 2, len(fields))
require.Equal(t, []string{"103"}, fields[":status"])
require.Equal(t,
)
// headers sent in the informational response must also be included in the final response
- fields = rw.DecodeHeaders(t)
+ fields = rw.DecodeHeaders(t, 1)
require.Equal(t, 4, len(fields))
require.Equal(t, []string{"200"}, fields[":status"])
require.Contains(t, fields, "date")
require.NoError(t, err)
// writeTrailers needs to be called after writing the full body
- headers := rw.DecodeHeaders(t)
+ headers := rw.DecodeHeaders(t, 0)
require.Equal(t, []string{"key"}, headers["trailer"])
require.NotContains(t, headers, "foo")
require.Equal(t, []byte("foobar"), rw.DecodeBody(t))
rw.Header().Set(http.TrailerPrefix+"lorem", "ipsum") // unannounced trailer with trailer prefix
require.NoError(t, rw.writeTrailers())
- trailers := rw.DecodeHeaders(t)
+ trailers := rw.DecodeHeaders(t, 2)
require.Equal(t, []string{"value"}, trailers["key"])
require.Equal(t, []string{"ipsum"}, trailers["lorem"])
// trailers without the trailer prefix that were not announced are ignored
"time"
"github.com/quic-go/quic-go"
+ "github.com/quic-go/quic-go/qlogwriter"
"github.com/quic-go/quic-go/quicvarint"
"github.com/quic-go/qpack"
}
}
+ var qlogger qlogwriter.Recorder
+ if qlogTrace := conn.QlogTrace(); qlogTrace != nil {
+ qlogger = qlogTrace.AddProducer()
+ }
+
hconn := newConnection(
connCtx,
conn,
// handleRequest will return once the request has been handled,
// or the underlying connection is closed
defer wg.Done()
- s.handleRequest(hconn, str, hconn.decoder)
+ s.handleRequest(hconn, str, hconn.decoder, qlogger)
}()
}
wg.Wait()
return uint64(s.MaxHeaderBytes)
}
-func (s *Server) handleRequest(conn *Conn, str datagramStream, decoder *qpack.Decoder) {
+func (s *Server) handleRequest(
+ conn *Conn,
+ str datagramStream,
+ decoder *qpack.Decoder,
+ qlogger qlogwriter.Recorder,
+) {
var ufh unknownFrameHandlerFunc
if s.StreamHijacker != nil {
ufh = func(ft FrameType, e error) (processed bool, err error) {
return
}
if hf.Length > s.maxHeaderBytes() {
+ maybeQlogInvalidHeadersFrame(qlogger, str.StreamID(), hf.Length)
str.CancelRead(quic.StreamErrorCode(ErrCodeFrameError))
str.CancelWrite(quic.StreamErrorCode(ErrCodeFrameError))
return
}
headerBlock := make([]byte, hf.Length)
if _, err := io.ReadFull(str, headerBlock); err != nil {
+ maybeQlogInvalidHeadersFrame(qlogger, str.StreamID(), hf.Length)
str.CancelRead(quic.StreamErrorCode(ErrCodeRequestIncomplete))
str.CancelWrite(quic.StreamErrorCode(ErrCodeRequestIncomplete))
return
conn.CloseWithError(quic.ApplicationErrorCode(ErrCodeGeneralProtocolError), "expected first frame to be a HEADERS frame")
return
}
+ if qlogger != nil {
+ qlogParsedHeadersFrame(qlogger, str.StreamID(), hf.Length, hfs)
+ }
req, err := requestFromHeaders(hfs)
if err != nil {
str.CancelRead(quic.StreamErrorCode(ErrCodeMessageError))
if _, ok := req.Header["Content-Length"]; ok && req.ContentLength >= 0 {
contentLength = req.ContentLength
}
- hstr := newStream(str, conn, nil, nil)
+ hstr := newStream(str, conn, nil, nil, qlogger)
body := newRequestBody(hstr, contentLength, conn.Context(), conn.ReceivedSettings(), conn.Settings)
req.Body = body
"github.com/quic-go/quic-go"
"github.com/quic-go/quic-go/http3/internal/testdata"
+ "github.com/quic-go/quic-go/http3/qlog"
+ "github.com/quic-go/quic-go/qlogwriter"
"github.com/quic-go/quic-go/quicvarint"
+ "github.com/quic-go/quic-go/testutils/events"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
func TestServerRequestHandling(t *testing.T) {
t.Run("200 with an empty handler", func(t *testing.T) {
+ var eventRecorder events.Recorder
hfs, body := testServerRequestHandling(t,
func(w http.ResponseWriter, r *http.Request) {},
httptest.NewRequest(http.MethodGet, "https://www.example.com", nil),
+ &eventRecorder,
)
require.Equal(t, hfs[":status"], []string{"200"})
require.Empty(t, body)
+
+ require.Len(t, eventRecorder.Events(qlog.FrameParsed{}), 1)
+ require.IsType(t, qlog.HeadersFrame{}, eventRecorder.Events(qlog.FrameParsed{})[0].(qlog.FrameParsed).Frame.Frame)
+ fp := eventRecorder.Events(qlog.FrameParsed{})[0].(qlog.FrameParsed)
+ require.Equal(t, quic.StreamID(0), fp.StreamID)
+ require.NotZero(t, fp.Raw.PayloadLength)
+ require.Contains(t, fp.Frame.Frame.(qlog.HeadersFrame).HeaderFields, qlog.HeaderField{Name: ":method", Value: "GET"})
+ require.Contains(t, fp.Frame.Frame.(qlog.HeadersFrame).HeaderFields, qlog.HeaderField{Name: ":authority", Value: "www.example.com"})
+
+ require.Len(t, eventRecorder.Events(qlog.FrameCreated{}), 1)
+ require.IsType(t, qlog.HeadersFrame{}, eventRecorder.Events(qlog.FrameCreated{})[0].(qlog.FrameCreated).Frame.Frame)
+ fc := eventRecorder.Events(qlog.FrameCreated{})[0].(qlog.FrameCreated)
+ require.Equal(t, quic.StreamID(0), fp.StreamID)
+ require.NotZero(t, fc.Raw.PayloadLength)
+ require.Contains(t, fc.Frame.Frame.(qlog.HeadersFrame).HeaderFields, qlog.HeaderField{Name: ":status", Value: "200"})
})
t.Run("content-length", func(t *testing.T) {
w.Write([]byte("foobar"))
},
httptest.NewRequest(http.MethodGet, "https://www.example.com", nil),
+ nil,
)
require.Equal(t, hfs[":status"], []string{"418"})
require.Equal(t, hfs["content-length"], []string{"6"})
w.Write([]byte("bar"))
},
httptest.NewRequest(http.MethodGet, "https://www.example.com", nil),
+ nil,
)
require.Equal(t, hfs[":status"], []string{"200"})
require.NotContains(t, hfs, "content-length")
w.Write([]byte("foobar"))
},
httptest.NewRequest(http.MethodHead, "https://www.example.com", nil),
+ nil,
)
require.Equal(t, hfs[":status"], []string{"200"})
require.Empty(t, body)
w.Write(data)
},
httptest.NewRequest(http.MethodPost, "https://www.example.com", bytes.NewBuffer([]byte("foobar"))),
+ nil,
)
require.Equal(t, hfs[":status"], []string{"418"})
require.Equal(t, []byte("foobar"), body)
func testServerRequestHandling(t *testing.T,
handler http.HandlerFunc,
req *http.Request,
+ rec qlogwriter.Recorder,
) (responseHeaders map[string][]string, body []byte) {
- clientConn, serverConn := newConnPair(t)
+ clientConn, serverConn := newConnPairWithRecorder(t, nil, rec)
str, err := clientConn.OpenStream()
require.NoError(t, err)
_, err = str.Write(encodeRequest(t, req))
require.NoError(t, err)
_, err = str.Write(encodeRequest(t, req))
require.NoError(t, err)
- // require.NoError(t, str.Close())
done := make(chan struct{})
s := &Server{
func TestServerRequestHeaderTooLarge(t *testing.T) {
t.Run("default value", func(t *testing.T) {
+ var eventRecorder events.Recorder
// use 2*DefaultMaxHeaderBytes here. qpack will compress the request,
// but the request will still end up larger than DefaultMaxHeaderBytes.
url := bytes.Repeat([]byte{'a'}, http.DefaultMaxHeaderBytes*2)
testServerRequestHeaderTooLarge(t,
httptest.NewRequest(http.MethodGet, "https://"+string(url), nil),
0,
+ &eventRecorder,
)
+ events := eventRecorder.Events(qlog.FrameParsed{})
+ require.Len(t, events, 1)
+ require.Equal(t, qlog.HeadersFrame{}, events[0].(qlog.FrameParsed).Frame.Frame)
+ // The request is QPACK-compressed, so it will be smaller than 2*http.DefaultMaxHeaderBytes
+ require.Greater(t, events[0].(qlog.FrameParsed).Raw.PayloadLength, http.DefaultMaxHeaderBytes)
+ require.Less(t, events[0].(qlog.FrameParsed).Raw.PayloadLength, http.DefaultMaxHeaderBytes*2)
})
t.Run("custom value", func(t *testing.T) {
+ var eventRecorder events.Recorder
testServerRequestHeaderTooLarge(t,
httptest.NewRequest(http.MethodGet, "https://www.example.com", nil),
20,
+ &eventRecorder,
)
+ events := eventRecorder.Events(qlog.FrameParsed{})
+ require.Len(t, events, 1)
+ require.Equal(t, qlog.HeadersFrame{}, events[0].(qlog.FrameParsed).Frame.Frame)
+ require.Greater(t, events[0].(qlog.FrameParsed).Raw.PayloadLength, 20)
+ require.Less(t, events[0].(qlog.FrameParsed).Raw.PayloadLength, 40)
})
}
-func testServerRequestHeaderTooLarge(t *testing.T, req *http.Request, maxHeaderBytes int) {
+func testServerRequestHeaderTooLarge(t *testing.T, req *http.Request, maxHeaderBytes int, rec qlogwriter.Recorder) {
var called bool
s := &Server{
MaxHeaderBytes: maxHeaderBytes,
}
s.init()
- clientConn, serverConn := newConnPair(t)
+ clientConn, serverConn := newConnPairWithRecorder(t, nil, rec)
str, err := clientConn.OpenStream()
require.NoError(t, err)
_, err = str.Write(encodeRequest(t, req))
"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/qpack"
)
bytesRemainingInFrame uint64
+ qlogger qlogwriter.Recorder
+
parseTrailer func(io.Reader, uint64) error
parsedTrailer bool
}
-func newStream(str datagramStream, conn *Conn, trace *httptrace.ClientTrace, parseTrailer func(io.Reader, uint64) error) *Stream {
+func newStream(
+ str datagramStream,
+ conn *Conn,
+ trace *httptrace.ClientTrace,
+ parseTrailer func(io.Reader, uint64) error,
+ qlogger qlogwriter.Recorder,
+) *Stream {
return &Stream{
datagramStream: str,
conn: conn,
buf: make([]byte, 16),
+ qlogger: qlogger,
parseTrailer: parseTrailer,
frameParser: &frameParser{
closeConn: conn.CloseWithError,
continue
}
if s.parsedTrailer {
+ maybeQlogInvalidHeadersFrame(s.qlogger, s.StreamID(), f.Length)
return 0, errors.New("additional HEADERS frame received after trailers")
}
s.parsedTrailer = true
func (s *Stream) Write(b []byte) (int, error) {
s.buf = s.buf[:0]
s.buf = (&dataFrame{Length: uint64(len(b))}).Append(s.buf)
+ if s.qlogger != nil {
+ s.qlogger.RecordEvent(qlog.FrameCreated{
+ StreamID: s.StreamID(),
+ Raw: qlog.RawInfo{
+ Length: len(s.buf) + len(b),
+ PayloadLength: len(b),
+ },
+ Frame: qlog.Frame{Frame: qlog.DataFrame{}},
+ })
+ }
if _, err := s.datagramStream.Write(s.buf); err != nil {
return 0, err
}
"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/testutils/events"
"github.com/quic-go/qpack"
),
nil,
func(r io.Reader, u uint64) error { return nil },
+ nil,
)
buf.Write(getDataFrame([]byte("foobar")))
newConnection(context.Background(), clientConn, false, false, nil, 0),
nil,
func(r io.Reader, u uint64) error { return nil },
+ nil,
)
_, err := str.Read([]byte{0})
var buf bytes.Buffer
mockCtrl := gomock.NewController(t)
qstr := NewMockDatagramStream(mockCtrl)
+ qstr.EXPECT().StreamID().Return(quic.StreamID(42)).AnyTimes()
qstr.EXPECT().Write(gomock.Any()).DoAndReturn(buf.Write).AnyTimes()
- str := newStream(qstr, nil, nil, func(r io.Reader, u uint64) error { return nil })
+ var eventRecorder events.Recorder
+ str := newStream(qstr, nil, nil, func(r io.Reader, u uint64) error { return nil }, &eventRecorder)
str.Write([]byte("foo"))
str.Write([]byte("foobar"))
+ startLen := buf.Len()
fp := frameParser{r: &buf}
f, err := fp.ParseNext()
require.NoError(t, err)
+ f1Len := startLen - buf.Len()
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()
require.NoError(t, err)
+ f2Len := startLen - buf.Len()
require.Equal(t, &dataFrame{Length: 6}, f)
b = make([]byte, 6)
_, err = io.ReadFull(&buf, b)
require.NoError(t, err)
require.Equal(t, []byte("foobar"), b)
+
+ require.Equal(t,
+ []qlogwriter.Event{
+ qlog.FrameCreated{
+ StreamID: 42,
+ Raw: qlog.RawInfo{Length: f1Len + 3, PayloadLength: 3},
+ Frame: qlog.Frame{Frame: qlog.DataFrame{}},
+ },
+ qlog.FrameCreated{
+ StreamID: 42,
+ Raw: qlog.RawInfo{Length: f2Len + 6, PayloadLength: 6},
+ Frame: qlog.Frame{Frame: qlog.DataFrame{}},
+ },
+ },
+ eventRecorder.Events(qlog.FrameCreated{}),
+ )
}
func TestRequestStream(t *testing.T) {
newConnection(context.Background(), clientConn, false, false, nil, 0),
&httptrace.ClientTrace{},
func(r io.Reader, u uint64) error { return nil },
+ nil,
),
requestWriter,
make(chan struct{}),
*handshake.TokenGenerator,
bool, /* client address validated by an address validation token */
time.Duration,
- qlogwriter.Recorder,
+ qlogwriter.Trace,
utils.Logger,
protocol.Version,
) *wrappedConn
cancel = cancel1
}
ctx = context.WithValue(ctx, ConnectionTracingKey, nextConnTracingID())
- var qlogger qlogwriter.Recorder
+ var qlogTrace qlogwriter.Trace
if config.Tracer != nil {
// Use the same connection ID that is passed to the client's GetLogWriter callback.
connID := hdr.DestConnectionID
if origDestConnID.Len() > 0 {
connID = origDestConnID
}
- if t := config.Tracer(ctx, false, connID); t != nil {
- qlogger = t.AddProducer()
- }
+ qlogTrace = config.Tracer(ctx, false, connID)
}
connID, err := s.connIDGenerator.GenerateConnectionID()
if err != nil {
s.tokenGenerator,
clientAddrVerified,
rtt,
- qlogger,
+ qlogTrace,
s.logger,
hdr.Version,
)
*handshake.TokenGenerator,
bool, /* client address validated by an address validation token */
time.Duration,
- qlogwriter.Recorder,
+ qlogwriter.Trace,
utils.Logger,
protocol.Version,
) *wrappedConn
_ *handshake.TokenGenerator,
_ bool,
_ time.Duration,
- _ qlogwriter.Recorder,
+ _ qlogwriter.Trace,
_ utils.Logger,
_ protocol.Version,
) *wrappedConn {
_ *handshake.TokenGenerator,
_ bool,
_ time.Duration,
- _ qlogwriter.Recorder,
+ _ qlogwriter.Trace,
_ utils.Logger,
_ protocol.Version,
) *wrappedConn {
return nil, t.closeErr
}
- var qlogger qlogwriter.Recorder
+ var qlogTrace qlogwriter.Trace
if config.Tracer != nil {
- if tr := config.Tracer(ctx, true, destConnID); tr != nil {
- qlogger = tr.AddProducer()
- }
- }
-
- if qlogger != nil {
- var srcAddr, destAddr *net.UDPAddr
- if addr, ok := sendConn.LocalAddr().(*net.UDPAddr); ok {
- srcAddr = addr
- }
- if addr, ok := sendConn.RemoteAddr().(*net.UDPAddr); ok {
- destAddr = addr
- }
- qlogger.RecordEvent(qlog.StartedConnection{
- SrcAddr: srcAddr,
- DestAddr: destAddr,
- SrcConnectionID: srcConnID,
- DestConnectionID: destConnID,
- })
+ qlogTrace = config.Tracer(ctx, true, destConnID)
}
logger := utils.DefaultLogger.WithPrefix("client")
initialPacketNumber,
use0RTT,
hasNegotiatedVersion,
- qlogger,
+ qlogTrace,
logger,
version,
)
_ protocol.PacketNumber,
_ bool,
_ bool,
- _ qlogwriter.Recorder,
+ _ qlogwriter.Trace,
_ utils.Logger,
_ protocol.Version,
) *wrappedConn {
pn protocol.PacketNumber,
_ bool,
hasNegotiatedVersion bool,
- _ qlogwriter.Recorder,
+ _ qlogwriter.Trace,
_ utils.Logger,
v protocol.Version,
) *wrappedConn {