qlog dropped packets

qlog/event.go

@@ -166,6 +166,22 @@ func (e eventPacketBuffered) MarshalJSONObject(enc *gojay.Encoder) {
 	enc.StringKey("trigger", "keys_unavailable")
 }
 
+type eventPacketDropped struct {
+	PacketType PacketType
+	PacketSize protocol.ByteCount
+	Trigger    PacketDropReason
+}
+
+func (e eventPacketDropped) Category() category { return categoryTransport }
+func (e eventPacketDropped) Name() string       { return "packet_dropped" }
+func (e eventPacketDropped) IsNil() bool        { return false }
+
+func (e eventPacketDropped) MarshalJSONObject(enc *gojay.Encoder) {
+	enc.StringKeyOmitEmpty("packet_type", e.PacketType.String())
+	enc.Uint64Key("packet_size", uint64(e.PacketSize))
+	enc.StringKey("trigger", e.Trigger.String())
+}
+
 func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 }
 
 type eventMetricsUpdated struct {

qlog/qlog.go

@@ -20,6 +20,7 @@ type Tracer interface {
 	ReceivedRetry(time.Time, *wire.Header)
 	ReceivedPacket(t time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []wire.Frame)
 	BufferedPacket(time.Time, PacketType)
+	DroppedPacket(time.Time, PacketType, protocol.ByteCount, PacketDropReason)
 	UpdatedMetrics(t time.Time, rttStats *congestion.RTTStats, cwnd protocol.ByteCount, bytesInFLight protocol.ByteCount, packetsInFlight int)
 	LostPacket(time.Time, protocol.EncryptionLevel, protocol.PacketNumber, PacketLossReason)
 	UpdatedPTOCount(time.Time, uint32)
@@ -146,6 +147,17 @@ func (t *tracer) BufferedPacket(time time.Time, packetType PacketType) {
 	})
 }
 
