github.com/quic-go/quic-go@v0.44.0/logging/multiplex_test.go (about)

     1  package logging_test
     2  
     3  import (
     4  	"errors"
     5  	"net"
     6  	"time"
     7  
     8  	mocklogging "github.com/quic-go/quic-go/internal/mocks/logging"
     9  	"github.com/quic-go/quic-go/internal/protocol"
    10  	"github.com/quic-go/quic-go/internal/wire"
    11  	. "github.com/quic-go/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 UpdatedMTU event", func() {
   205  			tr1.EXPECT().UpdatedMTU(ByteCount(1337), true)
   206  			tr2.EXPECT().UpdatedMTU(ByteCount(1337), true)
   207  			tracer.UpdatedMTU(1337, true)
   208  		})
   209  
   210  		It("traces the UpdatedCongestionState event", func() {
   211  			tr1.EXPECT().UpdatedCongestionState(CongestionStateRecovery)
   212  			tr2.EXPECT().UpdatedCongestionState(CongestionStateRecovery)
   213  			tracer.UpdatedCongestionState(CongestionStateRecovery)
   214  		})
   215  
   216  		It("traces the UpdatedMetrics event", func() {
   217  			rttStats := &RTTStats{}
   218  			rttStats.UpdateRTT(time.Second, 0, time.Now())
   219  			tr1.EXPECT().UpdatedMetrics(rttStats, ByteCount(1337), ByteCount(42), 13)
   220  			tr2.EXPECT().UpdatedMetrics(rttStats, ByteCount(1337), ByteCount(42), 13)
   221  			tracer.UpdatedMetrics(rttStats, 1337, 42, 13)
   222  		})
   223  
   224  		It("traces the AcknowledgedPacket event", func() {
   225  			tr1.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42))
   226  			tr2.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42))
   227  			tracer.AcknowledgedPacket(EncryptionHandshake, 42)
   228  		})
   229  
   230  		It("traces the LostPacket event", func() {
   231  			tr1.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold)
   232  			tr2.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold)
   233  			tracer.LostPacket(EncryptionHandshake, 42, PacketLossReorderingThreshold)
   234  		})
   235  
   236  		It("traces the UpdatedPTOCount event", func() {
   237  			tr1.EXPECT().UpdatedPTOCount(uint32(88))
   238  			tr2.EXPECT().UpdatedPTOCount(uint32(88))
   239  			tracer.UpdatedPTOCount(88)
   240  		})
   241  
   242  		It("traces the UpdatedKeyFromTLS event", func() {
   243  			tr1.EXPECT().UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient)
   244  			tr2.EXPECT().UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient)
   245  			tracer.UpdatedKeyFromTLS(EncryptionHandshake, PerspectiveClient)
   246  		})
   247  
   248  		It("traces the UpdatedKey event", func() {
   249  			tr1.EXPECT().UpdatedKey(KeyPhase(42), true)
   250  			tr2.EXPECT().UpdatedKey(KeyPhase(42), true)
   251  			tracer.UpdatedKey(KeyPhase(42), true)
   252  		})
   253  
   254  		It("traces the DroppedEncryptionLevel event", func() {
   255  			tr1.EXPECT().DroppedEncryptionLevel(EncryptionHandshake)
   256  			tr2.EXPECT().DroppedEncryptionLevel(EncryptionHandshake)
   257  			tracer.DroppedEncryptionLevel(EncryptionHandshake)
   258  		})
   259  
   260  		It("traces the DroppedKey event", func() {
   261  			tr1.EXPECT().DroppedKey(KeyPhase(123))
   262  			tr2.EXPECT().DroppedKey(KeyPhase(123))
   263  			tracer.DroppedKey(123)
   264  		})
   265  
   266  		It("traces the SetLossTimer event", func() {
   267  			now := time.Now()
   268  			tr1.EXPECT().SetLossTimer(TimerTypePTO, EncryptionHandshake, now)
   269  			tr2.EXPECT().SetLossTimer(TimerTypePTO, EncryptionHandshake, now)
   270  			tracer.SetLossTimer(TimerTypePTO, EncryptionHandshake, now)
   271  		})
   272  
   273  		It("traces the LossTimerExpired event", func() {
   274  			tr1.EXPECT().LossTimerExpired(TimerTypePTO, EncryptionHandshake)
   275  			tr2.EXPECT().LossTimerExpired(TimerTypePTO, EncryptionHandshake)
   276  			tracer.LossTimerExpired(TimerTypePTO, EncryptionHandshake)
   277  		})
   278  
   279  		It("traces the LossTimerCanceled event", func() {
   280  			tr1.EXPECT().LossTimerCanceled()
   281  			tr2.EXPECT().LossTimerCanceled()
   282  			tracer.LossTimerCanceled()
   283  		})
   284  
   285  		It("traces the Close event", func() {
   286  			tr1.EXPECT().Close()
   287  			tr2.EXPECT().Close()
   288  			tracer.Close()
   289  		})
   290  	})
   291  })