github.com/apernet/quic-go@v0.43.1-0.20240515053213-5e9e635fd9f0/logging/multiplex_test.go (about) 1 package logging_test 2 3 import ( 4 "errors" 5 "net" 6 "time" 7 8 mocklogging "github.com/apernet/quic-go/internal/mocks/logging" 9 "github.com/apernet/quic-go/internal/protocol" 10 "github.com/apernet/quic-go/internal/wire" 11 . "github.com/apernet/quic-go/logging" 12 13 . "github.com/onsi/ginkgo/v2" 14 . "github.com/onsi/gomega" 15 ) 16 17 var _ = Describe("Tracing", func() { 18 Context("Tracer", func() { 19 It("returns a nil tracer if no tracers are passed in", func() { 20 Expect(NewMultiplexedTracer()).To(BeNil()) 21 }) 22 23 It("returns the raw tracer if only one tracer is passed in", func() { 24 tr := &Tracer{} 25 tracer := NewMultiplexedTracer(tr) 26 Expect(tracer).To(Equal(tr)) 27 }) 28 29 Context("tracing events", func() { 30 var ( 31 tracer *Tracer 32 tr1, tr2 *mocklogging.MockTracer 33 ) 34 35 BeforeEach(func() { 36 var t1, t2 *Tracer 37 t1, tr1 = mocklogging.NewMockTracer(mockCtrl) 38 t2, tr2 = mocklogging.NewMockTracer(mockCtrl) 39 tracer = NewMultiplexedTracer(t1, t2, &Tracer{}) 40 }) 41 42 It("traces the PacketSent event", func() { 43 remote := &net.UDPAddr{IP: net.IPv4(4, 3, 2, 1)} 44 hdr := &Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} 45 f := &MaxDataFrame{MaximumData: 1337} 46 tr1.EXPECT().SentPacket(remote, hdr, ByteCount(1024), []Frame{f}) 47 tr2.EXPECT().SentPacket(remote, hdr, ByteCount(1024), []Frame{f}) 48 tracer.SentPacket(remote, hdr, 1024, []Frame{f}) 49 }) 50 51 It("traces the PacketSent event", func() { 52 remote := &net.UDPAddr{IP: net.IPv4(4, 3, 2, 1)} 53 src := ArbitraryLenConnectionID{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13} 54 dest := ArbitraryLenConnectionID{1, 2, 3, 4} 55 versions := []VersionNumber{1, 2, 3} 56 tr1.EXPECT().SentVersionNegotiationPacket(remote, dest, src, versions) 57 tr2.EXPECT().SentVersionNegotiationPacket(remote, dest, src, versions) 58 tracer.SentVersionNegotiationPacket(remote, dest, src, versions) 59 }) 60 61 It("traces the PacketDropped event", func() { 62 remote := &net.UDPAddr{IP: net.IPv4(4, 3, 2, 1)} 63 tr1.EXPECT().DroppedPacket(remote, PacketTypeRetry, ByteCount(1024), PacketDropDuplicate) 64 tr2.EXPECT().DroppedPacket(remote, PacketTypeRetry, ByteCount(1024), PacketDropDuplicate) 65 tracer.DroppedPacket(remote, PacketTypeRetry, 1024, PacketDropDuplicate) 66 }) 67 68 It("traces the Debug event", func() { 69 tr1.EXPECT().Debug("foo", "bar") 70 tr2.EXPECT().Debug("foo", "bar") 71 tracer.Debug("foo", "bar") 72 }) 73 74 It("traces the Close event", func() { 75 tr1.EXPECT().Close() 76 tr2.EXPECT().Close() 77 tracer.Close() 78 }) 79 }) 80 }) 81 82 Context("Connection Tracer", func() { 83 var ( 84 tracer *ConnectionTracer 85 tr1 *mocklogging.MockConnectionTracer 86 tr2 *mocklogging.MockConnectionTracer 87 ) 88 89 BeforeEach(func() { 90 var t1, t2 *ConnectionTracer 91 t1, tr1 = mocklogging.NewMockConnectionTracer(mockCtrl) 92 t2, tr2 = mocklogging.NewMockConnectionTracer(mockCtrl) 93 tracer = NewMultiplexedConnectionTracer(t1, t2) 94 }) 95 96 It("traces the StartedConnection event", func() { 97 local := &net.UDPAddr{IP: net.IPv4(1, 2, 3, 4)} 98 remote := &net.UDPAddr{IP: net.IPv4(4, 3, 2, 1)} 99 dest := protocol.ParseConnectionID([]byte{1, 2, 3, 4}) 100 src := protocol.ParseConnectionID([]byte{4, 3, 2, 1}) 101 tr1.EXPECT().StartedConnection(local, remote, src, dest) 102 tr2.EXPECT().StartedConnection(local, remote, src, dest) 103 tracer.StartedConnection(local, remote, src, dest) 104 }) 105 106 It("traces the NegotiatedVersion event", func() { 107 chosen := protocol.Version2 108 client := []protocol.Version{protocol.Version1} 109 server := []protocol.Version{13, 37} 110 tr1.EXPECT().NegotiatedVersion(chosen, client, server) 111 tr2.EXPECT().NegotiatedVersion(chosen, client, server) 112 tracer.NegotiatedVersion(chosen, client, server) 113 }) 114 115 It("traces the ClosedConnection event", func() { 116 e := errors.New("test err") 117 tr1.EXPECT().ClosedConnection(e) 118 tr2.EXPECT().ClosedConnection(e) 119 tracer.ClosedConnection(e) 120 }) 121 122 It("traces the SentTransportParameters event", func() { 123 tp := &wire.TransportParameters{InitialMaxData: 1337} 124 tr1.EXPECT().SentTransportParameters(tp) 125 tr2.EXPECT().SentTransportParameters(tp) 126 tracer.SentTransportParameters(tp) 127 }) 128 129 It("traces the ReceivedTransportParameters event", func() { 130 tp := &wire.TransportParameters{InitialMaxData: 1337} 131 tr1.EXPECT().ReceivedTransportParameters(tp) 132 tr2.EXPECT().ReceivedTransportParameters(tp) 133 tracer.ReceivedTransportParameters(tp) 134 }) 135 136 It("traces the RestoredTransportParameters event", func() { 137 tp := &wire.TransportParameters{InitialMaxData: 1337} 138 tr1.EXPECT().RestoredTransportParameters(tp) 139 tr2.EXPECT().RestoredTransportParameters(tp) 140 tracer.RestoredTransportParameters(tp) 141 }) 142 143 It("traces the SentLongHeaderPacket event", func() { 144 hdr := &ExtendedHeader{Header: Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})}} 145 ack := &AckFrame{AckRanges: []AckRange{{Smallest: 1, Largest: 10}}} 146 ping := &PingFrame{} 147 tr1.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ECTNot, ack, []Frame{ping}) 148 tr2.EXPECT().SentLongHeaderPacket(hdr, ByteCount(1337), ECTNot, ack, []Frame{ping}) 149 tracer.SentLongHeaderPacket(hdr, 1337, ECTNot, ack, []Frame{ping}) 150 }) 151 152 It("traces the SentShortHeaderPacket event", func() { 153 hdr := &ShortHeader{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} 154 ack := &AckFrame{AckRanges: []AckRange{{Smallest: 1, Largest: 10}}} 155 ping := &PingFrame{} 156 tr1.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ECNCE, ack, []Frame{ping}) 157 tr2.EXPECT().SentShortHeaderPacket(hdr, ByteCount(1337), ECNCE, ack, []Frame{ping}) 158 tracer.SentShortHeaderPacket(hdr, 1337, ECNCE, ack, []Frame{ping}) 159 }) 160 161 It("traces the ReceivedVersionNegotiationPacket event", func() { 162 src := ArbitraryLenConnectionID{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13} 163 dest := ArbitraryLenConnectionID{1, 2, 3, 4} 164 tr1.EXPECT().ReceivedVersionNegotiationPacket(dest, src, []VersionNumber{1337}) 165 tr2.EXPECT().ReceivedVersionNegotiationPacket(dest, src, []VersionNumber{1337}) 166 tracer.ReceivedVersionNegotiationPacket(dest, src, []VersionNumber{1337}) 167 }) 168 169 It("traces the ReceivedRetry event", func() { 170 hdr := &Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} 171 tr1.EXPECT().ReceivedRetry(hdr) 172 tr2.EXPECT().ReceivedRetry(hdr) 173 tracer.ReceivedRetry(hdr) 174 }) 175 176 It("traces the ReceivedLongHeaderPacket event", func() { 177 hdr := &ExtendedHeader{Header: Header{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})}} 178 ping := &PingFrame{} 179 tr1.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), ECT1, []Frame{ping}) 180 tr2.EXPECT().ReceivedLongHeaderPacket(hdr, ByteCount(1337), ECT1, []Frame{ping}) 181 tracer.ReceivedLongHeaderPacket(hdr, 1337, ECT1, []Frame{ping}) 182 }) 183 184 It("traces the ReceivedShortHeaderPacket event", func() { 185 hdr := &ShortHeader{DestConnectionID: protocol.ParseConnectionID([]byte{1, 2, 3})} 186 ping := &PingFrame{} 187 tr1.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), ECT0, []Frame{ping}) 188 tr2.EXPECT().ReceivedShortHeaderPacket(hdr, ByteCount(1337), ECT0, []Frame{ping}) 189 tracer.ReceivedShortHeaderPacket(hdr, 1337, ECT0, []Frame{ping}) 190 }) 191 192 It("traces the BufferedPacket event", func() { 193 tr1.EXPECT().BufferedPacket(PacketTypeHandshake, ByteCount(1337)) 194 tr2.EXPECT().BufferedPacket(PacketTypeHandshake, ByteCount(1337)) 195 tracer.BufferedPacket(PacketTypeHandshake, 1337) 196 }) 197 198 It("traces the DroppedPacket event", func() { 199 tr1.EXPECT().DroppedPacket(PacketTypeInitial, PacketNumber(42), ByteCount(1337), PacketDropHeaderParseError) 200 tr2.EXPECT().DroppedPacket(PacketTypeInitial, PacketNumber(42), ByteCount(1337), PacketDropHeaderParseError) 201 tracer.DroppedPacket(PacketTypeInitial, 42, 1337, PacketDropHeaderParseError) 202 }) 203 204 It("traces the UpdatedCongestionState event", func() { 205 tr1.EXPECT().UpdatedCongestionState(CongestionStateRecovery) 206 tr2.EXPECT().UpdatedCongestionState(CongestionStateRecovery) 207 tracer.UpdatedCongestionState(CongestionStateRecovery) 208 }) 209 210 It("traces the UpdatedMetrics event", func() { 211 rttStats := &RTTStats{} 212 rttStats.UpdateRTT(time.Second, 0, time.Now()) 213 tr1.EXPECT().UpdatedMetrics(rttStats, ByteCount(1337), ByteCount(42), 13) 214 tr2.EXPECT().UpdatedMetrics(rttStats, ByteCount(1337), ByteCount(42), 13) 215 tracer.UpdatedMetrics(rttStats, 1337, 42, 13) 216 }) 217 218 It("traces the AcknowledgedPacket event", func() { 219 tr1.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42)) 220 tr2.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42)) 221 tracer.AcknowledgedPacket(EncryptionHandshake, 42) 222 }) 223 224 It("traces the LostPacket event", func() { 225 tr1.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold) 226 tr2.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold) 227 tracer.LostPacket(EncryptionHandshake, 42, PacketLossReorderingThreshold) 228 }) 229 230 It("traces the UpdatedPTOCount event", func() { 231 tr1.EXPECT().UpdatedPTOCount(uint32(88)) 232 tr2.EXPECT().UpdatedPTOCount(uint32(88)) 233 tracer.UpdatedPTOCount(88) 234 }) 235 236 It("traces the UpdatedKeyFromTLS event", func() { 237 tr1.EXPECT().UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient) 238 tr2.EXPECT().UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient) 239 tracer.UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient) 240 }) 241 242 It("traces the UpdatedKey event", func() { 243 tr1.EXPECT().UpdatedKey(KeyPhase(42), true) 244 tr2.EXPECT().UpdatedKey(KeyPhase(42), true) 245 tracer.UpdatedKey(KeyPhase(42), true) 246 }) 247 248 It("traces the DroppedEncryptionLevel event", func() { 249 tr1.EXPECT().DroppedEncryptionLevel(EncryptionHandshake) 250 tr2.EXPECT().DroppedEncryptionLevel(EncryptionHandshake) 251 tracer.DroppedEncryptionLevel(EncryptionHandshake) 252 }) 253 254 It("traces the DroppedKey event", func() { 255 tr1.EXPECT().DroppedKey(KeyPhase(123)) 256 tr2.EXPECT().DroppedKey(KeyPhase(123)) 257 tracer.DroppedKey(123) 258 }) 259 260 It("traces the SetLossTimer event", func() { 261 now := time.Now() 262 tr1.EXPECT().SetLossTimer(TimerTypePTO, EncryptionHandshake, now) 263 tr2.EXPECT().SetLossTimer(TimerTypePTO, EncryptionHandshake, now) 264 tracer.SetLossTimer(TimerTypePTO, EncryptionHandshake, now) 265 }) 266 267 It("traces the LossTimerExpired event", func() { 268 tr1.EXPECT().LossTimerExpired(TimerTypePTO, EncryptionHandshake) 269 tr2.EXPECT().LossTimerExpired(TimerTypePTO, EncryptionHandshake) 270 tracer.LossTimerExpired(TimerTypePTO, EncryptionHandshake) 271 }) 272 273 It("traces the LossTimerCanceled event", func() { 274 tr1.EXPECT().LossTimerCanceled() 275 tr2.EXPECT().LossTimerCanceled() 276 tracer.LossTimerCanceled() 277 }) 278 279 It("traces the Close event", func() { 280 tr1.EXPECT().Close() 281 tr2.EXPECT().Close() 282 tracer.Close() 283 }) 284 }) 285 })