diff --git a/internal/ackhandler/sent_packet_handler.go b/internal/ackhandler/sent_packet_handler.go index c8f346153..1bb568ede 100644 --- a/internal/ackhandler/sent_packet_handler.go +++ b/internal/ackhandler/sent_packet_handler.go @@ -409,8 +409,16 @@ func (h *sentPacketHandler) detectLostPackets( return false, nil } - if packet.SendTime.Before(lostSendTime) || pnSpace.largestAcked >= packet.PacketNumber+packetThreshold { + if packet.SendTime.Before(lostSendTime) { lostPackets = append(lostPackets, packet) + if h.qlogger != nil { + h.qlogger.LostPacket(now, packet.EncryptionLevel, packet.PacketNumber, qlog.PacketLossTimeThreshold) + } + } else if pnSpace.largestAcked >= packet.PacketNumber+packetThreshold { + lostPackets = append(lostPackets, packet) + if h.qlogger != nil { + h.qlogger.LostPacket(now, packet.EncryptionLevel, packet.PacketNumber, qlog.PacketLossReorderingThreshold) + } } else if pnSpace.lossTime.IsZero() { // Note: This conditional is only entered once per call lossTime := packet.SendTime.Add(lossDelay) diff --git a/qlog/event.go b/qlog/event.go index d0a8cf63c..41893c957 100644 --- a/qlog/event.go +++ b/qlog/event.go @@ -126,3 +126,19 @@ func (e eventMetricsUpdated) MarshalJSONObject(enc *gojay.Encoder) { enc.Uint64Key("bytes_in_flight", uint64(e.BytesInFlight)) enc.Uint64KeyOmitEmpty("packets_in_flight", uint64(e.PacketsInFlight)) } + +type eventPacketLost struct { + PacketType packetType + PacketNumber protocol.PacketNumber + Trigger PacketLossReason +} + +func (e eventPacketLost) Category() category { return categoryRecovery } +func (e eventPacketLost) Name() string { return "packet_lost" } +func (e eventPacketLost) IsNil() bool { return false } + +func (e eventPacketLost) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_type", e.PacketType.String()) + enc.StringKey("packet_number", toString(int64(e.PacketNumber))) + enc.StringKey("trigger", e.Trigger.String()) +} diff --git a/qlog/packet_header.go b/qlog/packet_header.go index f749143e0..73e0c8d25 100644 --- a/qlog/packet_header.go +++ b/qlog/packet_header.go @@ -7,7 +7,7 @@ import ( "github.com/lucas-clemente/quic-go/internal/wire" ) -func getPacketType(hdr *wire.ExtendedHeader) packetType { +func getPacketTypeFromHeader(hdr *wire.ExtendedHeader) packetType { if !hdr.IsLongHeader { return packetType1RTT } @@ -28,6 +28,21 @@ func getPacketType(hdr *wire.ExtendedHeader) packetType { } } +func getPacketTypeFromEncryptionLevel(encLevel protocol.EncryptionLevel) packetType { + switch encLevel { + case protocol.EncryptionInitial: + return packetTypeInitial + case protocol.EncryptionHandshake: + return packetTypeHandshake + case protocol.Encryption0RTT: + return packetType0RTT + case protocol.Encryption1RTT: + return packetType1RTT + default: + panic("unknown encryption level") + } +} + func transformHeader(hdr *wire.Header) *packetHeader { return &packetHeader{ PayloadLength: hdr.Length, diff --git a/qlog/packet_header_test.go b/qlog/packet_header_test.go index a91aa48a4..1ed42ba42 100644 --- a/qlog/packet_header_test.go +++ b/qlog/packet_header_test.go @@ -14,9 +14,16 @@ import ( ) var _ = Describe("Packet Header", func() { - Context("determining the packet type", func() { + It("determines the packet type from the encryption level", func() { + Expect(getPacketTypeFromEncryptionLevel(protocol.EncryptionInitial)).To(Equal(packetTypeInitial)) + Expect(getPacketTypeFromEncryptionLevel(protocol.EncryptionHandshake)).To(Equal(packetTypeHandshake)) + Expect(getPacketTypeFromEncryptionLevel(protocol.Encryption0RTT)).To(Equal(packetType0RTT)) + Expect(getPacketTypeFromEncryptionLevel(protocol.Encryption1RTT)).To(Equal(packetType1RTT)) + }) + + Context("determining the packet type from the header", func() { It("recognizes Initial packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketTypeInitial, @@ -26,7 +33,7 @@ var _ = Describe("Packet Header", func() { }) It("recognizes Handshake packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketTypeHandshake, @@ -36,7 +43,7 @@ var _ = Describe("Packet Header", func() { }) It("recognizes Retry packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketTypeRetry, @@ -46,7 +53,7 @@ var _ = Describe("Packet Header", func() { }) It("recognizes 0-RTT packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketType0RTT, @@ -56,13 +63,13 @@ var _ = Describe("Packet Header", func() { }) It("recognizes Version Negotiation packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{IsLongHeader: true}, })).To(Equal(packetTypeVersionNegotiation)) }) It("recognizes 1-RTT packets", func() { - Expect(getPacketType(&wire.ExtendedHeader{ + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ Header: wire.Header{}, })).To(Equal(packetType1RTT)) }) diff --git a/qlog/qlog.go b/qlog/qlog.go index 93ed659cf..01c6b23d7 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -18,6 +18,7 @@ type Tracer interface { ReceivedRetry(time.Time, *wire.Header) ReceivedPacket(time.Time, *wire.ExtendedHeader, []wire.Frame) UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, cwnd protocol.ByteCount, bytesInFLight protocol.ByteCount, packetsInFlight int) + LostPacket(time.Time, protocol.EncryptionLevel, protocol.PacketNumber, PacketLossReason) } type tracer struct { @@ -74,7 +75,7 @@ func (t *tracer) SentPacket(time time.Time, hdr *wire.ExtendedHeader, ack *wire. t.events = append(t.events, event{ Time: time, eventDetails: eventPacketSent{ - PacketType: getPacketType(hdr), + PacketType: getPacketTypeFromHeader(hdr), Header: *transformExtendedHeader(hdr), Frames: fs, }, @@ -89,7 +90,7 @@ func (t *tracer) ReceivedPacket(time time.Time, hdr *wire.ExtendedHeader, frames t.events = append(t.events, event{ Time: time, eventDetails: eventPacketReceived{ - PacketType: getPacketType(hdr), + PacketType: getPacketTypeFromHeader(hdr), Header: *transformExtendedHeader(hdr), Frames: fs, }, @@ -119,3 +120,14 @@ func (t *tracer) UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, c }, }) } + +func (t *tracer) LostPacket(time time.Time, encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason PacketLossReason) { + t.events = append(t.events, event{ + Time: time, + eventDetails: eventPacketLost{ + PacketType: getPacketTypeFromEncryptionLevel(encLevel), + PacketNumber: pn, + Trigger: lossReason, + }, + }) +} diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index a3276e7a2..62f872ffd 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -215,5 +215,17 @@ var _ = Describe("Tracer", func() { Expect(ev).To(HaveKeyWithValue("bytes_in_flight", float64(1234))) Expect(ev).To(HaveKeyWithValue("packets_in_flight", float64(42))) }) + + It("records lost packets", func() { + now := time.Now() + tracer.LostPacket(now, protocol.EncryptionHandshake, 42, PacketLossReorderingThreshold) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("recovery")) + Expect(eventName).To(Equal("packet_lost")) + Expect(ev).To(HaveKeyWithValue("packet_type", "handshake")) + Expect(ev).To(HaveKeyWithValue("packet_number", "42")) + Expect(ev).To(HaveKeyWithValue("trigger", "reordering_threshold")) + }) }) }) diff --git a/qlog/types.go b/qlog/types.go index 5af5ba8ef..711c41715 100644 --- a/qlog/types.go +++ b/qlog/types.go @@ -90,3 +90,23 @@ func (t packetType) String() string { panic("unknown packet type") } } + +type PacketLossReason uint8 + +const ( + // PacketLossReorderingThreshold: when a packet is deemed lost due to reordering threshold + PacketLossReorderingThreshold PacketLossReason = iota + // PacketLossTimeThreshold: when a packet is deemed lost due to time threshold + PacketLossTimeThreshold +) + +func (r PacketLossReason) String() string { + switch r { + case PacketLossReorderingThreshold: + return "reordering_threshold" + case PacketLossTimeThreshold: + return "time_threshold" + default: + panic("unknown loss reason") + } +}