+func (t *tracer) DroppedPacket(time time.Time, packetType PacketType, size protocol.ByteCount, dropReason PacketDropReason) {
+	t.events = append(t.events, event{
+		Time: time,
+		eventDetails: eventPacketDropped{
+			PacketType: packetType,
+			PacketSize: size,
+			Trigger:    dropReason,
+		},
+	})
+}
+
 func (t *tracer) UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) {
 	t.events = append(t.events, event{
 		Time: time,

qlog/qlog_test.go

@@ -255,6 +255,19 @@ var _ = Describe("Tracer", func() {
 			Expect(ev).To(HaveKeyWithValue("trigger", "keys_unavailable"))
 		})
 
+		It("records dropped packets", func() {
+			now := time.Now()
+			tracer.DroppedPacket(now, PacketTypeHandshake, 1337, PacketDropPayloadDecryptError)
+			entry := exportAndParseSingle()
+			Expect(entry.Time).To(BeTemporally("~", now, time.Millisecond))
+			Expect(entry.Category).To(Equal("transport"))
+			Expect(entry.Name).To(Equal("packet_dropped"))
+			ev := entry.Event
+			Expect(ev).To(HaveKeyWithValue("packet_type", "handshake"))
+			Expect(ev).To(HaveKeyWithValue("packet_size", float64(1337)))
+			Expect(ev).To(HaveKeyWithValue("trigger", "payload_decrypt_error"))
+		})
+
 		It("records metrics updates", func() {
 			now := time.Now()
 			rttStats := congestion.NewRTTStats()

qlog/types.go

@@ -60,18 +60,20 @@ func (c category) String() string {
 type PacketType protocol.PacketType
 
 const (
-	// PacketTypeInitial: Initial packet
+	// PacketTypeInitial is the packet type of an Initial packet
 	PacketTypeInitial PacketType = iota
-	// PacketTypeHandshake: Handshake packet
+	// PacketTypeHandshake is the packet type of a Handshake packet
 	PacketTypeHandshake
-	// PacketTypeRetry: Retry packet
+	// PacketTypeRetry is the packet type of a Retry packet
 	PacketTypeRetry
-	// PacketType0RTT: 0-RTT packet
+	// PacketType0RTT is the packet type of a 0-RTT packet
 	PacketType0RTT
-	// PacketTypeVersionNegotiation: Version Negotiation packet
+	// PacketTypeVersionNegotiation is the packet type of a Version Negotiation packet
 	PacketTypeVersionNegotiation
-	// PacketType1RTT: 1-RTT packet
+	// PacketType1RTT is a 1-RTT packet
 	PacketType1RTT
+	// PacketTypeNotDetermined is the packet type when it could not be determined
+	PacketTypeNotDetermined
 )
 
 func (t PacketType) String() string {
@@ -88,6 +90,8 @@ func (t PacketType) String() string {
 		return "version_negotiation"
 	case PacketType1RTT:
 		return "1RTT"
+	case PacketTypeNotDetermined:
+		return ""
 	default:
 		panic("unknown packet type")
 	}
@@ -198,3 +202,43 @@ func (t keyUpdateTrigger) String() string {
 		panic("unknown key update trigger")
 	}
 }
+
+type PacketDropReason uint8
+
+const (
+	// PacketDropKeyUnavailable: when a packet is dropped because keys are unavailable
+	PacketDropKeyUnavailable PacketDropReason = iota
+	// PacketDropUnknownConnectionID: when a packet is dropped because the connection ID is unknown
+	PacketDropUnknownConnectionID
+	// PacketDropHeaderParseError: when a packet is dropped because header parsing failed
+	PacketDropHeaderParseError
+	// PacketDropPayloadDecryptError: when a packet is dropped because decrypting the payload failed
+	PacketDropPayloadDecryptError
+	// PacketDropProtocolViolation: when a packet is dropped due to a protocol violation
+	PacketDropProtocolViolation
+	// PacketDropDOSPrevention: when a packet is dropped to mitigate a DoS attack
+	PacketDropDOSPrevention
+	// PacketDropUnsupportedVersion: when a packet is dropped because the version is not supported
+	PacketDropUnsupportedVersion
+)
+
+func (r PacketDropReason) String() string {
+	switch r {
+	case PacketDropKeyUnavailable:
+		return "key_unavailable"
+	case PacketDropUnknownConnectionID:
+		return "unknown_connection_id"
+	case PacketDropHeaderParseError:
+		return "header_parse_error"
+	case PacketDropPayloadDecryptError:
+		return "payload_decrypt_error"
+	case PacketDropProtocolViolation:
+		return "protocol_violation"
+	case PacketDropDOSPrevention:
+		return "dos_prevention"
+	case PacketDropUnsupportedVersion:
+		return "unsupported_version"
+	default:
+		panic("unknown packet drop reason")
+	}
+}

qlog/types_test.go

@@ -21,6 +21,7 @@ var _ = Describe("Types", func() {
 		Expect(PacketType1RTT.String()).To(Equal("1RTT"))
 		Expect(PacketTypeRetry.String()).To(Equal("retry"))
 		Expect(PacketTypeVersionNegotiation.String()).To(Equal("version_negotiation"))
+		Expect(PacketTypeNotDetermined.String()).To(BeEmpty())
 	})
 
 	It("has a string representation for the key type", func() {
@@ -39,4 +40,14 @@ var _ = Describe("Types", func() {
 		Expect(keyUpdateRemote.String()).To(Equal("remote_update"))
 		Expect(keyUpdateLocal.String()).To(Equal("local_update"))
 	})
+
+	It("has a string representation for the packet drop reason", func() {
+		Expect(PacketDropKeyUnavailable.String()).To(Equal("key_unavailable"))
+		Expect(PacketDropUnknownConnectionID.String()).To(Equal("unknown_connection_id"))
+		Expect(PacketDropHeaderParseError.String()).To(Equal("header_parse_error"))
+		Expect(PacketDropPayloadDecryptError.String()).To(Equal("payload_decrypt_error"))
+		Expect(PacketDropProtocolViolation.String()).To(Equal("protocol_violation"))
+		Expect(PacketDropDOSPrevention.String()).To(Equal("dos_prevention"))
+		Expect(PacketDropUnsupportedVersion.String()).To(Equal("unsupported_version"))
+	})
 })

session.go

@@ -703,6 +703,9 @@ func (s *session) handlePacketImpl(rp *receivedPacket) bool {
 
 		hdr, packetData, rest, err := wire.ParsePacket(p.data, s.srcConnIDLen)
 		if err != nil {
+			if s.qlogger != nil {
+				s.qlogger.DroppedPacket(p.rcvTime, qlog.PacketTypeNotDetermined, protocol.ByteCount(len(data)), qlog.PacketDropHeaderParseError)
+			}
 			s.logger.Debugf("error parsing packet: %s", err)
 			break
 		}
@@ -761,6 +764,9 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool /
 	if err != nil {
 		switch err {
 		case handshake.ErrKeysDropped:
+			if s.qlogger != nil {
+				s.qlogger.DroppedPacket(p.rcvTime, qlog.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), qlog.PacketDropKeyUnavailable)
+			}
 			s.logger.Debugf("Dropping %s packet (%d bytes) because we already dropped the keys.", hdr.PacketType(), len(p.data))
 		case handshake.ErrKeysNotYetAvailable:
 			// Sealer for this encryption level not yet available.
@@ -772,6 +778,9 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool /
 		default:
 			// This might be a packet injected by an attacker.
 			// Drop it.
+			if s.qlogger != nil {
+				s.qlogger.DroppedPacket(p.rcvTime, qlog.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), qlog.PacketDropPayloadDecryptError)
+			}
 			s.logger.Debugf("Dropping %s packet (%d bytes) that could not be unpacked. Error: %s", hdr.PacketType(), len(p.data), err)
 		}
 		return false
@@ -1500,6 +1509,9 @@ func (s *session) scheduleSending() {
 
 func (s *session) tryQueueingUndecryptablePacket(p *receivedPacket, hdr *wire.Header) {
 	if len(s.undecryptablePackets)+1 > protocol.MaxUndecryptablePackets {
+		if s.qlogger != nil {
+			s.qlogger.DroppedPacket(p.rcvTime, qlog.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), qlog.PacketDropDOSPrevention)
+		}
 		s.logger.Infof("Dropping undecryptable packet (%d bytes). Undecryptable packet queue full.", len(p.data))
 		return
 	}