diff --git a/client.go b/client.go index 773e1821..57596ba0 100644 --- a/client.go +++ b/client.go @@ -41,8 +41,8 @@ type client struct { session quicSession - qlogger logging.Tracer - logger utils.Logger + tracer logging.Tracer + logger utils.Logger } var _ packetHandler = &client{} @@ -51,8 +51,8 @@ var ( // make it possible to mock connection ID generation in the tests generateConnectionID = protocol.GenerateConnectionID generateConnectionIDForInitial = protocol.GenerateConnectionIDForInitial - // make it possible to the qlogger - newQlogger = qlog.NewTracer + // make it possible to the tracer + newTracer = qlog.NewTracer ) // DialAddr establishes a new QUIC connection to a server. @@ -182,7 +182,7 @@ func dialContext( if c.config.GetLogWriter != nil { if w := c.config.GetLogWriter(c.destConnID); w != nil { - c.qlogger = newQlogger(w, protocol.PerspectiveClient, c.destConnID) + c.tracer = newTracer(w, protocol.PerspectiveClient, c.destConnID) } } if err := c.dial(ctx); err != nil { @@ -250,8 +250,8 @@ func newClient( func (c *client) dial(ctx context.Context) error { c.logger.Infof("Starting new connection to %s (%s -> %s), source connection ID %s, destination connection ID %s, version %s", c.tlsConf.ServerName, c.conn.LocalAddr(), c.conn.RemoteAddr(), c.srcConnID, c.destConnID, c.version) - if c.qlogger != nil { - c.qlogger.StartedConnection(c.conn.LocalAddr(), c.conn.RemoteAddr(), c.version, c.srcConnID, c.destConnID) + if c.tracer != nil { + c.tracer.StartedConnection(c.conn.LocalAddr(), c.conn.RemoteAddr(), c.version, c.srcConnID, c.destConnID) } c.mutex.Lock() @@ -266,7 +266,7 @@ func (c *client) dial(ctx context.Context) error { c.version, c.use0RTT, c.hasNegotiatedVersion, - c.qlogger, + c.tracer, c.logger, c.version, ) diff --git a/client_test.go b/client_test.go index a84d1a1e..67aefd7f 100644 --- a/client_test.go +++ b/client_test.go @@ -34,7 +34,7 @@ var _ = Describe("Client", func() { mockMultiplexer *MockMultiplexer origMultiplexer multiplexer tlsConf *tls.Config - qlogger *mocks.MockTracer + tracer *mocks.MockTracer config *Config originalClientSessConstructor func( @@ -48,11 +48,11 @@ var _ = Describe("Client", func() { initialVersion protocol.VersionNumber, enable0RTT bool, hasNegotiatedVersion bool, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession - originalQlogConstructor func(io.WriteCloser, protocol.Perspective, protocol.ConnectionID) logging.Tracer + originalTracerConstructor func(io.WriteCloser, protocol.Perspective, protocol.ConnectionID) logging.Tracer ) // generate a packet sent by the server that accepts the QUIC version suggested by the client @@ -70,14 +70,14 @@ var _ = Describe("Client", func() { tlsConf = &tls.Config{NextProtos: []string{"proto1"}} connID = protocol.ConnectionID{0, 0, 0, 0, 0, 0, 0x13, 0x37} originalClientSessConstructor = newClientSession - originalQlogConstructor = newQlogger - qlogger = mocks.NewMockTracer(mockCtrl) - newQlogger = func(io.WriteCloser, protocol.Perspective, protocol.ConnectionID) logging.Tracer { - return qlogger + originalTracerConstructor = newTracer + tracer = mocks.NewMockTracer(mockCtrl) + newTracer = func(io.WriteCloser, protocol.Perspective, protocol.ConnectionID) logging.Tracer { + return tracer } config = &Config{ GetLogWriter: func([]byte) io.WriteCloser { - // Since we're mocking the qlogger, it doesn't matter what we return here, + // Since we're mocking the tracer, it doesn't matter what we return here, // as long as it's not nil. return utils.NewBufferedWriteCloser( bufio.NewWriter(&bytes.Buffer{}), @@ -96,7 +96,7 @@ var _ = Describe("Client", func() { destConnID: connID, version: protocol.SupportedVersions[0], conn: &conn{pconn: packetConn, currentAddr: addr}, - qlogger: qlogger, + tracer: tracer, logger: utils.DefaultLogger, } getMultiplexer() // make the sync.Once execute @@ -109,7 +109,7 @@ var _ = Describe("Client", func() { AfterEach(func() { connMuxer = origMultiplexer newClientSession = originalClientSessConstructor - newQlogger = originalQlogConstructor + newTracer = originalTracerConstructor }) AfterEach(func() { @@ -237,7 +237,7 @@ var _ = Describe("Client", func() { sess.EXPECT().run() return sess } - qlogger.EXPECT().StartedConnection(packetConn.addr, addr, protocol.VersionTLS, gomock.Any(), gomock.Any()) + tracer.EXPECT().StartedConnection(packetConn.addr, addr, protocol.VersionTLS, gomock.Any(), gomock.Any()) _, err := Dial( packetConn, addr, @@ -278,7 +278,7 @@ var _ = Describe("Client", func() { sess.EXPECT().HandshakeComplete().Return(ctx) return sess } - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) s, err := Dial( packetConn, addr, @@ -324,7 +324,7 @@ var _ = Describe("Client", func() { go func() { defer GinkgoRecover() defer close(done) - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) s, err := DialEarly( packetConn, addr, @@ -367,7 +367,7 @@ var _ = Describe("Client", func() { return sess } packetConn.dataToRead <- acceptClientVersionPacket(cl.srcConnID) - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) _, err := Dial( packetConn, addr, @@ -411,7 +411,7 @@ var _ = Describe("Client", func() { dialed := make(chan struct{}) go func() { defer GinkgoRecover() - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionTLS, gomock.Any(), gomock.Any()) _, err := DialContext( ctx, packetConn, @@ -642,8 +642,8 @@ var _ = Describe("Client", func() { } gomock.InOrder( - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), initialVersion, gomock.Any(), gomock.Any()), - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionNumber(789), gomock.Any(), gomock.Any()), + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), initialVersion, gomock.Any(), gomock.Any()), + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), protocol.VersionNumber(789), gomock.Any(), gomock.Any()), ) _, err := DialAddr("localhost:7890", tlsConf, config) Expect(err).ToNot(HaveOccurred()) diff --git a/internal/ackhandler/ackhandler.go b/internal/ackhandler/ackhandler.go index 4c3dde74..7bb9369b 100644 --- a/internal/ackhandler/ackhandler.go +++ b/internal/ackhandler/ackhandler.go @@ -14,10 +14,10 @@ func NewAckHandler( rttStats *congestion.RTTStats, pers protocol.Perspective, traceCallback func(quictrace.Event), - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, version protocol.VersionNumber, ) (SentPacketHandler, ReceivedPacketHandler) { - sph := newSentPacketHandler(initialPacketNumber, rttStats, pers, traceCallback, qlogger, logger) + sph := newSentPacketHandler(initialPacketNumber, rttStats, pers, traceCallback, tracer, logger) return sph, newReceivedPacketHandler(sph, rttStats, logger, version) } diff --git a/internal/ackhandler/sent_packet_handler.go b/internal/ackhandler/sent_packet_handler.go index 0739f3ee..748b8cc4 100644 --- a/internal/ackhandler/sent_packet_handler.go +++ b/internal/ackhandler/sent_packet_handler.go @@ -84,7 +84,7 @@ type sentPacketHandler struct { perspective protocol.Perspective traceCallback func(quictrace.Event) - qlogger logging.Tracer + tracer logging.Tracer logger utils.Logger } @@ -96,7 +96,7 @@ func newSentPacketHandler( rttStats *congestion.RTTStats, pers protocol.Perspective, traceCallback func(quictrace.Event), - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, ) *sentPacketHandler { congestion := congestion.NewCubicSender( @@ -115,7 +115,7 @@ func newSentPacketHandler( congestion: congestion, perspective: pers, traceCallback: traceCallback, - qlogger: qlogger, + tracer: tracer, logger: logger, } } @@ -169,8 +169,8 @@ func (h *sentPacketHandler) dropPackets(encLevel protocol.EncryptionLevel) { panic(fmt.Sprintf("Cannot drop keys for encryption level %s", encLevel)) } h.setLossDetectionTimer() - if h.qlogger != nil && h.ptoCount != 0 { - h.qlogger.UpdatedPTOCount(0) + if h.tracer != nil && h.ptoCount != 0 { + h.tracer.UpdatedPTOCount(0) } h.ptoCount = 0 h.numProbesToSend = 0 @@ -208,8 +208,8 @@ func (h *sentPacketHandler) SentPacket(packet *Packet) { if isAckEliciting { h.getPacketNumberSpace(packet.EncryptionLevel).history.SentPacket(packet) } - if h.qlogger != nil && isAckEliciting { - h.qlogger.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) + if h.tracer != nil && isAckEliciting { + h.tracer.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) } if isAckEliciting || !h.peerCompletedAddressValidation { h.setLossDetectionTimer() @@ -289,8 +289,8 @@ func (h *sentPacketHandler) ReceivedAck(ack *wire.AckFrame, encLevel protocol.En h.logger.Debugf("\tupdated RTT: %s (σ: %s)", h.rttStats.SmoothedRTT(), h.rttStats.MeanDeviation()) } h.congestion.MaybeExitSlowStart() - if h.qlogger != nil { - h.qlogger.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) + if h.tracer != nil { + h.tracer.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) } } @@ -314,8 +314,8 @@ func (h *sentPacketHandler) ReceivedAck(ack *wire.AckFrame, encLevel protocol.En // Reset the pto_count unless the client is unsure if the server has validated the client's address. if h.peerCompletedAddressValidation { - if h.qlogger != nil && h.ptoCount != 0 { - h.qlogger.UpdatedPTOCount(0) + if h.tracer != nil && h.ptoCount != 0 { + h.tracer.UpdatedPTOCount(0) } h.ptoCount = 0 } @@ -472,12 +472,12 @@ func (h *sentPacketHandler) hasOutstandingPackets() bool { } func (h *sentPacketHandler) setLossDetectionTimer() { - oldAlarm := h.alarm // only needed in case qlog is enabled + oldAlarm := h.alarm // only needed in case tracing is enabled if lossTime, encLevel := h.getLossTimeAndSpace(); !lossTime.IsZero() { // Early retransmit timer or time loss detection. h.alarm = lossTime - if h.qlogger != nil && h.alarm != oldAlarm { - h.qlogger.SetLossTimer(logging.TimerTypeACK, encLevel, h.alarm) + if h.tracer != nil && h.alarm != oldAlarm { + h.tracer.SetLossTimer(logging.TimerTypeACK, encLevel, h.alarm) } return } @@ -486,8 +486,8 @@ func (h *sentPacketHandler) setLossDetectionTimer() { if !h.hasOutstandingPackets() && h.peerCompletedAddressValidation { h.alarm = time.Time{} h.logger.Debugf("Canceling loss detection timer. No packets in flight.") - if h.qlogger != nil && !oldAlarm.IsZero() { - h.qlogger.LossTimerCanceled() + if h.tracer != nil && !oldAlarm.IsZero() { + h.tracer.LossTimerCanceled() } return } @@ -495,8 +495,8 @@ func (h *sentPacketHandler) setLossDetectionTimer() { // PTO alarm ptoTime, encLevel := h.getPTOTimeAndSpace() h.alarm = ptoTime - if h.qlogger != nil && h.alarm != oldAlarm { - h.qlogger.SetLossTimer(logging.TimerTypePTO, encLevel, h.alarm) + if h.tracer != nil && h.alarm != oldAlarm { + h.tracer.SetLossTimer(logging.TimerTypePTO, encLevel, h.alarm) } } @@ -521,13 +521,13 @@ func (h *sentPacketHandler) detectAndRemoveLostPackets(now time.Time, encLevel p if packet.SendTime.Before(lostSendTime) { lostPackets = append(lostPackets, packet) - if h.qlogger != nil { - h.qlogger.LostPacket(packet.EncryptionLevel, packet.PacketNumber, logging.PacketLossTimeThreshold) + if h.tracer != nil { + h.tracer.LostPacket(packet.EncryptionLevel, packet.PacketNumber, logging.PacketLossTimeThreshold) } } else if pnSpace.largestAcked >= packet.PacketNumber+packetThreshold { lostPackets = append(lostPackets, packet) - if h.qlogger != nil { - h.qlogger.LostPacket(packet.EncryptionLevel, packet.PacketNumber, logging.PacketLossReorderingThreshold) + if h.tracer != nil { + h.tracer.LostPacket(packet.EncryptionLevel, packet.PacketNumber, logging.PacketLossReorderingThreshold) } } else if pnSpace.lossTime.IsZero() { // Note: This conditional is only entered once per call @@ -598,8 +598,8 @@ func (h *sentPacketHandler) onVerifiedLossDetectionTimeout() error { if h.logger.Debug() { h.logger.Debugf("Loss detection alarm fired in loss timer mode. Loss time: %s", earliestLossTime) } - if h.qlogger != nil { - h.qlogger.LossTimerExpired(logging.TimerTypeACK, encLevel) + if h.tracer != nil { + h.tracer.LossTimerExpired(logging.TimerTypeACK, encLevel) } // Early retransmit or time loss detection priorInFlight := h.bytesInFlight @@ -620,9 +620,9 @@ func (h *sentPacketHandler) onVerifiedLossDetectionTimeout() error { if h.logger.Debug() { h.logger.Debugf("Loss detection alarm for %s fired in PTO mode. PTO count: %d", encLevel, h.ptoCount) } - if h.qlogger != nil { - h.qlogger.LossTimerExpired(logging.TimerTypePTO, encLevel) - h.qlogger.UpdatedPTOCount(h.ptoCount) + if h.tracer != nil { + h.tracer.LossTimerExpired(logging.TimerTypePTO, encLevel) + h.tracer.UpdatedPTOCount(h.ptoCount) } h.numProbesToSend += 2 switch encLevel { @@ -783,18 +783,18 @@ func (h *sentPacketHandler) ResetForRetry() error { if h.logger.Debug() { h.logger.Debugf("\tupdated RTT: %s (σ: %s)", h.rttStats.SmoothedRTT(), h.rttStats.MeanDeviation()) } - if h.qlogger != nil { - h.qlogger.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) + if h.tracer != nil { + h.tracer.UpdatedMetrics(h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, h.packetsInFlight()) } } h.initialPackets = newPacketNumberSpace(h.initialPackets.pns.Pop()) h.appDataPackets = newPacketNumberSpace(h.appDataPackets.pns.Pop()) oldAlarm := h.alarm h.alarm = time.Time{} - if h.qlogger != nil { - h.qlogger.UpdatedPTOCount(0) + if h.tracer != nil { + h.tracer.UpdatedPTOCount(0) if !oldAlarm.IsZero() { - h.qlogger.LossTimerCanceled() + h.tracer.LossTimerCanceled() } } h.ptoCount = 0 diff --git a/internal/handshake/crypto_setup.go b/internal/handshake/crypto_setup.go index 600636ca..90dc1315 100644 --- a/internal/handshake/crypto_setup.go +++ b/internal/handshake/crypto_setup.go @@ -94,8 +94,8 @@ type cryptoSetup struct { rttStats *congestion.RTTStats - qlogger logging.Tracer - logger utils.Logger + tracer logging.Tracer + logger utils.Logger perspective protocol.Perspective @@ -137,7 +137,7 @@ func NewCryptoSetupClient( tlsConf *tls.Config, enable0RTT bool, rttStats *congestion.RTTStats, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, ) (CryptoSetup, <-chan *wire.TransportParameters /* ClientHello written. Receive nil for non-0-RTT */) { cs, clientHelloWritten := newCryptoSetup( @@ -149,7 +149,7 @@ func NewCryptoSetupClient( tlsConf, enable0RTT, rttStats, - qlogger, + tracer, logger, protocol.PerspectiveClient, ) @@ -169,7 +169,7 @@ func NewCryptoSetupServer( tlsConf *tls.Config, enable0RTT bool, rttStats *congestion.RTTStats, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, ) CryptoSetup { cs, _ := newCryptoSetup( @@ -181,7 +181,7 @@ func NewCryptoSetupServer( tlsConf, enable0RTT, rttStats, - qlogger, + tracer, logger, protocol.PerspectiveServer, ) @@ -198,14 +198,14 @@ func newCryptoSetup( tlsConf *tls.Config, enable0RTT bool, rttStats *congestion.RTTStats, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, perspective protocol.Perspective, ) (*cryptoSetup, <-chan *wire.TransportParameters /* ClientHello written. Receive nil for non-0-RTT */) { initialSealer, initialOpener := NewInitialAEAD(connID, perspective) - if qlogger != nil { - qlogger.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveClient) - qlogger.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveServer) + if tracer != nil { + tracer.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveClient) + tracer.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveServer) } extHandler := newExtensionHandler(tp.Marshal(perspective), perspective) cs := &cryptoSetup{ @@ -213,14 +213,14 @@ func newCryptoSetup( initialSealer: initialSealer, initialOpener: initialOpener, handshakeStream: handshakeStream, - aead: newUpdatableAEAD(rttStats, qlogger, logger), + aead: newUpdatableAEAD(rttStats, tracer, logger), readEncLevel: protocol.EncryptionInitial, writeEncLevel: protocol.EncryptionInitial, runner: runner, ourParams: tp, paramsChan: extHandler.TransportParameters(), rttStats: rttStats, - qlogger: qlogger, + tracer: tracer, logger: logger, perspective: perspective, handshakeDone: make(chan struct{}), @@ -241,9 +241,9 @@ func (h *cryptoSetup) ChangeConnectionID(id protocol.ConnectionID) { initialSealer, initialOpener := NewInitialAEAD(id, h.perspective) h.initialSealer = initialSealer h.initialOpener = initialOpener - if h.qlogger != nil { - h.qlogger.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveClient) - h.qlogger.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveServer) + if h.tracer != nil { + h.tracer.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveClient) + h.tracer.UpdatedKeyFromTLS(protocol.EncryptionInitial, protocol.PerspectiveServer) } } @@ -589,8 +589,8 @@ func (h *cryptoSetup) SetReadKey(encLevel qtls.EncryptionLevel, suite *qtls.Ciph ) h.mutex.Unlock() h.logger.Debugf("Installed 0-RTT Read keys (using %s)", qtls.CipherSuiteName(suite.ID)) - if h.qlogger != nil { - h.qlogger.UpdatedKeyFromTLS(protocol.Encryption0RTT, h.perspective.Opposite()) + if h.tracer != nil { + h.tracer.UpdatedKeyFromTLS(protocol.Encryption0RTT, h.perspective.Opposite()) } return case qtls.EncryptionHandshake: @@ -611,8 +611,8 @@ func (h *cryptoSetup) SetReadKey(encLevel qtls.EncryptionLevel, suite *qtls.Ciph panic("unexpected read encryption level") } h.mutex.Unlock() - if h.qlogger != nil { - h.qlogger.UpdatedKeyFromTLS(h.readEncLevel, h.perspective.Opposite()) + if h.tracer != nil { + h.tracer.UpdatedKeyFromTLS(h.readEncLevel, h.perspective.Opposite()) } h.receivedReadKey <- struct{}{} } @@ -630,8 +630,8 @@ func (h *cryptoSetup) SetWriteKey(encLevel qtls.EncryptionLevel, suite *qtls.Cip ) h.mutex.Unlock() h.logger.Debugf("Installed 0-RTT Write keys (using %s)", qtls.CipherSuiteName(suite.ID)) - if h.qlogger != nil { - h.qlogger.UpdatedKeyFromTLS(protocol.Encryption0RTT, h.perspective) + if h.tracer != nil { + h.tracer.UpdatedKeyFromTLS(protocol.Encryption0RTT, h.perspective) } return case qtls.EncryptionHandshake: @@ -656,8 +656,8 @@ func (h *cryptoSetup) SetWriteKey(encLevel qtls.EncryptionLevel, suite *qtls.Cip panic("unexpected write encryption level") } h.mutex.Unlock() - if h.qlogger != nil { - h.qlogger.UpdatedKeyFromTLS(h.writeEncLevel, h.perspective) + if h.tracer != nil { + h.tracer.UpdatedKeyFromTLS(h.writeEncLevel, h.perspective) } h.receivedWriteKey <- struct{}{} } diff --git a/internal/handshake/updatable_aead.go b/internal/handshake/updatable_aead.go index 4fba8ec8..8e17d3c4 100644 --- a/internal/handshake/updatable_aead.go +++ b/internal/handshake/updatable_aead.go @@ -74,8 +74,8 @@ type updatableAEAD struct { rttStats *congestion.RTTStats - qlogger logging.Tracer - logger utils.Logger + tracer logging.Tracer + logger utils.Logger // use a single slice to avoid allocations nonceBuf []byte @@ -84,7 +84,7 @@ type updatableAEAD struct { var _ ShortHeaderOpener = &updatableAEAD{} var _ ShortHeaderSealer = &updatableAEAD{} -func newUpdatableAEAD(rttStats *congestion.RTTStats, qlogger logging.Tracer, logger utils.Logger) *updatableAEAD { +func newUpdatableAEAD(rttStats *congestion.RTTStats, tracer logging.Tracer, logger utils.Logger) *updatableAEAD { return &updatableAEAD{ firstPacketNumber: protocol.InvalidPacketNumber, largestAcked: protocol.InvalidPacketNumber, @@ -92,7 +92,7 @@ func newUpdatableAEAD(rttStats *congestion.RTTStats, qlogger logging.Tracer, log firstSentWithCurrentKey: protocol.InvalidPacketNumber, keyUpdateInterval: keyUpdateInterval, rttStats: rttStats, - qlogger: qlogger, + tracer: tracer, logger: logger, } } @@ -183,8 +183,8 @@ func (a *updatableAEAD) Open(dst, src []byte, rcvTime time.Time, pn protocol.Pac } a.rollKeys(rcvTime) a.logger.Debugf("Peer updated keys to %s", a.keyPhase) - if a.qlogger != nil { - a.qlogger.UpdatedKey(a.keyPhase, true) + if a.tracer != nil { + a.tracer.UpdatedKey(a.keyPhase, true) } a.firstRcvdWithCurrentKey = pn return dec, err @@ -244,8 +244,8 @@ func (a *updatableAEAD) shouldInitiateKeyUpdate() bool { func (a *updatableAEAD) KeyPhase() protocol.KeyPhaseBit { if a.shouldInitiateKeyUpdate() { - if a.qlogger != nil { - a.qlogger.UpdatedKey(a.keyPhase, false) + if a.tracer != nil { + a.tracer.UpdatedKey(a.keyPhase, false) } a.rollKeys(time.Now()) } diff --git a/server.go b/server.go index d2a3a05d..82c69727 100644 --- a/server.go +++ b/server.go @@ -447,7 +447,7 @@ func (s *baseServer) createNewSession( ) quicSession { var sess quicSession if added := s.sessionHandler.AddWithConnID(clientDestConnID, srcConnID, func() packetHandler { - var qlogger logging.Tracer + var tracer logging.Tracer if s.config.GetLogWriter != nil { // Use the same connection ID that is passed to the client's GetLogWriter callback. connID := clientDestConnID @@ -455,7 +455,7 @@ func (s *baseServer) createNewSession( connID = origDestConnID } if w := s.config.GetLogWriter(connID); w != nil { - qlogger = qlog.NewTracer(w, protocol.PerspectiveServer, connID) + tracer = qlog.NewTracer(w, protocol.PerspectiveServer, connID) } } sess = s.newSession( @@ -471,7 +471,7 @@ func (s *baseServer) createNewSession( s.tlsConf, s.tokenGenerator, s.acceptEarlySessions, - qlogger, + tracer, s.logger, version, ) diff --git a/session.go b/session.go index 5cfdc2a4..1b7b2e24 100644 --- a/session.go +++ b/session.go @@ -203,9 +203,9 @@ type session struct { traceCallback func(quictrace.Event) - logID string - qlogger logging.Tracer - logger utils.Logger + logID string + tracer logging.Tracer + logger utils.Logger } var _ Session = &session{} @@ -225,7 +225,7 @@ var newSession = func( tlsConf *tls.Config, tokenGenerator *handshake.TokenGenerator, enable0RTT bool, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession { @@ -238,7 +238,7 @@ var newSession = func( oneRTTStream: newCryptoStream(), perspective: protocol.PerspectiveServer, handshakeCompleteChan: make(chan struct{}), - qlogger: qlogger, + tracer: tracer, logger: logger, version: v, } @@ -270,7 +270,7 @@ var newSession = func( s.rttStats, s.perspective, s.traceCallback, - s.qlogger, + s.tracer, s.logger, s.version, ) @@ -293,8 +293,8 @@ var newSession = func( InitialSourceConnectionID: srcConnID, RetrySourceConnectionID: retrySrcConnID, } - if s.qlogger != nil { - s.qlogger.SentTransportParameters(params) + if s.tracer != nil { + s.tracer.SentTransportParameters(params) } cs := handshake.NewCryptoSetupServer( initialStream, @@ -315,7 +315,7 @@ var newSession = func( tlsConf, enable0RTT, s.rttStats, - qlogger, + tracer, logger, ) s.cryptoStreamHandler = cs @@ -350,7 +350,7 @@ var newClientSession = func( initialVersion protocol.VersionNumber, enable0RTT bool, hasNegotiatedVersion bool, - qlogger logging.Tracer, + tracer logging.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession { @@ -364,7 +364,7 @@ var newClientSession = func( handshakeCompleteChan: make(chan struct{}), logID: destConnID.String(), logger: logger, - qlogger: qlogger, + tracer: tracer, initialVersion: initialVersion, versionNegotiated: hasNegotiatedVersion, version: v, @@ -392,7 +392,7 @@ var newClientSession = func( s.rttStats, s.perspective, s.traceCallback, - s.qlogger, + s.tracer, s.logger, s.version, ) @@ -412,8 +412,8 @@ var newClientSession = func( ActiveConnectionIDLimit: protocol.MaxActiveConnectionIDs, InitialSourceConnectionID: srcConnID, } - if s.qlogger != nil { - s.qlogger.SentTransportParameters(params) + if s.tracer != nil { + s.tracer.SentTransportParameters(params) } cs, clientHelloWritten := handshake.NewCryptoSetupClient( initialStream, @@ -431,7 +431,7 @@ var newClientSession = func( tlsConf, enable0RTT, s.rttStats, - qlogger, + tracer, logger, ) s.clientHelloWritten = clientHelloWritten @@ -591,14 +591,14 @@ runLoop: s.framer.QueueControlFrame(&wire.PingFrame{}) s.keepAlivePingSent = true } else if !s.handshakeComplete && now.Sub(s.sessionCreationTime) >= s.config.HandshakeTimeout { - if s.qlogger != nil { - s.qlogger.ClosedConnection(logging.CloseReasonHandshakeTimeout) + if s.tracer != nil { + s.tracer.ClosedConnection(logging.CloseReasonHandshakeTimeout) } s.destroyImpl(qerr.NewTimeoutError("Handshake did not complete in time")) continue } else if s.handshakeComplete && now.Sub(s.idleTimeoutStartTime()) >= s.idleTimeout { - if s.qlogger != nil { - s.qlogger.ClosedConnection(logging.CloseReasonIdleTimeout) + if s.tracer != nil { + s.tracer.ClosedConnection(logging.CloseReasonIdleTimeout) } s.destroyImpl(qerr.NewTimeoutError("No recent network activity")) continue @@ -610,8 +610,8 @@ runLoop: } s.handleCloseError(closeErr) - if !errors.Is(closeErr.err, errCloseForRecreating{}) && s.qlogger != nil { - if err := s.qlogger.Export(); err != nil { + if !errors.Is(closeErr.err, errCloseForRecreating{}) && s.tracer != nil { + if err := s.tracer.Export(); err != nil { s.logger.Errorf("exporting qlog failed: %s", err) } } @@ -726,28 +726,28 @@ func (s *session) handlePacketImpl(rp *receivedPacket) bool { hdr, packetData, rest, err := wire.ParsePacket(p.data, s.srcConnIDLen) if err != nil { - if s.qlogger != nil { + if s.tracer != nil { dropReason := logging.PacketDropHeaderParseError if err == wire.ErrUnsupportedVersion { dropReason = logging.PacketDropUnsupportedVersion } - s.qlogger.DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(data)), dropReason) + s.tracer.DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(data)), dropReason) } s.logger.Debugf("error parsing packet: %s", err) break } if hdr.IsLongHeader && hdr.Version != s.version { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(data)), logging.PacketDropUnexpectedVersion) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(data)), logging.PacketDropUnexpectedVersion) } s.logger.Debugf("Dropping packet with version %x. Expected %x.", hdr.Version, s.version) break } if counter > 0 && !hdr.DestConnectionID.Equal(lastConnID) { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(data)), logging.PacketDropUnknownConnectionID) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(data)), logging.PacketDropUnknownConnectionID) } s.logger.Debugf("coalesced packet has different destination connection ID: %s, expected %s", hdr.DestConnectionID, lastConnID) break @@ -790,15 +790,15 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool / // The server can change the source connection ID with the first Handshake packet. // After this, all packets with a different source connection have to be ignored. if s.receivedFirstPacket && hdr.IsLongHeader && !hdr.SrcConnectionID.Equal(s.handshakeDestConnID) { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropUnknownConnectionID) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropUnknownConnectionID) } s.logger.Debugf("Dropping %s packet (%d bytes) with unexpected source connection ID: %s (expected %s)", hdr.PacketType(), len(p.data), hdr.SrcConnectionID, s.handshakeDestConnID) return false } // drop 0-RTT packets, if we are a client if s.perspective == protocol.PerspectiveClient && hdr.Type == protocol.PacketType0RTT { - s.qlogger.DroppedPacket(logging.PacketType0RTT, protocol.ByteCount(len(p.data)), logging.PacketDropKeyUnavailable) + s.tracer.DroppedPacket(logging.PacketType0RTT, protocol.ByteCount(len(p.data)), logging.PacketDropKeyUnavailable) return false } @@ -806,8 +806,8 @@ 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(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropKeyUnavailable) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropKeyUnavailable) } s.logger.Debugf("Dropping %s packet (%d bytes) because we already dropped the keys.", hdr.PacketType(), len(p.data)) case handshake.ErrKeysNotYetAvailable: @@ -820,8 +820,8 @@ 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(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) } s.logger.Debugf("Dropping %s packet (%d bytes) that could not be unpacked. Error: %s", hdr.PacketType(), len(p.data), err) } @@ -835,8 +835,8 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool / if s.receivedPacketHandler.IsPotentiallyDuplicate(packet.packetNumber, packet.encryptionLevel) { s.logger.Debugf("Dropping (potentially) duplicate packet.") - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropDuplicate) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropDuplicate) } return false } @@ -851,23 +851,23 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool / func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was this a valid Retry */ { (&wire.ExtendedHeader{Header: *hdr}).Log(s.logger) if s.perspective == protocol.PerspectiveServer { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) } s.logger.Debugf("Ignoring Retry.") return false } if s.receivedFirstPacket { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) } s.logger.Debugf("Ignoring Retry, since we already received a packet.") return false } destConnID := s.connIDManager.Get() if hdr.SrcConnectionID.Equal(destConnID) { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropUnexpectedPacket) } s.logger.Debugf("Ignoring Retry, since the server didn't change the Source Connection ID.") return false @@ -881,8 +881,8 @@ func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was t tag := handshake.GetRetryIntegrityTag(data[:len(data)-16], destConnID) if !bytes.Equal(data[len(data)-16:], tag[:]) { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropPayloadDecryptError) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(data)), logging.PacketDropPayloadDecryptError) } s.logger.Debugf("Ignoring spoofed Retry. Integrity Tag doesn't match.") return false @@ -890,8 +890,8 @@ func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was t s.logger.Debugf("<- Received Retry: %#v", hdr) s.logger.Debugf("Switching destination connection ID to: %s", hdr.SrcConnectionID) - if s.qlogger != nil { - s.qlogger.ReceivedRetry(hdr) + if s.tracer != nil { + s.tracer.ReceivedRetry(hdr) } newDestConnID := hdr.SrcConnectionID s.receivedRetry = true @@ -911,16 +911,16 @@ func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was t func (s *session) handleVersionNegotiationPacket(p *receivedPacket) { if s.perspective == protocol.PerspectiveServer || // servers never receive version negotiation packets s.receivedFirstPacket || s.versionNegotiated { // ignore delayed / duplicated version negotiation packets - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) } return } hdr, _, _, err := wire.ParsePacket(p.data, 0) if err != nil { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) } s.logger.Debugf("Error parsing Version Negotiation packet: %s", err) return @@ -928,8 +928,8 @@ func (s *session) handleVersionNegotiationPacket(p *receivedPacket) { for _, v := range hdr.SupportedVersions { if v == s.version { - if s.qlogger != nil { - s.qlogger.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) } // The Version Negotiation packet contains the version that we offered. // This might be a packet sent by an attacker, or it was corrupted. @@ -938,8 +938,8 @@ func (s *session) handleVersionNegotiationPacket(p *receivedPacket) { } s.logger.Infof("Received a Version Negotiation packet. Supported Versions: %s", hdr.SupportedVersions) - if s.qlogger != nil { - s.qlogger.ReceivedVersionNegotiationPacket(hdr) + if s.tracer != nil { + s.tracer.ReceivedVersionNegotiationPacket(hdr) } newVersion, ok := protocol.ChooseSupportedVersion(s.config.Versions, hdr.SupportedVersions) if !ok { @@ -985,8 +985,8 @@ func (s *session) handleUnpackedPacket( s.handshakeDestConnID = packet.hdr.SrcConnectionID s.connIDManager.ChangeInitialConnID(packet.hdr.SrcConnectionID) } - if s.qlogger != nil { - s.qlogger.StartedConnection( + if s.tracer != nil { + s.tracer.StartedConnection( s.conn.LocalAddr(), s.conn.RemoteAddr(), s.version, @@ -1019,12 +1019,12 @@ func (s *session) handleUnpackedPacket( if ackhandler.IsFrameAckEliciting(frame) { isAckEliciting = true } - if s.traceCallback != nil || s.qlogger != nil { + if s.traceCallback != nil || s.tracer != nil { frames = append(frames, frame) } // Only process frames now if we're not logging. // If we're logging, we need to make sure that the packet_received event is logged first. - if s.qlogger == nil { + if s.tracer == nil { if err := s.handleFrame(frame, packet.encryptionLevel); err != nil { return err } @@ -1043,8 +1043,8 @@ func (s *session) handleUnpackedPacket( Frames: frames, }) } - if s.qlogger != nil { - s.qlogger.ReceivedPacket(packet.hdr, packetSize, frames) + if s.tracer != nil { + s.tracer.ReceivedPacket(packet.hdr, packetSize, frames) for _, frame := range frames { if err := s.handleFrame(frame, packet.encryptionLevel); err != nil { return err @@ -1283,8 +1283,8 @@ func (s *session) handleCloseError(closeErr closeError) { if closeErr.err == nil { closeErr.err = qerr.NewApplicationError(0, "") } - if statelessReset, ok := closeErr.err.(interface{ StatelessResetToken() *[16]byte }); ok && s.qlogger != nil { - s.qlogger.ReceivedStatelessReset(statelessReset.StatelessResetToken()) + if statelessReset, ok := closeErr.err.(interface{ StatelessResetToken() *[16]byte }); ok && s.tracer != nil { + s.tracer.ReceivedStatelessReset(statelessReset.StatelessResetToken()) } var quicErr *qerr.QuicError @@ -1319,8 +1319,8 @@ func (s *session) dropEncryptionLevel(encLevel protocol.EncryptionLevel) { } s.sentPacketHandler.DropPackets(encLevel) s.receivedPacketHandler.DropPackets(encLevel) - if s.qlogger != nil { - s.qlogger.DroppedEncryptionLevel(encLevel) + if s.tracer != nil { + s.tracer.DroppedEncryptionLevel(encLevel) } } @@ -1349,8 +1349,8 @@ func (s *session) processTransportParametersImpl(params *wire.TransportParameter if s.logger.Debug() { s.logger.Debugf("Processed Transport Parameters: %s", params) } - if s.qlogger != nil { - s.qlogger.ReceivedTransportParameters(params) + if s.tracer != nil { + s.tracer.ReceivedTransportParameters(params) } // check the initial_source_connection_id @@ -1556,13 +1556,13 @@ func (s *session) sendConnectionClose(quicErr *qerr.QuicError) ([]byte, error) { } func (s *session) logPacketContents(now time.Time, p *packetContents) { - // qlog - if s.qlogger != nil { + // tracing + if s.tracer != nil { frames := make([]wire.Frame, 0, len(p.frames)) for _, f := range p.frames { frames = append(frames, f.Frame) } - s.qlogger.SentPacket(p.header, p.length, p.ack, frames) + s.tracer.SentPacket(p.header, p.length, p.ack, frames) } // quic-trace @@ -1676,15 +1676,15 @@ 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(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropDOSPrevention) + if s.tracer != nil { + s.tracer.DroppedPacket(logging.PacketTypeFromHeader(hdr), protocol.ByteCount(len(p.data)), logging.PacketDropDOSPrevention) } s.logger.Infof("Dropping undecryptable packet (%d bytes). Undecryptable packet queue full.", len(p.data)) return } s.logger.Infof("Queueing packet (%d bytes) for later decryption", len(p.data)) - if s.qlogger != nil { - s.qlogger.BufferedPacket(logging.PacketTypeFromHeader(hdr)) + if s.tracer != nil { + s.tracer.BufferedPacket(logging.PacketTypeFromHeader(hdr)) } s.undecryptablePackets = append(s.undecryptablePackets, p) } diff --git a/session_test.go b/session_test.go index 37f6ab49..41f62b6a 100644 --- a/session_test.go +++ b/session_test.go @@ -49,7 +49,7 @@ var _ = Describe("Session", func() { streamManager *MockStreamManager packer *MockPacker cryptoSetup *mocks.MockCryptoSetup - qlogger *mocks.MockTracer + tracer *mocks.MockTracer ) remoteAddr := &net.UDPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 1337} localAddr := &net.UDPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 7331} @@ -87,9 +87,9 @@ var _ = Describe("Session", func() { mconn.EXPECT().LocalAddr().Return(localAddr).AnyTimes() tokenGenerator, err := handshake.NewTokenGenerator() Expect(err).ToNot(HaveOccurred()) - qlogger = mocks.NewMockTracer(mockCtrl) - qlogger.EXPECT().SentTransportParameters(gomock.Any()) - qlogger.EXPECT().UpdatedKeyFromTLS(gomock.Any(), gomock.Any()).AnyTimes() + tracer = mocks.NewMockTracer(mockCtrl) + tracer.EXPECT().SentTransportParameters(gomock.Any()) + tracer.EXPECT().UpdatedKeyFromTLS(gomock.Any(), gomock.Any()).AnyTimes() sess = newSession( mconn, sessionRunner, @@ -103,7 +103,7 @@ var _ = Describe("Session", func() { nil, // tls.Config tokenGenerator, false, - qlogger, + tracer, utils.DefaultLogger, protocol.VersionTLS, ).(*session) @@ -337,7 +337,7 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - qlogger.EXPECT().Export() + tracer.EXPECT().Export() go func() { defer GinkgoRecover() @@ -361,7 +361,7 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - qlogger.EXPECT().Export() + tracer.EXPECT().Export() go func() { defer GinkgoRecover() @@ -429,7 +429,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: buffer}, nil }) mconn.EXPECT().Write([]byte("connection close")) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -442,7 +442,7 @@ var _ = Describe("Session", func() { cryptoSetup.EXPECT().Close() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() sess.shutdown() Eventually(areSessionsRunning).Should(BeFalse()) @@ -461,7 +461,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.CloseWithError(0x1337, "test error") Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -481,7 +481,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.closeLocal(testErr) Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -494,7 +494,7 @@ var _ = Describe("Session", func() { sessionRunner.EXPECT().Remove(gomock.Any()).AnyTimes() cryptoSetup.EXPECT().Close() // don't EXPECT any calls to mconn.Write() - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.destroy(testErr) Eventually(areSessionsRunning).Should(BeFalse()) expectedRunErr = testErr @@ -516,7 +516,7 @@ var _ = Describe("Session", func() { }() Consistently(returned).ShouldNot(BeClosed()) mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(returned).Should(BeClosed()) }) @@ -545,9 +545,9 @@ var _ = Describe("Session", func() { }, nil }) gomock.InOrder( - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()), - qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()), - qlogger.EXPECT().Export(), + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()), + tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()), + tracer.EXPECT().Export(), ) // don't EXPECT any calls to packer.PackPacket() sess.handlePacket(&receivedPacket{ @@ -587,14 +587,14 @@ var _ = Describe("Session", func() { Version: sess.version, Token: []byte("foobar"), }}, make([]byte, 16) /* Retry integrity tag */) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) + tracer.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) It("drops Version Negotiation packets", func() { b, err := wire.ComposeVersionNegotiation(srcConnID, destConnID, sess.config.Versions) Expect(err).ToNot(HaveOccurred()) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(b)), logging.PacketDropUnexpectedPacket) + tracer.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(b)), logging.PacketDropUnexpectedPacket) Expect(sess.handlePacketImpl(&receivedPacket{ data: b, buffer: getPacketBuffer(), @@ -611,7 +611,7 @@ var _ = Describe("Session", func() { PacketNumberLen: protocol.PacketNumberLen2, }, nil) p.data[0] ^= 0x40 // unset the QUIC bit - qlogger.EXPECT().DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) + tracer.EXPECT().DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) @@ -624,7 +624,7 @@ var _ = Describe("Session", func() { }, PacketNumberLen: protocol.PacketNumberLen2, }, nil) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(p.data)), logging.PacketDropUnsupportedVersion) + tracer.EXPECT().DroppedPacket(logging.PacketTypeNotDetermined, protocol.ByteCount(len(p.data)), logging.PacketDropUnsupportedVersion) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) @@ -646,7 +646,7 @@ var _ = Describe("Session", func() { }, PacketNumberLen: protocol.PacketNumberLen2, }, nil) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) + tracer.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) @@ -671,8 +671,8 @@ var _ = Describe("Session", func() { ) sess.receivedPacketHandler = rph packet.rcvTime = rcvTime - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - qlogger.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), nil) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), nil) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -699,8 +699,8 @@ var _ = Describe("Session", func() { ) sess.receivedPacketHandler = rph packet.rcvTime = rcvTime - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - qlogger.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), []wire.Frame{&wire.PingFrame{}}) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), []wire.Frame{&wire.PingFrame{}}) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -720,7 +720,7 @@ var _ = Describe("Session", func() { rph := mockackhandler.NewMockReceivedPacketHandler(mockCtrl) rph.EXPECT().IsPotentiallyDuplicate(protocol.PacketNumber(0x1337), protocol.Encryption1RTT).Return(true) sess.receivedPacketHandler = rph - qlogger.EXPECT().DroppedPacket(logging.PacketType1RTT, protocol.ByteCount(len(packet.data)), logging.PacketDropDuplicate) + tracer.EXPECT().DroppedPacket(logging.PacketType1RTT, protocol.ByteCount(len(packet.data)), logging.PacketDropDuplicate) Expect(sess.handlePacketImpl(packet)).To(BeFalse()) }) @@ -746,11 +746,11 @@ var _ = Describe("Session", func() { PacketNumber: 0x1337, PacketNumberLen: protocol.PacketNumberLen2, }, []byte("foobar")) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) + tracer.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) sess.handlePacket(p) Consistently(sess.Context().Done()).ShouldNot(BeClosed()) // make the go routine return - qlogger.EXPECT().Export() + tracer.EXPECT().Export() mconn.EXPECT().Write(gomock.Any()) sess.closeLocal(errors.New("close")) Eventually(sess.Context().Done()).Should(BeClosed()) @@ -776,7 +776,7 @@ var _ = Describe("Session", func() { Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, }, nil) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.handlePacket(packet) Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -794,14 +794,14 @@ var _ = Describe("Session", func() { runErr <- sess.run() }() expectReplaceWithClosed() - qlogger.EXPECT().DroppedPacket(logging.PacketType1RTT, gomock.Any(), logging.PacketDropPayloadDecryptError) + tracer.EXPECT().DroppedPacket(logging.PacketType1RTT, gomock.Any(), logging.PacketDropPayloadDecryptError) sess.handlePacket(getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, }, nil)) Consistently(runErr).ShouldNot(Receive()) // make the go routine return - qlogger.EXPECT().Export() + tracer.EXPECT().Export() mconn.EXPECT().Write(gomock.Any()) sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -825,7 +825,7 @@ var _ = Describe("Session", func() { }() expectReplaceWithClosed() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.handlePacket(getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, @@ -867,12 +867,12 @@ var _ = Describe("Session", func() { data: []byte{0}, // one PADDING frame }, nil) p1 := getPacket(hdr1, nil) - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p1.data)), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p1.data)), gomock.Any()) Expect(sess.handlePacketImpl(p1)).To(BeTrue()) // The next packet has to be ignored, since the source connection ID doesn't match. p2 := getPacket(hdr2, nil) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p2.data)), logging.PacketDropUnknownConnectionID) + tracer.EXPECT().DroppedPacket(logging.PacketTypeHandshake, protocol.ByteCount(len(p2.data)), logging.PacketDropUnknownConnectionID) Expect(sess.handlePacketImpl(p2)).To(BeFalse()) }) @@ -892,7 +892,7 @@ var _ = Describe("Session", func() { } unpacker.EXPECT().Unpack(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil, handshake.ErrKeysNotYetAvailable) packet := getPacket(hdr, nil) - qlogger.EXPECT().BufferedPacket(logging.PacketTypeHandshake) + tracer.EXPECT().BufferedPacket(logging.PacketTypeHandshake) Expect(sess.handlePacketImpl(packet)).To(BeFalse()) Expect(sess.undecryptablePackets).To(Equal([]*receivedPacket{packet})) }) @@ -909,15 +909,15 @@ var _ = Describe("Session", func() { PacketNumberLen: protocol.PacketNumberLen1, }, nil) packet.remoteAddr = &net.IPAddr{IP: net.IPv4(192, 168, 0, 100)} - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) }) Context("coalesced packets", func() { BeforeEach(func() { - qlogger.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).MaxTimes(1) + tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).MaxTimes(1) }) getPacketWithLength := func(connID protocol.ConnectionID, length protocol.ByteCount) (int /* header length */, *receivedPacket) { hdr := &wire.ExtendedHeader{ @@ -948,7 +948,7 @@ var _ = Describe("Session", func() { hdr: &wire.ExtendedHeader{}, }, nil }) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -974,8 +974,8 @@ var _ = Describe("Session", func() { }, nil }) gomock.InOrder( - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), ) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) @@ -997,8 +997,8 @@ var _ = Describe("Session", func() { }), ) gomock.InOrder( - qlogger.EXPECT().BufferedPacket(gomock.Any()), - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), + tracer.EXPECT().BufferedPacket(gomock.Any()), + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), ) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) @@ -1022,8 +1022,8 @@ var _ = Describe("Session", func() { _, packet2 := getPacketWithLength(wrongConnID, 123) // don't EXPECT any more calls to unpacker.Unpack() gomock.InOrder( - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), - qlogger.EXPECT().DroppedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), logging.PacketDropUnknownConnectionID), + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()), + tracer.EXPECT().DroppedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), logging.PacketDropUnknownConnectionID), ) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) @@ -1044,7 +1044,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) Eventually(sessionDone).Should(BeClosed()) @@ -1074,7 +1074,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackPacket().Return(nil, nil).AnyTimes() sent := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(sent) }) - qlogger.EXPECT().SentPacket(p.header, p.buffer.Len(), nil, []wire.Frame{}) + tracer.EXPECT().SentPacket(p.header, p.buffer.Len(), nil, []wire.Frame{}) sess.scheduleSending() Eventually(sent).Should(BeClosed()) }) @@ -1120,7 +1120,7 @@ var _ = Describe("Session", func() { runSession() sent := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(sent) }) - qlogger.EXPECT().SentPacket(p.header, p.length, nil, []wire.Frame{}) + tracer.EXPECT().SentPacket(p.header, p.length, nil, []wire.Frame{}) sess.scheduleSending() Eventually(sent).Should(BeClosed()) frames, _ := sess.framer.AppendControlFrames(nil, 1000) @@ -1175,7 +1175,7 @@ var _ = Describe("Session", func() { runSession() sent := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(sent) }) - qlogger.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) sess.scheduleSending() Eventually(sent).Should(BeClosed()) }) @@ -1196,7 +1196,7 @@ var _ = Describe("Session", func() { runSession() sent := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(sent) }) - qlogger.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) + tracer.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) sess.scheduleSending() Eventually(sent).Should(BeClosed()) // We're using a mock packet packer in this test. @@ -1211,7 +1211,7 @@ var _ = Describe("Session", func() { var sph *mockackhandler.MockSentPacketHandler BeforeEach(func() { - qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() sph = mockackhandler.NewMockSentPacketHandler(mockCtrl) sph.EXPECT().GetLossDetectionTimeout().AnyTimes() sess.handshakeConfirmed = true @@ -1226,7 +1226,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1348,7 +1348,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1374,7 +1374,7 @@ var _ = Describe("Session", func() { // only EXPECT calls after scheduleSending is called written := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(written) }) - qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() sess.scheduleSending() Eventually(written).Should(BeClosed()) }) @@ -1398,7 +1398,7 @@ var _ = Describe("Session", func() { written := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(written) }) - qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() + tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake().MaxTimes(1) @@ -1460,10 +1460,10 @@ var _ = Describe("Session", func() { }), ) gomock.InOrder( - qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []wire.Frame) { + tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []wire.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeInitial)) }), - qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []wire.Frame) { + tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Do(func(hdr *wire.ExtendedHeader, _ protocol.ByteCount, _ *wire.AckFrame, _ []wire.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeHandshake)) }), ) @@ -1486,7 +1486,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1522,7 +1522,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1566,7 +1566,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1577,7 +1577,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() - qlogger.EXPECT().Export() + tracer.EXPECT().Export() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake() @@ -1630,7 +1630,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1648,7 +1648,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(done).Should(BeClosed()) }) @@ -1668,7 +1668,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() Expect(sess.CloseWithError(0x1337, testErr.Error())).To(Succeed()) Eventually(done).Should(BeClosed()) }) @@ -1690,7 +1690,7 @@ var _ = Describe("Session", func() { Expect(sess.earlySessionReady()).ToNot(BeClosed()) sessionRunner.EXPECT().GetStatelessResetToken(gomock.Any()).Times(2) sessionRunner.EXPECT().Add(gomock.Any(), sess).Times(2) - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Expect(sess.earlySessionReady()).To(BeClosed()) }) @@ -1700,7 +1700,7 @@ var _ = Describe("Session", func() { setRemoteIdleTimeout := func(t time.Duration) { streamManager.EXPECT().UpdateLimits(gomock.Any()) packer.EXPECT().HandleTransportParameters(gomock.Any()) - qlogger.EXPECT().ReceivedTransportParameters(gomock.Any()) + tracer.EXPECT().ReceivedTransportParameters(gomock.Any()) sess.processTransportParameters(&wire.TransportParameters{ MaxIdleTimeout: t, InitialSourceConnectionID: destConnID, @@ -1728,7 +1728,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1789,8 +1789,8 @@ var _ = Describe("Session", func() { done := make(chan struct{}) cryptoSetup.EXPECT().Close() gomock.InOrder( - qlogger.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), - qlogger.EXPECT().Export(), + tracer.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), + tracer.EXPECT().Export(), ) go func() { defer GinkgoRecover() @@ -1811,8 +1811,8 @@ var _ = Describe("Session", func() { sessionRunner.EXPECT().Remove(gomock.Any()).Times(2) cryptoSetup.EXPECT().Close() gomock.InOrder( - qlogger.EXPECT().ClosedConnection(logging.CloseReasonHandshakeTimeout), - qlogger.EXPECT().Export(), + tracer.EXPECT().ClosedConnection(logging.CloseReasonHandshakeTimeout), + tracer.EXPECT().Export(), ) done := make(chan struct{}) go func() { @@ -1836,7 +1836,7 @@ var _ = Describe("Session", func() { Expect(quicErr.ErrorCode).To(Equal(qerr.NoError)) return &coalescedPacket{buffer: getPacketBuffer()}, nil }) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() // the handshake timeout is irrelevant here, since it depends on the time the session was created, // and not on the last network activity go func() { @@ -1861,8 +1861,8 @@ var _ = Describe("Session", func() { ) cryptoSetup.EXPECT().Close() gomock.InOrder( - qlogger.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), - qlogger.EXPECT().Export(), + tracer.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), + tracer.EXPECT().Export(), ) sess.idleTimeout = 0 done := make(chan struct{}) @@ -1897,7 +1897,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1981,7 +1981,7 @@ var _ = Describe("Client Session", func() { packer *MockPacker mconn *MockConnection cryptoSetup *mocks.MockCryptoSetup - qlogger *mocks.MockTracer + tracer *mocks.MockTracer tlsConf *tls.Config quicConf *Config ) @@ -2020,9 +2020,9 @@ var _ = Describe("Client Session", func() { tlsConf = &tls.Config{} } sessionRunner = NewMockSessionRunner(mockCtrl) - qlogger = mocks.NewMockTracer(mockCtrl) - qlogger.EXPECT().SentTransportParameters(gomock.Any()) - qlogger.EXPECT().UpdatedKeyFromTLS(gomock.Any(), gomock.Any()).AnyTimes() + tracer = mocks.NewMockTracer(mockCtrl) + tracer.EXPECT().SentTransportParameters(gomock.Any()) + tracer.EXPECT().UpdatedKeyFromTLS(gomock.Any(), gomock.Any()).AnyTimes() sess = newClientSession( mconn, sessionRunner, @@ -2034,7 +2034,7 @@ var _ = Describe("Client Session", func() { protocol.VersionTLS, false, false, - qlogger, + tracer, utils.DefaultLogger, protocol.VersionTLS, ).(*session) @@ -2071,14 +2071,14 @@ var _ = Describe("Client Session", func() { }, PacketNumberLen: protocol.PacketNumberLen2, }, []byte("foobar")) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p.data)), nil) + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p.data)), nil) Expect(sess.handlePacketImpl(p)).To(BeTrue()) // make sure the go routine returns packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -2106,7 +2106,7 @@ var _ = Describe("Client Session", func() { DestConnectionID: srcConnID, SrcConnectionID: destConnID, } - qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handleSinglePacket(&receivedPacket{buffer: getPacketBuffer()}, hdr)).To(BeTrue()) }) @@ -2154,7 +2154,7 @@ var _ = Describe("Client Session", func() { errChan <- sess.run() }() sessionRunner.EXPECT().Remove(srcConnID) - qlogger.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any()).Do(func(hdr *wire.Header) { + tracer.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any()).Do(func(hdr *wire.Header) { Expect(hdr.Version).To(BeZero()) Expect(hdr.SupportedVersions).To(And( ContainElement(protocol.VersionNumber(4321)), @@ -2181,8 +2181,8 @@ var _ = Describe("Client Session", func() { }() sessionRunner.EXPECT().Remove(srcConnID).MaxTimes(1) gomock.InOrder( - qlogger.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any()), - qlogger.EXPECT().Export(), + tracer.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any()), + tracer.EXPECT().Export(), ) cryptoSetup.EXPECT().Close() Expect(sess.handlePacketImpl(getVNP(12345678))).To(BeFalse()) @@ -2195,14 +2195,14 @@ var _ = Describe("Client Session", func() { It("ignores Version Negotiation packets that offer the current version", func() { p := getVNP(sess.version) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) + tracer.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedVersion) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) It("ignores unparseable Version Negotiation packets", func() { p := getVNP(sess.version) p.data = p.data[:len(p.data)-2] - qlogger.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) + tracer.EXPECT().DroppedPacket(logging.PacketTypeVersionNegotiation, protocol.ByteCount(len(p.data)), logging.PacketDropHeaderParseError) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) }) @@ -2238,7 +2238,7 @@ var _ = Describe("Client Session", func() { sph.EXPECT().ResetForRetry() cryptoSetup.EXPECT().ChangeConnectionID(protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}) packer.EXPECT().SetToken([]byte("foobar")) - qlogger.EXPECT().ReceivedRetry(gomock.Any()).Do(func(hdr *wire.Header) { + tracer.EXPECT().ReceivedRetry(gomock.Any()).Do(func(hdr *wire.Header) { Expect(hdr.DestConnectionID).To(Equal(retryHdr.DestConnectionID)) Expect(hdr.SrcConnectionID).To(Equal(retryHdr.SrcConnectionID)) Expect(hdr.Token).To(Equal(retryHdr.Token)) @@ -2249,14 +2249,14 @@ var _ = Describe("Client Session", func() { It("ignores Retry packets after receiving a regular packet", func() { sess.receivedFirstPacket = true p := getPacket(retryHdr, getRetryTag(retryHdr)) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) + tracer.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) It("ignores Retry packets if the server didn't change the connection ID", func() { retryHdr.SrcConnectionID = destConnID p := getPacket(retryHdr, getRetryTag(retryHdr)) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) + tracer.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropUnexpectedPacket) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) @@ -2264,7 +2264,7 @@ var _ = Describe("Client Session", func() { tag := getRetryTag(retryHdr) tag[0]++ p := getPacket(retryHdr, tag) - qlogger.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) + tracer.EXPECT().DroppedPacket(logging.PacketTypeRetry, protocol.ByteCount(len(p.data)), logging.PacketDropPayloadDecryptError) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) }) @@ -2295,7 +2295,7 @@ var _ = Describe("Client Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil).MaxTimes(1) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - qlogger.EXPECT().Export() + tracer.EXPECT().Export() } closed = true } @@ -2320,7 +2320,7 @@ var _ = Describe("Client Session", func() { } packer.EXPECT().HandleTransportParameters(gomock.Any()) packer.EXPECT().PackCoalescedPacket(protocol.MaxByteCount).MaxTimes(1) - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) // make sure the connection ID is not retired cf, _ := sess.framer.AppendControlFrames(nil, protocol.MaxByteCount) @@ -2340,7 +2340,7 @@ var _ = Describe("Client Session", func() { MaxIdleTimeout: 18 * time.Second, } packer.EXPECT().HandleTransportParameters(gomock.Any()) - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Expect(sess.idleTimeout).To(Equal(18 * time.Second)) }) @@ -2353,7 +2353,7 @@ var _ = Describe("Client Session", func() { StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, } expectClose() - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: expected initial_source_connection_id to equal 0xdeadbeef, is 0xdecafbad"))) }) @@ -2366,7 +2366,7 @@ var _ = Describe("Client Session", func() { StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, } expectClose() - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: missing retry_source_connection_id"))) }) @@ -2380,7 +2380,7 @@ var _ = Describe("Client Session", func() { StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, } expectClose() - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: expected retry_source_connection_id to equal 0xdeadbeef, is 0xdeadc0de"))) }) @@ -2393,7 +2393,7 @@ var _ = Describe("Client Session", func() { StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, } expectClose() - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: received retry_source_connection_id, although no Retry was performed"))) }) @@ -2406,7 +2406,7 @@ var _ = Describe("Client Session", func() { StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, } expectClose() - qlogger.EXPECT().ReceivedTransportParameters(params) + tracer.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: expected original_destination_connection_id to equal 0xdeadbeef, is 0xdecafbad"))) }) @@ -2471,10 +2471,10 @@ var _ = Describe("Client Session", func() { hdr: hdr1, data: []byte{0}, // one PADDING frame }, nil) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handlePacketImpl(getPacket(hdr1, nil))).To(BeTrue()) // The next packet has to be ignored, since the source connection ID doesn't match. - qlogger.EXPECT().DroppedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().DroppedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handlePacketImpl(getPacket(hdr2, nil))).To(BeFalse()) }) @@ -2490,7 +2490,7 @@ var _ = Describe("Client Session", func() { PacketNumber: 0x42, PacketNumberLen: protocol.PacketNumberLen2, }, []byte("foobar")) - qlogger.EXPECT().DroppedPacket(logging.PacketType0RTT, protocol.ByteCount(len(p.data)), gomock.Any()) + tracer.EXPECT().DroppedPacket(logging.PacketType0RTT, protocol.ByteCount(len(p.data)), gomock.Any()) Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) @@ -2499,7 +2499,7 @@ var _ = Describe("Client Session", func() { It("fails on Initial-level ACK for unsent packet", func() { ackFrame := testutils.ComposeAckFrame(0, 0) initialPacket := testutils.ComposeInitialPacket(destConnID, srcConnID, sess.version, destConnID, []wire.Frame{ackFrame}) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeFalse()) }) @@ -2508,7 +2508,7 @@ var _ = Describe("Client Session", func() { It("fails on Initial-level CONNECTION_CLOSE frame", func() { connCloseFrame := testutils.ComposeConnCloseFrame() initialPacket := testutils.ComposeInitialPacket(destConnID, srcConnID, sess.version, destConnID, []wire.Frame{connCloseFrame}) - qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeTrue()) }) @@ -2523,10 +2523,10 @@ var _ = Describe("Client Session", func() { cryptoSetup.EXPECT().ChangeConnectionID(newSrcConnID) packer.EXPECT().SetToken([]byte("foobar")) - qlogger.EXPECT().ReceivedRetry(gomock.Any()) + tracer.EXPECT().ReceivedRetry(gomock.Any()) sess.handlePacketImpl(wrapPacket(testutils.ComposeRetryPacket(newSrcConnID, destConnID, destConnID, []byte("foobar"), sess.version))) initialPacket := testutils.ComposeInitialPacket(sess.connIDManager.Get(), srcConnID, sess.version, sess.connIDManager.Get(), nil) - qlogger.EXPECT().DroppedPacket(gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().DroppedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeFalse()) })