http3: qlog sent and received DATAGRAMs (#5375)

http3/conn.go

@@ -411,8 +411,18 @@ func (c *Conn) handleControlStream(str *quic.ReceiveStream) {
 func (c *Conn) sendDatagram(streamID quic.StreamID, b []byte) error {
 	// TODO: this creates a lot of garbage and an additional copy
 	data := make([]byte, 0, len(b)+8)
+	quarterStreamID := uint64(streamID / 4)
 	data = quicvarint.Append(data, uint64(streamID/4))
 	data = append(data, b...)
+	if c.qlogger != nil {
+		c.qlogger.RecordEvent(qlog.DatagramCreated{
+			QuaterStreamID: quarterStreamID,
+			Raw: qlog.RawInfo{
+				Length:        len(data),
+				PayloadLength: len(b),
+			},
+		})
+	}
 	return c.conn.SendDatagram(data)
 }
 
@@ -427,6 +437,15 @@ func (c *Conn) receiveDatagrams() error {
 			c.CloseWithError(quic.ApplicationErrorCode(ErrCodeDatagramError), "")
 			return fmt.Errorf("could not read quarter stream id: %w", err)
 		}
+		if c.qlogger != nil {
+			c.qlogger.RecordEvent(qlog.DatagramParsed{
+				QuaterStreamID: quarterStreamID,
+				Raw: qlog.RawInfo{
+					Length:        len(b),
+					PayloadLength: len(b) - n,
+				},
+			})
+		}
 		if quarterStreamID > maxQuarterStreamID {
 			c.CloseWithError(quic.ApplicationErrorCode(ErrCodeDatagramError), "")
 			return fmt.Errorf("invalid quarter stream id: %w", err)

http3/conn_test.go

@@ -9,6 +9,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/quic-go/quic-go/testutils/events"
 
@@ -416,7 +417,8 @@ func TestConnInconsistentDatagramSupport(t *testing.T) {
 }
 
 func TestConnSendAndReceiveDatagram(t *testing.T) {
-	clientConn, serverConn := newConnPairWithDatagrams(t)
+	var eventRecorder events.Recorder
+	clientConn, serverConn := newConnPairWithDatagrams(t, &eventRecorder, nil)
 
 	conn := newConnection(
 		clientConn.Context(),
@@ -441,9 +443,21 @@ func TestConnSendAndReceiveDatagram(t *testing.T) {
 	// since the stream is not open yet, it will be dropped
 	quarterStreamID := quicvarint.Append([]byte{}, strID/4)
 
-	require.NoError(t, serverConn.SendDatagram(append(quarterStreamID, []byte("foo")...)))
+	datagram := append(quarterStreamID, []byte("foo")...)
+	require.NoError(t, serverConn.SendDatagram(datagram))
 	time.Sleep(scaleDuration(10 * time.Millisecond)) // give the datagram a chance to be delivered
 
+	require.Equal(t,
+		[]qlogwriter.Event{
+			qlog.DatagramParsed{
+				QuaterStreamID: strID / 4,
+				Raw:            qlog.RawInfo{Length: len(datagram), PayloadLength: 3},
+			},
+		},
+		eventRecorder.Events(qlog.DatagramParsed{}),
+	)
+	eventRecorder.Clear()
+
 	// don't use stream 0, since that makes it hard to test that the quarter stream ID is used
 	str1, err := conn.openRequestStream(context.Background(), nil, nil, true, 1000)
 	require.NoError(t, err)
@@ -468,6 +482,17 @@ func TestConnSendAndReceiveDatagram(t *testing.T) {
 	expected := quicvarint.Append([]byte{}, strID/4)
 	expected = append(expected, []byte("foobaz")...)
 
+	require.Equal(t,
+		[]qlogwriter.Event{
+			qlog.DatagramCreated{
+				QuaterStreamID: strID / 4,
+				Raw:            qlog.RawInfo{PayloadLength: 6, Length: len(expected)},
+			},
+		},
+		eventRecorder.Events(qlog.DatagramCreated{}),
+	)
+	eventRecorder.Clear()
+
 	data, err = serverConn.ReceiveDatagram(ctx)
 	require.NoError(t, err)
 	require.Equal(t, expected, data)
@@ -483,7 +508,7 @@ func TestConnDatagramFailures(t *testing.T) {
 }
 
 func testConnDatagramFailures(t *testing.T, datagram []byte) {
-	clientConn, serverConn := newConnPairWithDatagrams(t)
+	clientConn, serverConn := newConnPairWithDatagrams(t, nil, nil)
 
 	conn := newConnection(
 		clientConn.Context(),

http3/http3_helper_test.go

@@ -187,7 +187,7 @@ func newConnPairWithRecorder(t *testing.T, clientRecorder, serverRecorder qlogwr
 	return cl, conn
 }
 
-func newConnPairWithDatagrams(t *testing.T) (client, server *quic.Conn) {
+func newConnPairWithDatagrams(t *testing.T, clientRecorder, serverRecorder qlogwriter.Recorder) (client, server *quic.Conn) {
 	t.Helper()
 
 	ln, err := quic.ListenEarly(
@@ -197,13 +197,27 @@ func newConnPairWithDatagrams(t *testing.T) (client, server *quic.Conn) {
 			InitialStreamReceiveWindow:     maxByteCount,
 			InitialConnectionReceiveWindow: maxByteCount,
 			EnableDatagrams:                true,
+			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{EnableDatagrams: true})
+	cl, err := quic.DialEarly(
+		ctx,
+		newUDPConnLocalhost(t),
+		ln.Addr(),
+		getTLSClientConfig(),
+		&quic.Config{
+			EnableDatagrams: true,
+			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, "") })
 

http3/qlog/event.go

@@ -96,3 +96,43 @@ func (e FrameCreated) Encode(enc *jsontext.Encoder, _ time.Time) error {
 	h.WriteToken(jsontext.EndObject)
 	return h.err
 }
+
+type DatagramCreated struct {
+	QuaterStreamID uint64
+	Raw            RawInfo
+}
+
+func (e DatagramCreated) Name() string { return "http3:datagram_created" }
+
+func (e DatagramCreated) Encode(enc *jsontext.Encoder, _ time.Time) error {
+	h := encoderHelper{enc: enc}
+	h.WriteToken(jsontext.BeginObject)
+	h.WriteToken(jsontext.String("quater_stream_id"))
+	h.WriteToken(jsontext.Uint(e.QuaterStreamID))
+	h.WriteToken(jsontext.String("raw"))
+	if err := e.Raw.encode(enc); err != nil {
+		return err
+	}
+	h.WriteToken(jsontext.EndObject)
+	return h.err
+}
+
+type DatagramParsed struct {
+	QuaterStreamID uint64
+	Raw            RawInfo
+}
+
+func (e DatagramParsed) Name() string { return "http3:datagram_parsed" }
+
+func (e DatagramParsed) Encode(enc *jsontext.Encoder, _ time.Time) error {
+	h := encoderHelper{enc: enc}
+	h.WriteToken(jsontext.BeginObject)
+	h.WriteToken(jsontext.String("quater_stream_id"))
+	h.WriteToken(jsontext.Uint(e.QuaterStreamID))
+	h.WriteToken(jsontext.String("raw"))
+	if err := e.Raw.encode(enc); err != nil {
+		return err
+	}
+	h.WriteToken(jsontext.EndObject)
+	return h.err
+}