diff --git a/internal/mocks/logging.go b/internal/mocks/logging.go index d5df1267..5fb2cf0c 100644 --- a/internal/mocks/logging.go +++ b/internal/mocks/logging.go @@ -51,6 +51,18 @@ func (mr *MockTracerMockRecorder) BufferedPacket(arg0 interface{}) *gomock.Call return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockTracer)(nil).BufferedPacket), arg0) } +// Close mocks base method +func (m *MockTracer) Close() { + m.ctrl.T.Helper() + m.ctrl.Call(m, "Close") +} + +// Close indicates an expected call of Close +func (mr *MockTracerMockRecorder) Close() *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "Close", reflect.TypeOf((*MockTracer)(nil).Close)) +} + // ClosedConnection mocks base method func (m *MockTracer) ClosedConnection(arg0 logging.CloseReason) { m.ctrl.T.Helper() @@ -87,20 +99,6 @@ func (mr *MockTracerMockRecorder) DroppedPacket(arg0, arg1, arg2 interface{}) *g return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DroppedPacket", reflect.TypeOf((*MockTracer)(nil).DroppedPacket), arg0, arg1, arg2) } -// Export mocks base method -func (m *MockTracer) Export() error { - m.ctrl.T.Helper() - ret := m.ctrl.Call(m, "Export") - ret0, _ := ret[0].(error) - return ret0 -} - -// Export indicates an expected call of Export -func (mr *MockTracerMockRecorder) Export() *gomock.Call { - mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "Export", reflect.TypeOf((*MockTracer)(nil).Export)) -} - // LossTimerCanceled mocks base method func (m *MockTracer) LossTimerCanceled() { m.ctrl.T.Helper() diff --git a/logging/interface.go b/logging/interface.go index 7a1aa0a1..4df9cb59 100644 --- a/logging/interface.go +++ b/logging/interface.go @@ -13,7 +13,6 @@ import ( // A Tracer records events. type Tracer interface { - Export() error StartedConnection(local, remote net.Addr, version protocol.VersionNumber, srcConnID, destConnID protocol.ConnectionID) ClosedConnection(CloseReason) SentTransportParameters(*wire.TransportParameters) @@ -34,4 +33,6 @@ type Tracer interface { SetLossTimer(TimerType, protocol.EncryptionLevel, time.Time) LossTimerExpired(TimerType, protocol.EncryptionLevel) LossTimerCanceled() + // Close is called when the connection is closed. + Close() } diff --git a/qlog/qlog.go b/qlog/qlog.go index 58576768..d7eb907d 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -4,6 +4,7 @@ import ( "bytes" "fmt" "io" + "log" "net" "sync" "time" @@ -90,8 +91,14 @@ func (t *tracer) run() { } } -// Export writes a qlog. -func (t *tracer) Export() error { +func (t *tracer) Close() { + if err := t.export(); err != nil { + log.Printf("exporting qlog failed: %s\n", err) + } +} + +// export writes a qlog. +func (t *tracer) export() error { close(t.events) <-t.runStopped if t.encodeErr != nil { diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index 52407830..4960ce80 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -5,7 +5,9 @@ import ( "encoding/json" "errors" "io" + "log" "net" + "os" "time" "github.com/lucas-clemente/quic-go/internal/congestion" @@ -63,7 +65,7 @@ var _ = Describe("Tracer", func() { }) It("exports a trace that has the right metadata", func() { - Expect(tracer.Export()).To(Succeed()) + tracer.Close() m := make(map[string]interface{}) Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed()) @@ -98,12 +100,17 @@ var _ = Describe("Tracer", func() { for i := uint32(0); i < 1000; i++ { tracer.UpdatedPTOCount(i) } - Expect(tracer.Export()).To(MatchError("writer full")) + + buf := &bytes.Buffer{} + log.SetOutput(buf) + defer log.SetOutput(os.Stdout) + tracer.Close() + Expect(buf.String()).To(ContainSubstring("writer full")) }) Context("Events", func() { exportAndParse := func() []entry { - Expect(tracer.Export()).To(Succeed()) + tracer.Close() m := make(map[string]interface{}) Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed()) diff --git a/session.go b/session.go index 1b7b2e24..c2cbfa69 100644 --- a/session.go +++ b/session.go @@ -611,9 +611,7 @@ runLoop: s.handleCloseError(closeErr) if !errors.Is(closeErr.err, errCloseForRecreating{}) && s.tracer != nil { - if err := s.tracer.Export(); err != nil { - s.logger.Errorf("exporting qlog failed: %s", err) - } + s.tracer.Close() } s.logger.Infof("Connection %s closed.", s.logID) s.cryptoStreamHandler.Close() diff --git a/session_test.go b/session_test.go index 41f62b6a..eac9c26c 100644 --- a/session_test.go +++ b/session_test.go @@ -337,7 +337,7 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - tracer.EXPECT().Export() + tracer.EXPECT().Close() go func() { defer GinkgoRecover() @@ -361,7 +361,7 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() - tracer.EXPECT().Export() + tracer.EXPECT().Close() go func() { defer GinkgoRecover() @@ -429,7 +429,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: buffer}, nil }) mconn.EXPECT().Write([]byte("connection close")) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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() - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(returned).Should(BeClosed()) }) @@ -547,7 +547,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().Export(), + tracer.EXPECT().Close(), ) // don't EXPECT any calls to packer.PackPacket() sess.handlePacket(&receivedPacket{ @@ -750,7 +750,7 @@ var _ = Describe("Session", func() { sess.handlePacket(p) Consistently(sess.Context().Done()).ShouldNot(BeClosed()) // make the go routine return - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.handlePacket(packet) Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -801,7 +801,7 @@ var _ = Describe("Session", func() { }, nil)) Consistently(runErr).ShouldNot(Receive()) // make the go routine return - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.handlePacket(getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, @@ -1044,7 +1044,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) Eventually(sessionDone).Should(BeClosed()) @@ -1226,7 +1226,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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() - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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() - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() 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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() Expect(sess.CloseWithError(0x1337, testErr.Error())).To(Succeed()) Eventually(done).Should(BeClosed()) }) @@ -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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1790,7 +1790,7 @@ var _ = Describe("Session", func() { cryptoSetup.EXPECT().Close() gomock.InOrder( tracer.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), - tracer.EXPECT().Export(), + tracer.EXPECT().Close(), ) go func() { defer GinkgoRecover() @@ -1812,7 +1812,7 @@ var _ = Describe("Session", func() { cryptoSetup.EXPECT().Close() gomock.InOrder( tracer.EXPECT().ClosedConnection(logging.CloseReasonHandshakeTimeout), - tracer.EXPECT().Export(), + tracer.EXPECT().Close(), ) 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 }) - tracer.EXPECT().Export() + 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() { @@ -1862,7 +1862,7 @@ var _ = Describe("Session", func() { cryptoSetup.EXPECT().Close() gomock.InOrder( tracer.EXPECT().ClosedConnection(logging.CloseReasonIdleTimeout), - tracer.EXPECT().Export(), + tracer.EXPECT().Close(), ) sess.idleTimeout = 0 done := make(chan struct{}) @@ -1897,7 +1897,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -2078,7 +2078,7 @@ var _ = Describe("Client Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -2182,7 +2182,7 @@ var _ = Describe("Client Session", func() { sessionRunner.EXPECT().Remove(srcConnID).MaxTimes(1) gomock.InOrder( tracer.EXPECT().ReceivedVersionNegotiationPacket(gomock.Any()), - tracer.EXPECT().Export(), + tracer.EXPECT().Close(), ) cryptoSetup.EXPECT().Close() Expect(sess.handlePacketImpl(getVNP(12345678))).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()) - tracer.EXPECT().Export() + tracer.EXPECT().Close() } closed = true }