split the tracing function for received short and long header packets

qlog/event.go

@@ -177,7 +177,7 @@ func (e eventPacketSent) MarshalJSONObject(enc *gojay.Encoder) {
 }
 
 type eventPacketReceived struct {
-	Header        packetHeader
+	Header        gojay.MarshalerJSONObject // either a shortHeader or a packetHeader
 	Length        logging.ByteCount
 	PayloadLength logging.ByteCount
 	Frames        frames

qlog/packet_header.go

@@ -4,7 +4,6 @@ import (
 	"fmt"
 
 	"github.com/lucas-clemente/quic-go/internal/protocol"
-	"github.com/lucas-clemente/quic-go/internal/wire"
 	"github.com/lucas-clemente/quic-go/logging"
 
 	"github.com/francoispqt/gojay"
@@ -37,6 +36,7 @@ func (t token) MarshalJSONObject(enc *gojay.Encoder) {
 }
 
 // PacketHeader is a QUIC packet header.
+// TODO: make this a long header
 type packetHeader struct {
 	PacketType logging.PacketType
 
@@ -50,7 +50,7 @@ type packetHeader struct {
 	Token *token
 }
 
-func transformHeader(hdr *wire.Header) *packetHeader {
+func transformHeader(hdr *logging.Header) *packetHeader {
 	h := &packetHeader{
 		PacketType:       logging.PacketTypeFromHeader(hdr),
 		SrcConnectionID:  hdr.SrcConnectionID,
@@ -63,7 +63,7 @@ func transformHeader(hdr *wire.Header) *packetHeader {
 	return h
 }
 
-func transformExtendedHeader(hdr *wire.ExtendedHeader) *packetHeader {
+func transformLongHeader(hdr *logging.ExtendedHeader) *packetHeader {
 	h := transformHeader(&hdr.Header)
 	h.PacketNumber = hdr.PacketNumber
 	h.KeyPhaseBit = hdr.KeyPhase
@@ -131,3 +131,27 @@ func (h packetHeaderWithTypeAndPacketNumber) MarshalJSONObject(enc *gojay.Encode
 	enc.StringKey("packet_type", packetType(h.PacketType).String())
 	enc.Int64Key("packet_number", int64(h.PacketNumber))
 }
+
+type shortHeader struct {
+	DestConnectionID logging.ConnectionID
+	PacketNumber     logging.PacketNumber
+	KeyPhaseBit      logging.KeyPhaseBit
+}
+
+func transformShortHeader(hdr *logging.ShortHeader) *shortHeader {
+	return &shortHeader{
+		DestConnectionID: hdr.DestConnectionID,
+		PacketNumber:     hdr.PacketNumber,
+		KeyPhaseBit:      hdr.KeyPhase,
+	}
+}
+
+func (h shortHeader) IsNil() bool { return false }
+func (h shortHeader) MarshalJSONObject(enc *gojay.Encoder) {
+	enc.StringKey("packet_type", packetType(logging.PacketType1RTT).String())
+	if h.DestConnectionID.Len() > 0 {
+		enc.StringKey("dcid", h.DestConnectionID.String())
+	}
+	enc.Int64Key("packet_number", int64(h.PacketNumber))
+	enc.StringKey("key_phase_bit", h.KeyPhaseBit.String())
+}

qlog/packet_header_test.go

@@ -26,7 +26,7 @@ var _ = Describe("Packet Header", func() {
 		check := func(hdr *wire.ExtendedHeader, expected map[string]interface{}) {
 			buf := &bytes.Buffer{}
 			enc := gojay.NewEncoder(buf)
-			ExpectWithOffset(1, enc.Encode(transformExtendedHeader(hdr))).To(Succeed())
+			ExpectWithOffset(1, enc.Encode(transformLongHeader(hdr))).To(Succeed())
 			data := buf.Bytes()
 			ExpectWithOffset(1, json.Valid(data)).To(BeTrue())
 			checkEncoding(data, expected)

qlog/qlog.go

@@ -286,7 +286,7 @@ func (t *connectionTracer) SentPacket(hdr *wire.ExtendedHeader, packetSize loggi
 	for _, f := range frames {
 		fs = append(fs, frame{Frame: f})
 	}
-	header := *transformExtendedHeader(hdr)
+	header := *transformLongHeader(hdr)
 	t.mutex.Lock()
 	t.recordEvent(time.Now(), &eventPacketSent{
 		Header:        header,
@@ -297,12 +297,12 @@ func (t *connectionTracer) SentPacket(hdr *wire.ExtendedHeader, packetSize loggi
 	t.mutex.Unlock()
 }
 
-func (t *connectionTracer) ReceivedPacket(hdr *wire.ExtendedHeader, packetSize logging.ByteCount, frames []logging.Frame) {
+func (t *connectionTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, packetSize logging.ByteCount, frames []logging.Frame) {
 	fs := make([]frame, len(frames))
 	for i, f := range frames {
 		fs[i] = frame{Frame: f}
 	}
-	header := *transformExtendedHeader(hdr)
+	header := *transformLongHeader(hdr)
 	t.mutex.Lock()
 	t.recordEvent(time.Now(), &eventPacketReceived{
 		Header:        header,
@@ -313,6 +313,22 @@ func (t *connectionTracer) ReceivedPacket(hdr *wire.ExtendedHeader, packetSize l
 	t.mutex.Unlock()
 }
 
+func (t *connectionTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, packetSize logging.ByteCount, frames []logging.Frame) {
+	fs := make([]frame, len(frames))
+	for i, f := range frames {
+		fs[i] = frame{Frame: f}
+	}
+	header := *transformShortHeader(hdr)
+	t.mutex.Lock()
+	t.recordEvent(time.Now(), &eventPacketReceived{
+		Header:        header,
+		Length:        packetSize,
+		PayloadLength: packetSize - hdr.Len(),
+		Frames:        fs,
+	})
+	t.mutex.Unlock()
+}
+
 func (t *connectionTracer) ReceivedRetry(hdr *wire.Header) {
 	t.mutex.Lock()
 	t.recordEvent(time.Now(), &eventRetryReceived{

qlog/qlog_test.go

@@ -11,6 +11,8 @@ import (
 	"os"
 	"time"
 
+	"github.com/lucas-clemente/quic-go/internal/wire"
+
 	"github.com/lucas-clemente/quic-go"
 	"github.com/lucas-clemente/quic-go/internal/protocol"
 	"github.com/lucas-clemente/quic-go/internal/qerr"
@@ -486,8 +488,8 @@ var _ = Describe("Tracing", func() {
 				Expect(frames[1].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "max_data"))
 			})
 
-			It("records a received packet", func() {
-				tracer.ReceivedPacket(
+			It("records a received Long Header packet", func() {
+				tracer.ReceivedLongHeaderPacket(
 					&logging.ExtendedHeader{
 						Header: logging.Header{
 							IsLongHeader:     true,
@@ -526,6 +528,37 @@ var _ = Describe("Tracing", func() {
 				Expect(ev["frames"].([]interface{})).To(HaveLen(2))
 			})
 
+			It("records a received Short Header packet", func() {
+				shdr := &wire.ShortHeader{
+					DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3, 4, 5, 6, 7, 8}),
+					PacketNumber:     1337,
+					KeyPhase:         protocol.KeyPhaseZero,
+				}
+				tracer.ReceivedShortHeaderPacket(
+					shdr,
+					789,
+					[]logging.Frame{
+						&logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987},
+						&logging.StreamFrame{StreamID: 123, Offset: 1234, Length: 6, Fin: true},
+					},
+				)
+				entry := exportAndParseSingle()
+				Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
+				Expect(entry.Name).To(Equal("transport:packet_received"))
+				ev := entry.Event
+				Expect(ev).To(HaveKey("raw"))
+				raw := ev["raw"].(map[string]interface{})
+				Expect(raw).To(HaveKeyWithValue("length", float64(789)))
+				Expect(raw).To(HaveKeyWithValue("payload_length", float64(789-shdr.Len())))
+				Expect(ev).To(HaveKey("header"))
+				hdr := ev["header"].(map[string]interface{})
+				Expect(hdr).To(HaveKeyWithValue("packet_type", "1RTT"))
+				Expect(hdr).To(HaveKeyWithValue("packet_number", float64(1337)))
+				Expect(hdr).To(HaveKeyWithValue("key_phase_bit", "0"))
+				Expect(ev).To(HaveKey("frames"))
+				Expect(ev["frames"].([]interface{})).To(HaveLen(2))
+			})
+
 			It("records a received Retry packet", func() {
 				tracer.ReceivedRetry(
 					&logging.Header{