diff --git a/internal/mocks/connection_tracer.go b/internal/mocks/connection_tracer.go index b8ad6477..73e63d8b 100644 --- a/internal/mocks/connection_tracer.go +++ b/internal/mocks/connection_tracer.go @@ -64,7 +64,7 @@ func (mr *MockConnectionTracerMockRecorder) Close() *gomock.Call { } // ClosedConnection mocks base method -func (m *MockConnectionTracer) ClosedConnection(arg0 logging.TimeoutReason) { +func (m *MockConnectionTracer) ClosedConnection(arg0 logging.CloseReason) { m.ctrl.T.Helper() m.ctrl.Call(m, "ClosedConnection", arg0) } @@ -159,18 +159,6 @@ func (mr *MockConnectionTracerMockRecorder) ReceivedRetry(arg0 interface{}) *gom return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedRetry", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedRetry), arg0) } -// ReceivedStatelessReset mocks base method -func (m *MockConnectionTracer) ReceivedStatelessReset(arg0 *[16]byte) { - m.ctrl.T.Helper() - m.ctrl.Call(m, "ReceivedStatelessReset", arg0) -} - -// ReceivedStatelessReset indicates an expected call of ReceivedStatelessReset -func (mr *MockConnectionTracerMockRecorder) ReceivedStatelessReset(arg0 interface{}) *gomock.Call { - mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedStatelessReset", reflect.TypeOf((*MockConnectionTracer)(nil).ReceivedStatelessReset), arg0) -} - // ReceivedTransportParameters mocks base method func (m *MockConnectionTracer) ReceivedTransportParameters(arg0 *wire.TransportParameters) { m.ctrl.T.Helper() diff --git a/logging/close_reason.go b/logging/close_reason.go new file mode 100644 index 00000000..6c0e32be --- /dev/null +++ b/logging/close_reason.go @@ -0,0 +1,68 @@ +package logging + +// A CloseReason is the reason why a QUIC connection is closed. +// It falls in one of 4 categories: +// 1. The application closed the connection (with an application-specific error code). +// 2. The transport closed the connection with a transport-error code. +// 3. The connection timed out, either during the handshake, or due to an idle timeout. +// 4. A stateless reset was received. +type CloseReason struct { + remote bool + applicationError *ApplicationError + transportError *TransportError + + timeout *TimeoutReason + statelessResetToken *[16]byte +} + +// NewApplicationCloseReason creates a new CloseReason for an application error. +func NewApplicationCloseReason(errorCode ApplicationError, remote bool) CloseReason { + return CloseReason{remote: remote, applicationError: &errorCode} +} + +// NewTransportCloseReason creates a new CloseReason for a transport error. +func NewTransportCloseReason(errorCode TransportError, remote bool) CloseReason { + return CloseReason{remote: remote, transportError: &errorCode} +} + +// NewTimeoutCloseReason creates a new CloseReason for a connection timeout. +func NewTimeoutCloseReason(r TimeoutReason) CloseReason { + return CloseReason{timeout: &r} +} + +// NewStatelessResetCloseReason creates a new CloseReason for a stateless reset. +func NewStatelessResetCloseReason(token *[16]byte) CloseReason { + return CloseReason{statelessResetToken: token} +} + +// ApplicationError gets the application error. +func (r *CloseReason) ApplicationError() (errorCode ApplicationError, remote bool, ok bool) { + if r.applicationError == nil { + return + } + return *r.applicationError, r.remote, true +} + +// TransportError gets the transport error. +func (r *CloseReason) TransportError() (errorCode TransportError, remote bool, ok bool) { + if r.transportError == nil { + return + } + return *r.transportError, r.remote, true +} + +// Timeout gets the timeout error. +func (r *CloseReason) Timeout() (reason TimeoutReason, ok bool) { + if r.timeout == nil { + return + } + return *r.timeout, true +} + +// StatelessReset gets the stateless reset token. +func (r *CloseReason) StatelessReset() (token [16]byte, ok bool) { + if r.statelessResetToken == nil { + return + } + return *r.statelessResetToken, true +} diff --git a/logging/close_reason_test.go b/logging/close_reason_test.go new file mode 100644 index 00000000..60b1a84e --- /dev/null +++ b/logging/close_reason_test.go @@ -0,0 +1,70 @@ +package logging + +import ( + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +var _ = Describe("Close Reason", func() { + checkNotApplicationError := func(r CloseReason) { + _, _, ok := r.ApplicationError() + Expect(ok).To(BeFalse()) + } + + checkNotTransportError := func(r CloseReason) { + _, _, ok := r.TransportError() + Expect(ok).To(BeFalse()) + } + + checkNotStatelessReset := func(r CloseReason) { + _, ok := r.StatelessReset() + ExpectWithOffset(1, ok).To(BeFalse()) + } + + checkNotTimeout := func(r CloseReason) { + _, ok := r.Timeout() + ExpectWithOffset(1, ok).To(BeFalse()) + } + + It("application errors", func() { + r := NewApplicationCloseReason(1337, true) + errorCode, remote, ok := r.ApplicationError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeTrue()) + Expect(errorCode).To(Equal(ApplicationError(1337))) + checkNotTransportError(r) + checkNotStatelessReset(r) + checkNotTimeout(r) + }) + + It("transport errors", func() { + r := NewTransportCloseReason(1337, true) + errorCode, remote, ok := r.TransportError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeTrue()) + Expect(errorCode).To(Equal(TransportError(1337))) + checkNotApplicationError(r) + checkNotStatelessReset(r) + checkNotTimeout(r) + }) + + It("transport errors", func() { + r := NewTimeoutCloseReason(TimeoutReasonIdle) + timeout, ok := r.Timeout() + Expect(ok).To(BeTrue()) + Expect(timeout).To(Equal(TimeoutReasonIdle)) + checkNotApplicationError(r) + checkNotTransportError(r) + checkNotStatelessReset(r) + }) + + It("stateless resets", func() { + r := NewStatelessResetCloseReason(&[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}) + token, ok := r.StatelessReset() + Expect(ok).To(BeTrue()) + Expect(token).To(Equal([16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16})) + checkNotApplicationError(r) + checkNotTransportError(r) + checkNotTimeout(r) + }) +}) diff --git a/logging/interface.go b/logging/interface.go index 1129c7f6..fb3ee975 100644 --- a/logging/interface.go +++ b/logging/interface.go @@ -84,14 +84,13 @@ type Tracer interface { // A ConnectionTracer records events. type ConnectionTracer interface { StartedConnection(local, remote net.Addr, version VersionNumber, srcConnID, destConnID ConnectionID) - ClosedConnection(TimeoutReason) + ClosedConnection(CloseReason) SentTransportParameters(*TransportParameters) ReceivedTransportParameters(*TransportParameters) SentPacket(hdr *ExtendedHeader, packetSize ByteCount, ack *AckFrame, frames []Frame) ReceivedVersionNegotiationPacket(*Header, []VersionNumber) ReceivedRetry(*Header) ReceivedPacket(hdr *ExtendedHeader, packetSize ByteCount, frames []Frame) - ReceivedStatelessReset(token *[16]byte) BufferedPacket(PacketType) DroppedPacket(PacketType, ByteCount, PacketDropReason) UpdatedMetrics(rttStats *RTTStats, cwnd ByteCount, bytesInFLight ByteCount, packetsInFlight int) diff --git a/qlog/qlog.go b/qlog/qlog.go index a2a6f171..fc976851 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -163,10 +163,17 @@ func (t *connectionTracer) StartedConnection(local, remote net.Addr, version pro t.mutex.Unlock() } -func (t *connectionTracer) ClosedConnection(r logging.TimeoutReason) { +func (t *connectionTracer) ClosedConnection(r logging.CloseReason) { t.mutex.Lock() - t.recordEvent(time.Now(), &eventConnectionClosed{Reason: timeoutReason(r)}) - t.mutex.Unlock() + defer t.mutex.Unlock() + + if reason, ok := r.Timeout(); ok { + t.recordEvent(time.Now(), &eventConnectionClosed{Reason: timeoutReason(reason)}) + } else if token, ok := r.StatelessReset(); ok { + t.recordEvent(time.Now(), &eventStatelessResetReceived{ + Token: &token, + }) + } } func (t *connectionTracer) SentTransportParameters(tp *wire.TransportParameters) { @@ -266,14 +273,6 @@ func (t *connectionTracer) ReceivedVersionNegotiationPacket(hdr *wire.Header, ve t.mutex.Unlock() } -func (t *connectionTracer) ReceivedStatelessReset(token *[16]byte) { - t.mutex.Lock() - t.recordEvent(time.Now(), &eventStatelessResetReceived{ - Token: token, - }) - t.mutex.Unlock() -} - func (t *connectionTracer) BufferedPacket(pt logging.PacketType) { t.mutex.Lock() t.recordEvent(time.Now(), &eventPacketBuffered{PacketType: packetType(pt)}) diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index 67003f5f..554f8cd6 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -172,7 +172,7 @@ var _ = Describe("Tracing", func() { }) It("records connection closes", func() { - tracer.ClosedConnection(logging.TimeoutReasonIdle) + tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonIdle)) entry := exportAndParseSingle() Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) Expect(entry.Category).To(Equal("transport")) @@ -182,6 +182,17 @@ var _ = Describe("Tracing", func() { Expect(ev).To(HaveKeyWithValue("trigger", "idle_timeout")) }) + It("records a received stateless reset packet", func() { + tracer.ClosedConnection(logging.NewStatelessResetCloseReason(&[16]byte{0x00, 0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff})) + entry := exportAndParseSingle() + Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) + Expect(entry.Category).To(Equal("transport")) + Expect(entry.Name).To(Equal("packet_received")) + ev := entry.Event + Expect(ev).To(HaveKeyWithValue("packet_type", "stateless_reset")) + Expect(ev).To(HaveKeyWithValue("stateless_reset_token", "00112233445566778899aabbccddeeff")) + }) + It("records sent transport parameters", func() { tracer.SentTransportParameters(&logging.TransportParameters{ InitialMaxStreamDataBidiLocal: 1000, @@ -403,17 +414,6 @@ var _ = Describe("Tracing", func() { Expect(header).To(HaveKey("scid")) }) - It("records a received Retry packet", func() { - tracer.ReceivedStatelessReset(&[16]byte{0x00, 0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff}) - entry := exportAndParseSingle() - Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) - Expect(entry.Category).To(Equal("transport")) - Expect(entry.Name).To(Equal("packet_received")) - ev := entry.Event - Expect(ev).To(HaveKeyWithValue("packet_type", "stateless_reset")) - Expect(ev).To(HaveKeyWithValue("stateless_reset_token", "00112233445566778899aabbccddeeff")) - }) - It("records buffered packets", func() { tracer.BufferedPacket(logging.PacketTypeHandshake) entry := exportAndParseSingle() diff --git a/session.go b/session.go index fc6c556d..2af7425c 100644 --- a/session.go +++ b/session.go @@ -593,13 +593,13 @@ runLoop: s.keepAlivePingSent = true } else if !s.handshakeComplete && now.Sub(s.sessionCreationTime) >= s.config.HandshakeTimeout { if s.tracer != nil { - s.tracer.ClosedConnection(logging.TimeoutReasonHandshake) + s.tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonHandshake)) } s.destroyImpl(qerr.NewTimeoutError("Handshake did not complete in time")) continue } else if s.handshakeComplete && now.Sub(s.idleTimeoutStartTime()) >= s.idleTimeout { if s.tracer != nil { - s.tracer.ClosedConnection(logging.TimeoutReasonIdle) + s.tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonIdle)) } s.destroyImpl(qerr.NewTimeoutError("No recent network activity")) continue @@ -1269,7 +1269,7 @@ func (s *session) closeRemote(e error) { }) } -// Close the connection. It sends a NO_ERROR transport error. +// Close the connection. It sends a NO_ERROR application error. // It waits until the run loop has stopped before returning func (s *session) shutdown() { s.closeLocal(nil) @@ -1286,9 +1286,6 @@ 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.tracer != nil { - s.tracer.ReceivedStatelessReset(statelessReset.StatelessResetToken()) - } var quicErr *qerr.QuicError var ok bool @@ -1299,6 +1296,19 @@ func (s *session) handleCloseError(closeErr closeError) { s.streamsMap.CloseWithError(quicErr) s.connIDManager.Close() + if s.tracer != nil { + // timeout errors are logged as soon as they occur (to distinguish between handshake and idle timeouts) + if nerr, ok := closeErr.err.(net.Error); !ok || !nerr.Timeout() { + if statelessReset, ok := closeErr.err.(interface{ StatelessResetToken() *[16]byte }); ok && s.tracer != nil { + s.tracer.ClosedConnection(logging.NewStatelessResetCloseReason(statelessReset.StatelessResetToken())) + } else if quicErr.IsApplicationError() { + s.tracer.ClosedConnection(logging.NewApplicationCloseReason(quicErr.ErrorCode, closeErr.remote)) + } else { + s.tracer.ClosedConnection(logging.NewTransportCloseReason(quicErr.ErrorCode, closeErr.remote)) + } + } + } + // If this is a remote close we're done here if closeErr.remote { s.connIDGenerator.ReplaceWithClosed(newClosedRemoteSession(s.perspective)) diff --git a/session_test.go b/session_test.go index c411a2bc..b10050d1 100644 --- a/session_test.go +++ b/session_test.go @@ -338,7 +338,15 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.TransportError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeTrue()) + Expect(errorCode).To(Equal(qerr.StreamLimitError)) + }), + tracer.EXPECT().Close(), + ) go func() { defer GinkgoRecover() @@ -362,7 +370,15 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.ApplicationError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeTrue()) + Expect(errorCode).To(BeEquivalentTo(0x1337)) + }), + tracer.EXPECT().Close(), + ) go func() { defer GinkgoRecover() @@ -430,7 +446,15 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: buffer}, nil }) mconn.EXPECT().Write([]byte("connection close")) - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.ApplicationError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeFalse()) + Expect(errorCode).To(BeZero()) + }), + tracer.EXPECT().Close(), + ) sess.shutdown() Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -443,6 +467,7 @@ var _ = Describe("Session", func() { cryptoSetup.EXPECT().Close() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() sess.shutdown() @@ -462,7 +487,15 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.ApplicationError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeFalse()) + Expect(errorCode).To(Equal(logging.ApplicationError(0x1337))) + }), + tracer.EXPECT().Close(), + ) sess.CloseWithError(0x1337, "test error") Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -482,7 +515,15 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.TransportError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeFalse()) + Expect(errorCode).To(Equal(logging.TransportError(0x1337))) + }), + tracer.EXPECT().Close(), + ) sess.closeLocal(testErr) Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -495,7 +536,15 @@ var _ = Describe("Session", func() { sessionRunner.EXPECT().Remove(gomock.Any()).AnyTimes() cryptoSetup.EXPECT().Close() // don't EXPECT any calls to mconn.Write() - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + errorCode, remote, ok := reason.TransportError() + Expect(ok).To(BeTrue()) + Expect(remote).To(BeFalse()) + Expect(errorCode).To(Equal(qerr.InternalError)) + }), + tracer.EXPECT().Close(), + ) sess.destroy(testErr) Eventually(areSessionsRunning).Should(BeFalse()) expectedRunErr = testErr @@ -517,6 +566,7 @@ var _ = Describe("Session", func() { }() Consistently(returned).ShouldNot(BeClosed()) mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(returned).Should(BeClosed()) @@ -548,6 +598,7 @@ var _ = Describe("Session", func() { gomock.InOrder( tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()), tracer.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()), + tracer.EXPECT().ClosedConnection(gomock.Any()), tracer.EXPECT().Close(), ) // don't EXPECT any calls to packer.PackPacket() @@ -574,6 +625,7 @@ var _ = Describe("Session", func() { // only expect a single SentPacket() call sph.EXPECT().SentPacket(gomock.Any()) tracer.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() streamManager.EXPECT().CloseWithError(gomock.Any()) sessionRunner.EXPECT().Remove(gomock.Any()).AnyTimes() @@ -778,6 +830,7 @@ var _ = Describe("Session", func() { sess.handlePacket(p) Consistently(sess.Context().Done()).ShouldNot(BeClosed()) // make the go routine return + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) sess.closeLocal(errors.New("close")) @@ -804,6 +857,7 @@ var _ = Describe("Session", func() { Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, }, nil) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.handlePacket(packet) Eventually(sess.Context().Done()).Should(BeClosed()) @@ -829,6 +883,7 @@ var _ = Describe("Session", func() { }, nil)) Consistently(runErr).ShouldNot(Receive()) // make the go routine return + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) sess.shutdown() @@ -853,6 +908,7 @@ var _ = Describe("Session", func() { }() expectReplaceWithClosed() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.handlePacket(getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, @@ -1072,6 +1128,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1254,6 +1311,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1376,6 +1434,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1514,6 +1573,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1550,6 +1610,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1594,6 +1655,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1605,6 +1667,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() go func() { defer GinkgoRecover() @@ -1658,6 +1721,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1676,6 +1740,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(done).Should(BeClosed()) @@ -1696,6 +1761,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() Expect(sess.CloseWithError(0x1337, testErr.Error())).To(Succeed()) Eventually(done).Should(BeClosed()) @@ -1756,6 +1822,7 @@ var _ = Describe("Session", func() { packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -1817,7 +1884,11 @@ var _ = Describe("Session", func() { done := make(chan struct{}) cryptoSetup.EXPECT().Close() gomock.InOrder( - tracer.EXPECT().ClosedConnection(logging.TimeoutReasonIdle), + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + timeout, ok := reason.Timeout() + Expect(ok).To(BeTrue()) + Expect(timeout).To(Equal(logging.TimeoutReasonIdle)) + }), tracer.EXPECT().Close(), ) go func() { @@ -1839,7 +1910,11 @@ var _ = Describe("Session", func() { sessionRunner.EXPECT().Remove(gomock.Any()).Times(2) cryptoSetup.EXPECT().Close() gomock.InOrder( - tracer.EXPECT().ClosedConnection(logging.TimeoutReasonHandshake), + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + timeout, ok := reason.Timeout() + Expect(ok).To(BeTrue()) + Expect(timeout).To(Equal(logging.TimeoutReasonHandshake)) + }), tracer.EXPECT().Close(), ) done := make(chan struct{}) @@ -1864,7 +1939,13 @@ var _ = Describe("Session", func() { Expect(quicErr.ErrorCode).To(Equal(qerr.NoError)) return &coalescedPacket{buffer: getPacketBuffer()}, nil }) - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + _, ok := reason.Timeout() + Expect(ok).To(BeFalse()) + }), + tracer.EXPECT().Close(), + ) // 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() { @@ -1889,7 +1970,11 @@ var _ = Describe("Session", func() { ) cryptoSetup.EXPECT().Close() gomock.InOrder( - tracer.EXPECT().ClosedConnection(logging.TimeoutReasonIdle), + tracer.EXPECT().ClosedConnection(gomock.Any()).Do(func(reason logging.CloseReason) { + timeout, ok := reason.Timeout() + Expect(ok).To(BeTrue()) + Expect(timeout).To(Equal(logging.TimeoutReasonIdle)) + }), tracer.EXPECT().Close(), ) sess.idleTimeout = 0 @@ -1925,6 +2010,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -2106,6 +2192,7 @@ var _ = Describe("Client Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + tracer.EXPECT().ClosedConnection(gomock.Any()) tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -2189,6 +2276,7 @@ var _ = Describe("Client Session", func() { ContainElement(protocol.VersionNumber(1337)), )) }) + tracer.EXPECT().ClosedConnection(gomock.Any()) cryptoSetup.EXPECT().Close() Expect(sess.handlePacketImpl(getVNP(4321, 1337))).To(BeFalse()) var err error @@ -2210,6 +2298,7 @@ var _ = Describe("Client Session", func() { sessionRunner.EXPECT().Remove(srcConnID).MaxTimes(1) gomock.InOrder( tracer.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any(), gomock.Any()), + tracer.EXPECT().ClosedConnection(gomock.Any()), tracer.EXPECT().Close(), ) cryptoSetup.EXPECT().Close() @@ -2323,7 +2412,10 @@ 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()) - tracer.EXPECT().Close() + gomock.InOrder( + tracer.EXPECT().ClosedConnection(gomock.Any()), + tracer.EXPECT().Close(), + ) } closed = true }