diff --git a/qlog/event.go b/qlog/event.go index 92a70095..3d56f610 100644 --- a/qlog/event.go +++ b/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 { diff --git a/qlog/qlog.go b/qlog/qlog.go index 0aa7ae98..4abbc960 100644 --- a/qlog/qlog.go +++ b/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, diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index d9f1f646..d1966571 100644 --- a/qlog/qlog_test.go +++ b/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() diff --git a/qlog/types.go b/qlog/types.go index 273f4134..cd6e95b6 100644 --- a/qlog/types.go +++ b/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") + } +} diff --git a/qlog/types_test.go b/qlog/types_test.go index 42f289af..e349ffb2 100644 --- a/qlog/types_test.go +++ b/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")) + }) }) diff --git a/session.go b/session.go index 3bde1da7..44fd133d 100644 --- a/session.go +++ b/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 }