From ad63e2a40af01c377cb02c5142111d99141a30bf Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Fri, 1 Sep 2023 11:47:05 +0700 Subject: [PATCH] trace and qlog the ECN marking on sent and received packets --- connection.go | 10 +-- connection_test.go | 70 +++++++++++---------- integrationtests/self/key_update_test.go | 6 +- integrationtests/self/self_suite_test.go | 8 ++- internal/mocks/logging/connection_tracer.go | 32 +++++----- logging/interface.go | 23 +++++-- logging/mock_connection_tracer_test.go | 32 +++++----- logging/multiplex.go | 16 ++--- logging/multiplex_test.go | 24 +++---- logging/null_tracer.go | 26 ++++---- qlog/event.go | 8 +++ qlog/qlog.go | 43 +++++++++---- qlog/qlog_test.go | 8 +++ qlog/types.go | 18 ++++++ qlog/types_test.go | 8 +++ 15 files changed, 212 insertions(+), 120 deletions(-) diff --git a/connection.go b/connection.go index d4e44be6..fdd056f1 100644 --- a/connection.go +++ b/connection.go @@ -907,6 +907,7 @@ func (s *connection) handleShortHeaderPacket(p receivedPacket, destConnID protoc KeyPhase: keyPhase, }, p.Size(), + p.ecn, frames, ) } @@ -1192,7 +1193,7 @@ func (s *connection) handleUnpackedLongHeaderPacket( var log func([]logging.Frame) if s.tracer != nil { log = func(frames []logging.Frame) { - s.tracer.ReceivedLongHeaderPacket(packet.hdr, packetSize, frames) + s.tracer.ReceivedLongHeaderPacket(packet.hdr, packetSize, ecn, frames) } } isAckEliciting, err := s.handleFrames(packet.data, packet.hdr.DestConnectionID, packet.encryptionLevel, log) @@ -2112,7 +2113,7 @@ func (s *connection) sendConnectionClose(e error) ([]byte, error) { return packet.buffer.Data, s.conn.Write(packet.buffer.Data, 0, ecn) } -func (s *connection) logLongHeaderPacket(p *longHeaderPacket) { +func (s *connection) logLongHeaderPacket(p *longHeaderPacket, ecn protocol.ECN) { // quic-go logging if s.logger.Debug() { p.header.Log(s.logger) @@ -2140,7 +2141,7 @@ func (s *connection) logLongHeaderPacket(p *longHeaderPacket) { if p.ack != nil { ack = logutils.ConvertAckFrame(p.ack) } - s.tracer.SentLongHeaderPacket(p.header, p.length, ack, frames) + s.tracer.SentLongHeaderPacket(p.header, p.length, ecn, ack, frames) } } @@ -2194,6 +2195,7 @@ func (s *connection) logShortHeaderPacket( KeyPhase: kp, }, size, + ecn, ack, fs, ) @@ -2226,7 +2228,7 @@ func (s *connection) logCoalescedPacket(packet *coalescedPacket, ecn protocol.EC } } for _, p := range packet.longHdrPackets { - s.logLongHeaderPacket(p) + s.logLongHeaderPacket(p, ecn) } if p := packet.shortHdrPacket; p != nil { s.logShortHeaderPacket(p.DestConnID, p.Ack, p.Frames, p.StreamFrames, p.PacketNumber, p.PacketNumberLen, p.KeyPhase, ecn, p.Length, true) diff --git a/connection_test.go b/connection_test.go index c4e067af..4fe53910 100644 --- a/connection_test.go +++ b/connection_test.go @@ -590,7 +590,7 @@ var _ = Describe("Connection", func() { return 3, protocol.PacketNumberLen2, protocol.KeyPhaseOne, b, nil }) gomock.InOrder( - tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()), + tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()), tracer.EXPECT().ClosedConnection(gomock.Any()), tracer.EXPECT().Close(), ) @@ -617,7 +617,7 @@ var _ = Describe("Connection", func() { sph.EXPECT().SendMode(gomock.Any()).Return(ackhandler.SendAny).AnyTimes() // only expect a single SentPacket() call sph.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() streamManager.EXPECT().CloseWithError(gomock.Any()) @@ -778,7 +778,7 @@ var _ = Describe("Connection", func() { conn.receivedPacketHandler = rph packet.rcvTime = rcvTime tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), []logging.Frame{}) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), logging.ECNCE, []logging.Frame{}) Expect(conn.handlePacketImpl(packet)).To(BeTrue()) }) @@ -796,7 +796,12 @@ var _ = Describe("Connection", func() { ) conn.receivedPacketHandler = rph packet.rcvTime = rcvTime - tracer.EXPECT().ReceivedShortHeaderPacket(&logging.ShortHeader{PacketNumber: 0x1337, PacketNumberLen: 2, KeyPhase: protocol.KeyPhaseZero}, protocol.ByteCount(len(packet.data)), []logging.Frame{&logging.PingFrame{}}) + tracer.EXPECT().ReceivedShortHeaderPacket( + &logging.ShortHeader{PacketNumber: 0x1337, PacketNumberLen: 2, KeyPhase: protocol.KeyPhaseZero}, + protocol.ByteCount(len(packet.data)), + logging.ECT1, + []logging.Frame{&logging.PingFrame{}}, + ) Expect(conn.handlePacketImpl(packet)).To(BeTrue()) }) @@ -850,8 +855,7 @@ var _ = Describe("Connection", func() { pn++ return pn, protocol.PacketNumberLen2, protocol.KeyPhaseZero, []byte{0} /* PADDING frame */, nil }).Times(3) - tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *logging.ShortHeader, _ protocol.ByteCount, _ []logging.Frame) { - }).Times(3) + tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Times(3) packer.EXPECT().PackCoalescedPacket(false, gomock.Any(), conn.version) // only expect a single call for i := 0; i < 3; i++ { @@ -886,8 +890,7 @@ var _ = Describe("Connection", func() { pn++ return pn, protocol.PacketNumberLen4, protocol.KeyPhaseZero, []byte{0} /* PADDING frame */, nil }).Times(3) - tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *logging.ShortHeader, _ protocol.ByteCount, _ []logging.Frame) { - }).Times(3) + tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Times(3) packer.EXPECT().PackCoalescedPacket(false, gomock.Any(), conn.version).Times(3) for i := 0; i < 3; i++ { @@ -1021,7 +1024,7 @@ var _ = Describe("Connection", func() { }, nil) p1 := getLongHeaderPacket(hdr1, nil) tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(p1.data)), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(p1.data)), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(p1)).To(BeTrue()) // The next packet has to be ignored, since the source connection ID doesn't match. p2 := getLongHeaderPacket(hdr2, nil) @@ -1054,7 +1057,7 @@ var _ = Describe("Connection", func() { unpacker.EXPECT().UnpackShortHeader(gomock.Any(), gomock.Any()).Return(protocol.PacketNumber(10), protocol.PacketNumberLen2, protocol.KeyPhaseZero, []byte{0} /* one PADDING frame */, nil) packet := getShortHeaderPacket(srcConnID, 0x42, nil) packet.remoteAddr = &net.IPAddr{IP: net.IPv4(192, 168, 0, 100)} - tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) + tracer.EXPECT().ReceivedShortHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(packet)).To(BeTrue()) }) }) @@ -1094,12 +1097,13 @@ var _ = Describe("Connection", func() { }) cryptoSetup.EXPECT().DiscardInitialKeys() tracer.EXPECT().DroppedEncryptionLevel(protocol.EncryptionInitial) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(packet)).To(BeTrue()) }) It("handles coalesced packets", func() { hdrLen1, packet1 := getPacketWithLength(srcConnID, 456) + packet1.ecn = protocol.ECT1 unpacker.EXPECT().UnpackLongHeader(gomock.Any(), gomock.Any(), gomock.Any(), conn.version).DoAndReturn(func(_ *wire.Header, _ time.Time, data []byte, _ protocol.VersionNumber) (*unpackedPacket, error) { Expect(data).To(HaveLen(hdrLen1 + 456 - 3)) return &unpackedPacket{ @@ -1126,8 +1130,8 @@ var _ = Describe("Connection", func() { tracer.EXPECT().DroppedEncryptionLevel(protocol.EncryptionInitial).AnyTimes() cryptoSetup.EXPECT().DiscardInitialKeys().AnyTimes() gomock.InOrder( - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), logging.ECT1, gomock.Any()), + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), logging.ECT1, gomock.Any()), ) packet1.data = append(packet1.data, packet2.data...) Expect(conn.handlePacketImpl(packet1)).To(BeTrue()) @@ -1152,7 +1156,7 @@ var _ = Describe("Connection", func() { cryptoSetup.EXPECT().DiscardInitialKeys().AnyTimes() gomock.InOrder( tracer.EXPECT().BufferedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data))), - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any(), gomock.Any()), ) packet1.data = append(packet1.data, packet2.data...) Expect(conn.handlePacketImpl(packet1)).To(BeTrue()) @@ -1178,7 +1182,7 @@ var _ = Describe("Connection", func() { cryptoSetup.EXPECT().DiscardInitialKeys().AnyTimes() // don't EXPECT any more calls to unpacker.UnpackLongHeader() gomock.InOrder( - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any(), gomock.Any()), tracer.EXPECT().DroppedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), logging.PacketDropUnknownConnectionID), ) packet1.data = append(packet1.data, packet2.data...) @@ -1253,7 +1257,7 @@ var _ = Describe("Connection", func() { PacketNumber: p.PacketNumber, PacketNumberLen: p.PacketNumberLen, KeyPhase: p.KeyPhase, - }, gomock.Any(), nil, []logging.Frame{}) + }, gomock.Any(), gomock.Any(), nil, []logging.Frame{}) conn.scheduleSending() Eventually(sent).Should(BeClosed()) }) @@ -1297,7 +1301,7 @@ var _ = Describe("Connection", func() { runConn() sent := make(chan struct{}) sender.EXPECT().Send(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(*packetBuffer, uint16, protocol.ECN) { close(sent) }) - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), nil, []logging.Frame{}) + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), nil, []logging.Frame{}) conn.scheduleSending() Eventually(sent).Should(BeClosed()) frames, _ := conn.framer.AppendControlFrames(nil, 1000, protocol.Version1) @@ -1350,9 +1354,9 @@ var _ = Describe("Connection", func() { sent := make(chan struct{}) sender.EXPECT().Send(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(*packetBuffer, uint16, protocol.ECN) { close(sent) }) if enc == protocol.Encryption1RTT { - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), p.shortHdrPacket.Length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), p.shortHdrPacket.Length, gomock.Any(), gomock.Any(), gomock.Any()) } else { - tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), p.longHdrPackets[0].length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), p.longHdrPackets[0].length, gomock.Any(), gomock.Any(), gomock.Any()) } conn.scheduleSending() Eventually(sent).Should(BeClosed()) @@ -1363,7 +1367,7 @@ var _ = Describe("Connection", func() { sph.EXPECT().TimeUntilSend().AnyTimes() sph.EXPECT().SendMode(gomock.Any()).Return(sendMode) sph.EXPECT().SendMode(gomock.Any()).Return(ackhandler.SendNone) - sph.EXPECT().ECNMode(gomock.Any()) + sph.EXPECT().ECNMode(gomock.Any()).Return(protocol.ECT0) sph.EXPECT().QueueProbePacket(encLevel).Return(false) p := getCoalescedPacket(123, enc != protocol.Encryption1RTT) packer.EXPECT().MaybePackProbePacket(encLevel, gomock.Any(), conn.version).Return(p, nil) @@ -1372,9 +1376,9 @@ var _ = Describe("Connection", func() { sent := make(chan struct{}) sender.EXPECT().Send(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(*packetBuffer, uint16, protocol.ECN) { close(sent) }) if enc == protocol.Encryption1RTT { - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), p.shortHdrPacket.Length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), p.shortHdrPacket.Length, logging.ECT0, gomock.Any(), gomock.Any()) } else { - tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), p.longHdrPackets[0].length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), p.longHdrPackets[0].length, logging.ECT0, gomock.Any(), gomock.Any()) } conn.scheduleSending() Eventually(sent).Should(BeClosed()) @@ -1393,7 +1397,7 @@ var _ = Describe("Connection", func() { ) BeforeEach(func() { - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() sph = mockackhandler.NewMockSentPacketHandler(mockCtrl) sph.EXPECT().GetLossDetectionTimeout().AnyTimes() conn.handshakeConfirmed = true @@ -1792,7 +1796,7 @@ var _ = Describe("Connection", func() { // only EXPECT calls after scheduleSending is called written := make(chan struct{}) sender.EXPECT().Send(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(*packetBuffer, uint16, protocol.ECN) { close(written) }) - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() conn.scheduleSending() Eventually(written).Should(BeClosed()) }) @@ -1814,7 +1818,7 @@ var _ = Describe("Connection", func() { written := make(chan struct{}) sender.EXPECT().Send(gomock.Any(), gomock.Any(), gomock.Any()).Do(func(*packetBuffer, uint16, protocol.ECN) { close(written) }) - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().StartHandshake().MaxTimes(1) @@ -1862,10 +1866,10 @@ var _ = Describe("Connection", func() { sph.EXPECT().SentPacket(gomock.Any(), protocol.PacketNumber(37), gomock.Any(), gomock.Any(), gomock.Any(), protocol.EncryptionHandshake, protocol.ECT1, protocol.ByteCount(1234), gomock.Any()), ) gomock.InOrder( - tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []logging.Frame) { + tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ logging.ECN, _ *wire.AckFrame, _ []logging.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeInitial)) }), - tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []logging.Frame) { + tracer.EXPECT().SentLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ logging.ECN, _ *wire.AckFrame, _ []logging.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeHandshake)) }), ) @@ -1974,7 +1978,7 @@ var _ = Describe("Connection", func() { sph.EXPECT().SetHandshakeConfirmed() sph.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) mconn.EXPECT().Write(gomock.Any(), gomock.Any(), gomock.Any()) - tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().SentShortHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) conn.sentPacketHandler = sph done := make(chan struct{}) connRunner.EXPECT().Retire(clientDestConnID) @@ -2549,7 +2553,7 @@ var _ = Describe("Client Connection", func() { }, PacketNumberLen: protocol.PacketNumberLen2, }, []byte("foobar")) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), p.Size(), []logging.Frame{}) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), p.Size(), gomock.Any(), []logging.Frame{}) Expect(conn.handlePacketImpl(p)).To(BeTrue()) go func() { defer GinkgoRecover() @@ -2593,7 +2597,7 @@ var _ = Describe("Client Connection", func() { DestConnectionID: srcConnID, SrcConnectionID: destConnID, } - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) Expect(conn.handleLongHeaderPacket(receivedPacket{buffer: getPacketBuffer()}, hdr)).To(BeTrue()) }) @@ -3105,7 +3109,7 @@ var _ = Describe("Client Connection", func() { hdr: hdr1, data: []byte{0}, // one PADDING frame }, nil) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(getPacket(hdr1, nil))).To(BeTrue()) // The next packet has to be ignored, since the source connection ID doesn't match. tracer.EXPECT().DroppedPacket(gomock.Any(), gomock.Any(), gomock.Any()) @@ -3132,7 +3136,7 @@ var _ = Describe("Client Connection", func() { It("fails on Initial-level ACK for unsent packet", func() { ack := &wire.AckFrame{AckRanges: []wire.AckRange{{Smallest: 2, Largest: 2}}} initialPacket := testutils.ComposeInitialPacket(destConnID, srcConnID, conn.version, destConnID, []wire.Frame{ack}) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(wrapPacket(initialPacket))).To(BeFalse()) }) @@ -3144,7 +3148,7 @@ var _ = Describe("Client Connection", func() { ReasonPhrase: "mitm attacker", } initialPacket := testutils.ComposeInitialPacket(destConnID, srcConnID, conn.version, destConnID, []wire.Frame{connCloseFrame}) - tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) Expect(conn.handlePacketImpl(wrapPacket(initialPacket))).To(BeTrue()) }) diff --git a/integrationtests/self/key_update_test.go b/integrationtests/self/key_update_test.go index c24bef27..7975a77b 100644 --- a/integrationtests/self/key_update_test.go +++ b/integrationtests/self/key_update_test.go @@ -42,11 +42,13 @@ type keyUpdateConnTracer struct { logging.NullConnectionTracer } -func (t *keyUpdateConnTracer) SentShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, _ *logging.AckFrame, _ []logging.Frame) { +var _ logging.ConnectionTracer = &keyUpdateConnTracer{} + +func (t *keyUpdateConnTracer) SentShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, _ logging.ECN, _ *logging.AckFrame, _ []logging.Frame) { sentHeaders = append(sentHeaders, hdr) } -func (t *keyUpdateConnTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, size logging.ByteCount, frames []logging.Frame) { +func (t *keyUpdateConnTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, _ logging.ECN, _ []logging.Frame) { receivedHeaders = append(receivedHeaders, hdr) } diff --git a/integrationtests/self/self_suite_test.go b/integrationtests/self/self_suite_test.go index 4b7ee5ef..6396d3a7 100644 --- a/integrationtests/self/self_suite_test.go +++ b/integrationtests/self/self_suite_test.go @@ -265,19 +265,21 @@ type packetTracer struct { rcvdLongHdr []packet } +var _ logging.ConnectionTracer = &packetTracer{} + func newPacketTracer() *packetTracer { return &packetTracer{closed: make(chan struct{})} } -func (t *packetTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, _ logging.ByteCount, frames []logging.Frame) { +func (t *packetTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, _ logging.ByteCount, _ logging.ECN, frames []logging.Frame) { t.rcvdLongHdr = append(t.rcvdLongHdr, packet{time: time.Now(), hdr: hdr, frames: frames}) } -func (t *packetTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, frames []logging.Frame) { +func (t *packetTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, _ logging.ECN, frames []logging.Frame) { t.rcvdShortHdr = append(t.rcvdShortHdr, shortHeaderPacket{time: time.Now(), hdr: hdr, frames: frames}) } -func (t *packetTracer) SentShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, ack *wire.AckFrame, frames []logging.Frame) { +func (t *packetTracer) SentShortHeaderPacket(hdr *logging.ShortHeader, _ logging.ByteCount, _ logging.ECN, ack *wire.AckFrame, frames []logging.Frame) { if ack != nil { frames = append(frames, ack) } diff --git a/internal/mocks/logging/connection_tracer.go b/internal/mocks/logging/connection_tracer.go index 1ca0895d..ff180062 100644 --- a/internal/mocks/logging/connection_tracer.go +++ b/internal/mocks/logging/connection_tracer.go @@ -184,15 +184,15 @@ func (mr *MockConnectionTracerMockRecorder) NegotiatedVersion(arg0, arg1, arg2 i } // ReceivedLongHeaderPacket mocks base method. -func (m *MockConnectionTracer) ReceivedLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 []logging.Frame) { +func (m *MockConnectionTracer) ReceivedLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 []logging.Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "ReceivedLongHeaderPacket", arg0, arg1, arg2) + m.ctrl.Call(m, "ReceivedLongHeaderPacket", arg0, arg1, arg2, arg3) } // ReceivedLongHeaderPacket indicates an expected call of ReceivedLongHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) ReceivedLongHeaderPacket(arg0, arg1, arg2 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) ReceivedLongHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedLongHeaderPacket), arg0, arg1, arg2) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedLongHeaderPacket), arg0, arg1, arg2, arg3) } // ReceivedRetry mocks base method. @@ -208,15 +208,15 @@ func (mr *MockConnectionTracerMockRecorder) ReceivedRetry(arg0 interface{}) *gom } // ReceivedShortHeaderPacket mocks base method. -func (m *MockConnectionTracer) ReceivedShortHeaderPacket(arg0 *logging.ShortHeader, arg1 protocol.ByteCount, arg2 []logging.Frame) { +func (m *MockConnectionTracer) ReceivedShortHeaderPacket(arg0 *logging.ShortHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 []logging.Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "ReceivedShortHeaderPacket", arg0, arg1, arg2) + m.ctrl.Call(m, "ReceivedShortHeaderPacket", arg0, arg1, arg2, arg3) } // ReceivedShortHeaderPacket indicates an expected call of ReceivedShortHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) ReceivedShortHeaderPacket(arg0, arg1, arg2 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) ReceivedShortHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedShortHeaderPacket), arg0, arg1, arg2) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedShortHeaderPacket), arg0, arg1, arg2, arg3) } // ReceivedTransportParameters mocks base method. @@ -256,27 +256,27 @@ func (mr *MockConnectionTracerMockRecorder) RestoredTransportParameters(arg0 int } // SentLongHeaderPacket mocks base method. -func (m *MockConnectionTracer) SentLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []logging.Frame) { +func (m *MockConnectionTracer) SentLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 *wire.AckFrame, arg4 []logging.Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "SentLongHeaderPacket", arg0, arg1, arg2, arg3) + m.ctrl.Call(m, "SentLongHeaderPacket", arg0, arg1, arg2, arg3, arg4) } // SentLongHeaderPacket indicates an expected call of SentLongHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) SentLongHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) SentLongHeaderPacket(arg0, arg1, arg2, arg3, arg4 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentLongHeaderPacket), arg0, arg1, arg2, arg3) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentLongHeaderPacket), arg0, arg1, arg2, arg3, arg4) } // SentShortHeaderPacket mocks base method. -func (m *MockConnectionTracer) SentShortHeaderPacket(arg0 *logging.ShortHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []logging.Frame) { +func (m *MockConnectionTracer) SentShortHeaderPacket(arg0 *logging.ShortHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 *wire.AckFrame, arg4 []logging.Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "SentShortHeaderPacket", arg0, arg1, arg2, arg3) + m.ctrl.Call(m, "SentShortHeaderPacket", arg0, arg1, arg2, arg3, arg4) } // SentShortHeaderPacket indicates an expected call of SentShortHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) SentShortHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) SentShortHeaderPacket(arg0, arg1, arg2, arg3, arg4 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentShortHeaderPacket), arg0, arg1, arg2, arg3) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentShortHeaderPacket), arg0, arg1, arg2, arg3, arg4) } // SentTransportParameters mocks base method. diff --git a/logging/interface.go b/logging/interface.go index 2ce8582e..a83fb507 100644 --- a/logging/interface.go +++ b/logging/interface.go @@ -15,6 +15,8 @@ import ( type ( // A ByteCount is used to count bytes. ByteCount = protocol.ByteCount + // ECN is the ECN value + ECN = protocol.ECN // A ConnectionID is a QUIC Connection ID. ConnectionID = protocol.ConnectionID // An ArbitraryLenConnectionID is a QUIC Connection ID that can be up to 255 bytes long. @@ -58,6 +60,19 @@ type ( RTTStats = utils.RTTStats ) +const ( + // ECNUnsupported means that no ECN value was set / received + ECNUnsupported = protocol.ECNUnsupported + // ECTNot is Not-ECT + ECTNot = protocol.ECNNon + // ECT0 is ECT(0) + ECT0 = protocol.ECT0 + // ECT1 is ECT(1) + ECT1 = protocol.ECT1 + // ECNCE is CE + ECNCE = protocol.ECNCE +) + const ( // KeyPhaseZero is key phase bit 0 KeyPhaseZero KeyPhaseBit = protocol.KeyPhaseZero @@ -113,12 +128,12 @@ type ConnectionTracer interface { SentTransportParameters(*TransportParameters) ReceivedTransportParameters(*TransportParameters) RestoredTransportParameters(parameters *TransportParameters) // for 0-RTT - SentLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, ack *AckFrame, frames []Frame) - SentShortHeaderPacket(hdr *ShortHeader, size ByteCount, ack *AckFrame, frames []Frame) + SentLongHeaderPacket(*ExtendedHeader, ByteCount, ECN, *AckFrame, []Frame) + SentShortHeaderPacket(*ShortHeader, ByteCount, ECN, *AckFrame, []Frame) ReceivedVersionNegotiationPacket(dest, src ArbitraryLenConnectionID, _ []VersionNumber) ReceivedRetry(*Header) - ReceivedLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, frames []Frame) - ReceivedShortHeaderPacket(hdr *ShortHeader, size ByteCount, frames []Frame) + ReceivedLongHeaderPacket(*ExtendedHeader, ByteCount, ECN, []Frame) + ReceivedShortHeaderPacket(*ShortHeader, ByteCount, ECN, []Frame) BufferedPacket(PacketType, ByteCount) DroppedPacket(PacketType, ByteCount, PacketDropReason) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int) diff --git a/logging/mock_connection_tracer_test.go b/logging/mock_connection_tracer_test.go index f4f7648a..f2b8cc8a 100644 --- a/logging/mock_connection_tracer_test.go +++ b/logging/mock_connection_tracer_test.go @@ -183,15 +183,15 @@ func (mr *MockConnectionTracerMockRecorder) NegotiatedVersion(arg0, arg1, arg2 i } // ReceivedLongHeaderPacket mocks base method. -func (m *MockConnectionTracer) ReceivedLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 []Frame) { +func (m *MockConnectionTracer) ReceivedLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 []Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "ReceivedLongHeaderPacket", arg0, arg1, arg2) + m.ctrl.Call(m, "ReceivedLongHeaderPacket", arg0, arg1, arg2, arg3) } // ReceivedLongHeaderPacket indicates an expected call of ReceivedLongHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) ReceivedLongHeaderPacket(arg0, arg1, arg2 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) ReceivedLongHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedLongHeaderPacket), arg0, arg1, arg2) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedLongHeaderPacket), arg0, arg1, arg2, arg3) } // ReceivedRetry mocks base method. @@ -207,15 +207,15 @@ func (mr *MockConnectionTracerMockRecorder) ReceivedRetry(arg0 interface{}) *gom } // ReceivedShortHeaderPacket mocks base method. -func (m *MockConnectionTracer) ReceivedShortHeaderPacket(arg0 *ShortHeader, arg1 protocol.ByteCount, arg2 []Frame) { +func (m *MockConnectionTracer) ReceivedShortHeaderPacket(arg0 *ShortHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 []Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "ReceivedShortHeaderPacket", arg0, arg1, arg2) + m.ctrl.Call(m, "ReceivedShortHeaderPacket", arg0, arg1, arg2, arg3) } // ReceivedShortHeaderPacket indicates an expected call of ReceivedShortHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) ReceivedShortHeaderPacket(arg0, arg1, arg2 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) ReceivedShortHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedShortHeaderPacket), arg0, arg1, arg2) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedShortHeaderPacket), arg0, arg1, arg2, arg3) } // ReceivedTransportParameters mocks base method. @@ -255,27 +255,27 @@ func (mr *MockConnectionTracerMockRecorder) RestoredTransportParameters(arg0 int } // SentLongHeaderPacket mocks base method. -func (m *MockConnectionTracer) SentLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []Frame) { +func (m *MockConnectionTracer) SentLongHeaderPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 *wire.AckFrame, arg4 []Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "SentLongHeaderPacket", arg0, arg1, arg2, arg3) + m.ctrl.Call(m, "SentLongHeaderPacket", arg0, arg1, arg2, arg3, arg4) } // SentLongHeaderPacket indicates an expected call of SentLongHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) SentLongHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) SentLongHeaderPacket(arg0, arg1, arg2, arg3, arg4 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentLongHeaderPacket), arg0, arg1, arg2, arg3) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentLongHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentLongHeaderPacket), arg0, arg1, arg2, arg3, arg4) } // SentShortHeaderPacket mocks base method. -func (m *MockConnectionTracer) SentShortHeaderPacket(arg0 *ShortHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []Frame) { +func (m *MockConnectionTracer) SentShortHeaderPacket(arg0 *ShortHeader, arg1 protocol.ByteCount, arg2 protocol.ECN, arg3 *wire.AckFrame, arg4 []Frame) { m.ctrl.T.Helper() - m.ctrl.Call(m, "SentShortHeaderPacket", arg0, arg1, arg2, arg3) + m.ctrl.Call(m, "SentShortHeaderPacket", arg0, arg1, arg2, arg3, arg4) } // SentShortHeaderPacket indicates an expected call of SentShortHeaderPacket. -func (mr *MockConnectionTracerMockRecorder) SentShortHeaderPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { +func (mr *MockConnectionTracerMockRecorder) SentShortHeaderPacket(arg0, arg1, arg2, arg3, arg4 interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentShortHeaderPacket), arg0, arg1, arg2, arg3) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentShortHeaderPacket", reflect.TypeOf((*MockConnectionTracer)(nil).SentShortHeaderPacket), arg0, arg1, arg2, arg3, arg4) } // SentTransportParameters mocks base method. diff --git a/logging/multiplex.go b/logging/multiplex.go index 672a5cdb..0aecc9c2 100644 --- a/logging/multiplex.go +++ b/logging/multiplex.go @@ -93,15 +93,15 @@ func (m *connTracerMultiplexer) RestoredTransportParameters(tp *TransportParamet } } -func (m *connTracerMultiplexer) SentLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, ack *AckFrame, frames []Frame) { +func (m *connTracerMultiplexer) SentLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, ecn ECN, ack *AckFrame, frames []Frame) { for _, t := range m.tracers { - t.SentLongHeaderPacket(hdr, size, ack, frames) + t.SentLongHeaderPacket(hdr, size, ecn, ack, frames) } } -func (m *connTracerMultiplexer) SentShortHeaderPacket(hdr *ShortHeader, size ByteCount, ack *AckFrame, frames []Frame) { +func (m *connTracerMultiplexer) SentShortHeaderPacket(hdr *ShortHeader, size ByteCount, ecn ECN, ack *AckFrame, frames []Frame) { for _, t := range m.tracers { - t.SentShortHeaderPacket(hdr, size, ack, frames) + t.SentShortHeaderPacket(hdr, size, ecn, ack, frames) } } @@ -117,15 +117,15 @@ func (m *connTracerMultiplexer) ReceivedRetry(hdr *Header) { } } -func (m *connTracerMultiplexer) ReceivedLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, frames []Frame) { +func (m *connTracerMultiplexer) ReceivedLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, ecn ECN, frames []Frame) { for _, t := range m.tracers { - t.ReceivedLongHeaderPacket(hdr, size, frames) + t.ReceivedLongHeaderPacket(hdr, size, ecn, frames) } } -func (m *connTracerMultiplexer) ReceivedShortHeaderPacket(hdr *ShortHeader, size ByteCount, frames []Frame) { +func (m *connTracerMultiplexer) ReceivedShortHeaderPacket(hdr *ShortHeader, size ByteCount, ecn ECN, frames []Frame) { for _, t := range m.tracers { - t.ReceivedShortHeaderPacket(hdr, size, frames) + t.ReceivedShortHeaderPacket(hdr, size, ecn, frames) } } diff --git a/logging/multiplex_test.go b/logging/multiplex_test.go index d2220499..572ced6a 100644 --- a/logging/multiplex_test.go +++ b/logging/multiplex_test.go @@ -119,18 +119,18 @@ var _ = Describe("Tracing", func() { hdr := &ExtendedHeader{Header: Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})}} ack := &AckFrame{AckRanges: []AckRange{{Smallest: 1, Largest: 10}}} ping := &PingFrame{} - tr1.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ack, []Frame{ping}) - tr2.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ack, []Frame{ping}) - tracer.SentLongHeaderPacket(hdr, 1337, ack, []Frame{ping}) + tr1.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ECTNot, ack, []Frame{ping}) + tr2.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ECTNot, ack, []Frame{ping}) + tracer.SentLongHeaderPacket(hdr, 1337, ECTNot, ack, []Frame{ping}) }) It("traces the SentShortHeaderPacket event", func() { hdr := &ShortHeader{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} ack := &AckFrame{AckRanges: []AckRange{{Smallest: 1, Largest: 10}}} ping := &PingFrame{} - tr1.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ack, []Frame{ping}) - tr2.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ack, []Frame{ping}) - tracer.SentShortHeaderPacket(hdr, 1337, ack, []Frame{ping}) + tr1.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ECNCE, ack, []Frame{ping}) + tr2.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ECNCE, ack, []Frame{ping}) + tracer.SentShortHeaderPacket(hdr, 1337, ECNCE, ack, []Frame{ping}) }) It("traces the ReceivedVersionNegotiationPacket event", func() { @@ -151,17 +151,17 @@ var _ = Describe("Tracing", func() { It("traces the ReceivedLongHeaderPacket event", func() { hdr := &ExtendedHeader{Header: Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})}} ping := &PingFrame{} - tr1.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), []Frame{ping}) - tr2.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), []Frame{ping}) - tracer.ReceivedLongHeaderPacket(hdr, 1337, []Frame{ping}) + tr1.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), ECT1, []Frame{ping}) + tr2.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), ECT1, []Frame{ping}) + tracer.ReceivedLongHeaderPacket(hdr, 1337, ECT1, []Frame{ping}) }) It("traces the ReceivedShortHeaderPacket event", func() { hdr := &ShortHeader{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} ping := &PingFrame{} - tr1.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), []Frame{ping}) - tr2.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), []Frame{ping}) - tracer.ReceivedShortHeaderPacket(hdr, 1337, []Frame{ping}) + tr1.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), ECT0, []Frame{ping}) + tr2.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), ECT0, []Frame{ping}) + tracer.ReceivedShortHeaderPacket(hdr, 1337, ECT0, []Frame{ping}) }) It("traces the BufferedPacket event", func() { diff --git a/logging/null_tracer.go b/logging/null_tracer.go index de970385..731039e3 100644 --- a/logging/null_tracer.go +++ b/logging/null_tracer.go @@ -27,19 +27,23 @@ func (n NullConnectionTracer) StartedConnection(local, remote net.Addr, srcConnI func (n NullConnectionTracer) NegotiatedVersion(chosen VersionNumber, clientVersions, serverVersions []VersionNumber) { } -func (n NullConnectionTracer) ClosedConnection(err error) {} -func (n NullConnectionTracer) SentTransportParameters(*TransportParameters) {} -func (n NullConnectionTracer) ReceivedTransportParameters(*TransportParameters) {} -func (n NullConnectionTracer) RestoredTransportParameters(*TransportParameters) {} -func (n NullConnectionTracer) SentLongHeaderPacket(*ExtendedHeader, ByteCount, *AckFrame, []Frame) {} -func (n NullConnectionTracer) SentShortHeaderPacket(*ShortHeader, ByteCount, *AckFrame, []Frame) {} +func (n NullConnectionTracer) ClosedConnection(err error) {} +func (n NullConnectionTracer) SentTransportParameters(*TransportParameters) {} +func (n NullConnectionTracer) ReceivedTransportParameters(*TransportParameters) {} +func (n NullConnectionTracer) RestoredTransportParameters(*TransportParameters) {} +func (n NullConnectionTracer) SentLongHeaderPacket(*ExtendedHeader, ByteCount, ECN, *AckFrame, []Frame) { +} + +func (n NullConnectionTracer) SentShortHeaderPacket(*ShortHeader, ByteCount, ECN, *AckFrame, []Frame) { +} + func (n NullConnectionTracer) ReceivedVersionNegotiationPacket(dest, src ArbitraryLenConnectionID, _ []VersionNumber) { } -func (n NullConnectionTracer) ReceivedRetry(*Header) {} -func (n NullConnectionTracer) ReceivedLongHeaderPacket(*ExtendedHeader, ByteCount, []Frame) {} -func (n NullConnectionTracer) ReceivedShortHeaderPacket(*ShortHeader, ByteCount, []Frame) {} -func (n NullConnectionTracer) BufferedPacket(PacketType, ByteCount) {} -func (n NullConnectionTracer) DroppedPacket(PacketType, ByteCount, PacketDropReason) {} +func (n NullConnectionTracer) ReceivedRetry(*Header) {} +func (n NullConnectionTracer) ReceivedLongHeaderPacket(*ExtendedHeader, ByteCount, ECN, []Frame) {} +func (n NullConnectionTracer) ReceivedShortHeaderPacket(*ShortHeader, ByteCount, ECN, []Frame) {} +func (n NullConnectionTracer) BufferedPacket(PacketType, ByteCount) {} +func (n NullConnectionTracer) DroppedPacket(PacketType, ByteCount, PacketDropReason) {} func (n NullConnectionTracer) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int) { } diff --git a/qlog/event.go b/qlog/event.go index 9dae7444..1a76df95 100644 --- a/qlog/event.go +++ b/qlog/event.go @@ -158,6 +158,7 @@ type eventPacketSent struct { PayloadLength logging.ByteCount Frames frames IsCoalesced bool + ECN logging.ECN Trigger string } @@ -172,6 +173,9 @@ func (e eventPacketSent) MarshalJSONObject(enc *gojay.Encoder) { enc.ObjectKey("raw", rawInfo{Length: e.Length, PayloadLength: e.PayloadLength}) enc.ArrayKeyOmitEmpty("frames", e.Frames) enc.BoolKeyOmitEmpty("is_coalesced", e.IsCoalesced) + if e.ECN != logging.ECNUnsupported { + enc.StringKey("ecn", ecn(e.ECN).String()) + } enc.StringKeyOmitEmpty("trigger", e.Trigger) } @@ -180,6 +184,7 @@ type eventPacketReceived struct { Length logging.ByteCount PayloadLength logging.ByteCount Frames frames + ECN logging.ECN IsCoalesced bool Trigger string } @@ -195,6 +200,9 @@ func (e eventPacketReceived) MarshalJSONObject(enc *gojay.Encoder) { enc.ObjectKey("raw", rawInfo{Length: e.Length, PayloadLength: e.PayloadLength}) enc.ArrayKeyOmitEmpty("frames", e.Frames) enc.BoolKeyOmitEmpty("is_coalesced", e.IsCoalesced) + if e.ECN != logging.ECNUnsupported { + enc.StringKey("ecn", ecn(e.ECN).String()) + } enc.StringKeyOmitEmpty("trigger", e.Trigger) } diff --git a/qlog/qlog.go b/qlog/qlog.go index 4c480e26..6d2ece07 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -253,15 +253,33 @@ func (t *connectionTracer) toTransportParameters(tp *wire.TransportParameters) * } } -func (t *connectionTracer) SentLongHeaderPacket(hdr *logging.ExtendedHeader, packetSize logging.ByteCount, ack *logging.AckFrame, frames []logging.Frame) { - t.sentPacket(*transformLongHeader(hdr), packetSize, hdr.Length, ack, frames) +func (t *connectionTracer) SentLongHeaderPacket( + hdr *logging.ExtendedHeader, + size logging.ByteCount, + ecn logging.ECN, + ack *logging.AckFrame, + frames []logging.Frame, +) { + t.sentPacket(*transformLongHeader(hdr), size, hdr.Length, ecn, ack, frames) } -func (t *connectionTracer) SentShortHeaderPacket(hdr *logging.ShortHeader, packetSize logging.ByteCount, ack *logging.AckFrame, frames []logging.Frame) { - t.sentPacket(*transformShortHeader(hdr), packetSize, 0, ack, frames) +func (t *connectionTracer) SentShortHeaderPacket( + hdr *logging.ShortHeader, + size logging.ByteCount, + ecn logging.ECN, + ack *logging.AckFrame, + frames []logging.Frame, +) { + t.sentPacket(*transformShortHeader(hdr), size, 0, ecn, ack, frames) } -func (t *connectionTracer) sentPacket(hdr gojay.MarshalerJSONObject, packetSize, payloadLen logging.ByteCount, ack *logging.AckFrame, frames []logging.Frame) { +func (t *connectionTracer) sentPacket( + hdr gojay.MarshalerJSONObject, + size, payloadLen logging.ByteCount, + ecn logging.ECN, + ack *logging.AckFrame, + frames []logging.Frame, +) { numFrames := len(frames) if ack != nil { numFrames++ @@ -276,14 +294,15 @@ func (t *connectionTracer) sentPacket(hdr gojay.MarshalerJSONObject, packetSize, t.mutex.Lock() t.recordEvent(time.Now(), &eventPacketSent{ Header: hdr, - Length: packetSize, + Length: size, PayloadLength: payloadLen, + ECN: ecn, Frames: fs, }) t.mutex.Unlock() } -func (t *connectionTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, packetSize logging.ByteCount, frames []logging.Frame) { +func (t *connectionTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) { fs := make([]frame, len(frames)) for i, f := range frames { fs[i] = frame{Frame: f} @@ -292,14 +311,15 @@ func (t *connectionTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, t.mutex.Lock() t.recordEvent(time.Now(), &eventPacketReceived{ Header: header, - Length: packetSize, + Length: size, PayloadLength: hdr.Length, + ECN: ecn, Frames: fs, }) t.mutex.Unlock() } -func (t *connectionTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, packetSize logging.ByteCount, frames []logging.Frame) { +func (t *connectionTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) { fs := make([]frame, len(frames)) for i, f := range frames { fs[i] = frame{Frame: f} @@ -308,8 +328,9 @@ func (t *connectionTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, p t.mutex.Lock() t.recordEvent(time.Now(), &eventPacketReceived{ Header: header, - Length: packetSize, - PayloadLength: packetSize - wire.ShortHeaderLen(hdr.DestConnectionID, hdr.PacketNumberLen), + Length: size, + PayloadLength: size - wire.ShortHeaderLen(hdr.DestConnectionID, hdr.PacketNumberLen), + ECN: ecn, Frames: fs, }) t.mutex.Unlock() diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index dc0d2dc1..d7634464 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -419,6 +419,7 @@ var _ = Describe("Tracing", func() { PacketNumber: 1337, }, 987, + logging.ECNCE, nil, []logging.Frame{ &logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, @@ -439,6 +440,7 @@ var _ = Describe("Tracing", func() { Expect(hdr).To(HaveKeyWithValue("packet_number", float64(1337))) Expect(hdr).To(HaveKeyWithValue("scid", "04030201")) Expect(ev).To(HaveKey("frames")) + Expect(ev).To(HaveKeyWithValue("ecn", "CE")) frames := ev["frames"].([]interface{}) Expect(frames).To(HaveLen(2)) Expect(frames[0].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "max_stream_data")) @@ -452,6 +454,7 @@ var _ = Describe("Tracing", func() { PacketNumber: 1337, }, 123, + logging.ECNUnsupported, &logging.AckFrame{AckRanges: []logging.AckRange{{Smallest: 1, Largest: 10}}}, []logging.Frame{&logging.MaxDataFrame{MaximumData: 987}}, ) @@ -461,6 +464,7 @@ var _ = Describe("Tracing", func() { Expect(raw).To(HaveKeyWithValue("length", float64(123))) Expect(raw).ToNot(HaveKey("payload_length")) Expect(ev).To(HaveKey("header")) + Expect(ev).ToNot(HaveKey("ecn")) hdr := ev["header"].(map[string]interface{}) Expect(hdr).To(HaveKeyWithValue("packet_type", "1RTT")) Expect(hdr).To(HaveKeyWithValue("packet_number", float64(1337))) @@ -485,6 +489,7 @@ var _ = Describe("Tracing", func() { PacketNumber: 1337, }, 789, + logging.ECT0, []logging.Frame{ &logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, &logging.StreamFrame{StreamID: 123, Offset: 1234, Length: 6, Fin: true}, @@ -498,6 +503,7 @@ var _ = Describe("Tracing", func() { raw := ev["raw"].(map[string]interface{}) Expect(raw).To(HaveKeyWithValue("length", float64(789))) Expect(raw).To(HaveKeyWithValue("payload_length", float64(1234))) + Expect(ev).To(HaveKeyWithValue("ecn", "ECT(0)")) Expect(ev).To(HaveKey("header")) hdr := ev["header"].(map[string]interface{}) Expect(hdr).To(HaveKeyWithValue("packet_type", "initial")) @@ -520,6 +526,7 @@ var _ = Describe("Tracing", func() { tracer.ReceivedShortHeaderPacket( shdr, 789, + logging.ECT1, []logging.Frame{ &logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, &logging.StreamFrame{StreamID: 123, Offset: 1234, Length: 6, Fin: true}, @@ -533,6 +540,7 @@ var _ = Describe("Tracing", func() { raw := ev["raw"].(map[string]interface{}) Expect(raw).To(HaveKeyWithValue("length", float64(789))) Expect(raw).To(HaveKeyWithValue("payload_length", float64(789-(1+8+3)))) + Expect(ev).To(HaveKeyWithValue("ecn", "ECT(1)")) Expect(ev).To(HaveKey("header")) hdr := ev["header"].(map[string]interface{}) Expect(hdr).To(HaveKeyWithValue("packet_type", "1RTT")) diff --git a/qlog/types.go b/qlog/types.go index c47ad481..34104e61 100644 --- a/qlog/types.go +++ b/qlog/types.go @@ -312,3 +312,21 @@ func (s congestionState) String() string { return "unknown congestion state" } } + +type ecn logging.ECN + +func (e ecn) String() string { + //nolint:exhaustive // The unsupported value is never logged. + switch logging.ECN(e) { + case logging.ECTNot: + return "Not-ECT" + case logging.ECT0: + return "ECT(0)" + case logging.ECT1: + return "ECT(1)" + case logging.ECNCE: + return "CE" + default: + return "unknown ECN" + } +} diff --git a/qlog/types_test.go b/qlog/types_test.go index 9213ad31..6918b082 100644 --- a/qlog/types_test.go +++ b/qlog/types_test.go @@ -127,4 +127,12 @@ var _ = Describe("Types", func() { Expect(congestionState(logging.CongestionStateApplicationLimited).String()).To(Equal("application_limited")) Expect(congestionState(logging.CongestionStateRecovery).String()).To(Equal("recovery")) }) + + It("has a string representation for the ECN bits", func() { + Expect(ecn(logging.ECT0).String()).To(Equal("ECT(0)")) + Expect(ecn(logging.ECT1).String()).To(Equal("ECT(1)")) + Expect(ecn(logging.ECNCE).String()).To(Equal("CE")) + Expect(ecn(logging.ECTNot).String()).To(Equal("Not-ECT")) + Expect(ecn(42).String()).To(Equal("unknown ECN")) + }) })