diff --git a/internal/mocks/mockgen.go b/internal/mocks/mockgen.go index ad9364b7..a1cbbc26 100644 --- a/internal/mocks/mockgen.go +++ b/internal/mocks/mockgen.go @@ -3,6 +3,7 @@ package mocks //go:generate sh -c "mockgen -package mockquic -destination quic/stream.go github.com/lucas-clemente/quic-go Stream && goimports -w quic/stream.go" //go:generate sh -c "mockgen -package mockquic -destination quic/early_session.go github.com/lucas-clemente/quic-go EarlySession && goimports -w quic/early_session.go" //go:generate sh -c "mockgen -package mockquic -destination quic/early_listener.go github.com/lucas-clemente/quic-go EarlyListener && goimports -w quic/early_listener.go" +//go:generate sh -c "mockgen -package mocks -destination qlog.go github.com/lucas-clemente/quic-go/qlog Tracer && goimports -w qlog.go" //go:generate sh -c "mockgen -package mocks -destination short_header_sealer.go github.com/lucas-clemente/quic-go/internal/handshake ShortHeaderSealer && goimports -w short_header_sealer.go" //go:generate sh -c "mockgen -package mocks -destination short_header_opener.go github.com/lucas-clemente/quic-go/internal/handshake ShortHeaderOpener && goimports -w short_header_opener.go" //go:generate sh -c "mockgen -package mocks -destination long_header_opener.go github.com/lucas-clemente/quic-go/internal/handshake LongHeaderOpener && goimports -w long_header_opener.go" diff --git a/internal/mocks/qlog.go b/internal/mocks/qlog.go new file mode 100644 index 00000000..f8f845a8 --- /dev/null +++ b/internal/mocks/qlog.go @@ -0,0 +1,270 @@ +// Code generated by MockGen. DO NOT EDIT. +// Source: github.com/lucas-clemente/quic-go/qlog (interfaces: Tracer) + +// Package mocks is a generated GoMock package. +package mocks + +import ( + net "net" + reflect "reflect" + time "time" + + gomock "github.com/golang/mock/gomock" + congestion "github.com/lucas-clemente/quic-go/internal/congestion" + protocol "github.com/lucas-clemente/quic-go/internal/protocol" + wire "github.com/lucas-clemente/quic-go/internal/wire" + qlog "github.com/lucas-clemente/quic-go/qlog" +) + +// MockTracer is a mock of Tracer interface +type MockTracer struct { + ctrl *gomock.Controller + recorder *MockTracerMockRecorder +} + +// MockTracerMockRecorder is the mock recorder for MockTracer +type MockTracerMockRecorder struct { + mock *MockTracer +} + +// NewMockTracer creates a new mock instance +func NewMockTracer(ctrl *gomock.Controller) *MockTracer { + mock := &MockTracer{ctrl: ctrl} + mock.recorder = &MockTracerMockRecorder{mock} + return mock +} + +// EXPECT returns an object that allows the caller to indicate expected use +func (m *MockTracer) EXPECT() *MockTracerMockRecorder { + return m.recorder +} + +// BufferedPacket mocks base method +func (m *MockTracer) BufferedPacket(arg0 qlog.PacketType) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "BufferedPacket", arg0) +} + +// BufferedPacket indicates an expected call of BufferedPacket +func (mr *MockTracerMockRecorder) BufferedPacket(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockTracer)(nil).BufferedPacket), arg0) +} + +// DroppedEncryptionLevel mocks base method +func (m *MockTracer) DroppedEncryptionLevel(arg0 protocol.EncryptionLevel) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "DroppedEncryptionLevel", arg0) +} + +// DroppedEncryptionLevel indicates an expected call of DroppedEncryptionLevel +func (mr *MockTracerMockRecorder) DroppedEncryptionLevel(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DroppedEncryptionLevel", reflect.TypeOf((*MockTracer)(nil).DroppedEncryptionLevel), arg0) +} + +// DroppedPacket mocks base method +func (m *MockTracer) DroppedPacket(arg0 qlog.PacketType, arg1 protocol.ByteCount, arg2 qlog.PacketDropReason) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "DroppedPacket", arg0, arg1, arg2) +} + +// DroppedPacket indicates an expected call of DroppedPacket +func (mr *MockTracerMockRecorder) DroppedPacket(arg0, arg1, arg2 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + 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() + m.ctrl.Call(m, "LossTimerCanceled") +} + +// LossTimerCanceled indicates an expected call of LossTimerCanceled +func (mr *MockTracerMockRecorder) LossTimerCanceled() *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "LossTimerCanceled", reflect.TypeOf((*MockTracer)(nil).LossTimerCanceled)) +} + +// LossTimerExpired mocks base method +func (m *MockTracer) LossTimerExpired(arg0 qlog.TimerType, arg1 protocol.EncryptionLevel) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "LossTimerExpired", arg0, arg1) +} + +// LossTimerExpired indicates an expected call of LossTimerExpired +func (mr *MockTracerMockRecorder) LossTimerExpired(arg0, arg1 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "LossTimerExpired", reflect.TypeOf((*MockTracer)(nil).LossTimerExpired), arg0, arg1) +} + +// LostPacket mocks base method +func (m *MockTracer) LostPacket(arg0 protocol.EncryptionLevel, arg1 protocol.PacketNumber, arg2 qlog.PacketLossReason) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "LostPacket", arg0, arg1, arg2) +} + +// LostPacket indicates an expected call of LostPacket +func (mr *MockTracerMockRecorder) LostPacket(arg0, arg1, arg2 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "LostPacket", reflect.TypeOf((*MockTracer)(nil).LostPacket), arg0, arg1, arg2) +} + +// ReceivedPacket mocks base method +func (m *MockTracer) ReceivedPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 []wire.Frame) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "ReceivedPacket", arg0, arg1, arg2) +} + +// ReceivedPacket indicates an expected call of ReceivedPacket +func (mr *MockTracerMockRecorder) ReceivedPacket(arg0, arg1, arg2 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedPacket", reflect.TypeOf((*MockTracer)(nil).ReceivedPacket), arg0, arg1, arg2) +} + +// ReceivedRetry mocks base method +func (m *MockTracer) ReceivedRetry(arg0 *wire.Header) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "ReceivedRetry", arg0) +} + +// ReceivedRetry indicates an expected call of ReceivedRetry +func (mr *MockTracerMockRecorder) ReceivedRetry(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedRetry", reflect.TypeOf((*MockTracer)(nil).ReceivedRetry), arg0) +} + +// ReceivedStatelessReset mocks base method +func (m *MockTracer) ReceivedStatelessReset(arg0 *[16]byte) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "ReceivedStatelessReset", arg0) +} + +// ReceivedStatelessReset indicates an expected call of ReceivedStatelessReset +func (mr *MockTracerMockRecorder) ReceivedStatelessReset(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedStatelessReset", reflect.TypeOf((*MockTracer)(nil).ReceivedStatelessReset), arg0) +} + +// ReceivedTransportParameters mocks base method +func (m *MockTracer) ReceivedTransportParameters(arg0 *wire.TransportParameters) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "ReceivedTransportParameters", arg0) +} + +// ReceivedTransportParameters indicates an expected call of ReceivedTransportParameters +func (mr *MockTracerMockRecorder) ReceivedTransportParameters(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "ReceivedTransportParameters", reflect.TypeOf((*MockTracer)(nil).ReceivedTransportParameters), arg0) +} + +// SentPacket mocks base method +func (m *MockTracer) SentPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []wire.Frame) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "SentPacket", arg0, arg1, arg2, arg3) +} + +// SentPacket indicates an expected call of SentPacket +func (mr *MockTracerMockRecorder) SentPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentPacket", reflect.TypeOf((*MockTracer)(nil).SentPacket), arg0, arg1, arg2, arg3) +} + +// SentTransportParameters mocks base method +func (m *MockTracer) SentTransportParameters(arg0 *wire.TransportParameters) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "SentTransportParameters", arg0) +} + +// SentTransportParameters indicates an expected call of SentTransportParameters +func (mr *MockTracerMockRecorder) SentTransportParameters(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SentTransportParameters", reflect.TypeOf((*MockTracer)(nil).SentTransportParameters), arg0) +} + +// SetLossTimer mocks base method +func (m *MockTracer) SetLossTimer(arg0 qlog.TimerType, arg1 protocol.EncryptionLevel, arg2 time.Time) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "SetLossTimer", arg0, arg1, arg2) +} + +// SetLossTimer indicates an expected call of SetLossTimer +func (mr *MockTracerMockRecorder) SetLossTimer(arg0, arg1, arg2 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "SetLossTimer", reflect.TypeOf((*MockTracer)(nil).SetLossTimer), arg0, arg1, arg2) +} + +// StartedConnection mocks base method +func (m *MockTracer) StartedConnection(arg0, arg1 net.Addr, arg2 protocol.VersionNumber, arg3, arg4 protocol.ConnectionID) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "StartedConnection", arg0, arg1, arg2, arg3, arg4) +} + +// StartedConnection indicates an expected call of StartedConnection +func (mr *MockTracerMockRecorder) StartedConnection(arg0, arg1, arg2, arg3, arg4 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "StartedConnection", reflect.TypeOf((*MockTracer)(nil).StartedConnection), arg0, arg1, arg2, arg3, arg4) +} + +// UpdatedKey mocks base method +func (m *MockTracer) UpdatedKey(arg0 protocol.KeyPhase, arg1 bool) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "UpdatedKey", arg0, arg1) +} + +// UpdatedKey indicates an expected call of UpdatedKey +func (mr *MockTracerMockRecorder) UpdatedKey(arg0, arg1 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "UpdatedKey", reflect.TypeOf((*MockTracer)(nil).UpdatedKey), arg0, arg1) +} + +// UpdatedKeyFromTLS mocks base method +func (m *MockTracer) UpdatedKeyFromTLS(arg0 protocol.EncryptionLevel, arg1 protocol.Perspective) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "UpdatedKeyFromTLS", arg0, arg1) +} + +// UpdatedKeyFromTLS indicates an expected call of UpdatedKeyFromTLS +func (mr *MockTracerMockRecorder) UpdatedKeyFromTLS(arg0, arg1 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "UpdatedKeyFromTLS", reflect.TypeOf((*MockTracer)(nil).UpdatedKeyFromTLS), arg0, arg1) +} + +// UpdatedMetrics mocks base method +func (m *MockTracer) UpdatedMetrics(arg0 *congestion.RTTStats, arg1, arg2 protocol.ByteCount, arg3 int) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "UpdatedMetrics", arg0, arg1, arg2, arg3) +} + +// UpdatedMetrics indicates an expected call of UpdatedMetrics +func (mr *MockTracerMockRecorder) UpdatedMetrics(arg0, arg1, arg2, arg3 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "UpdatedMetrics", reflect.TypeOf((*MockTracer)(nil).UpdatedMetrics), arg0, arg1, arg2, arg3) +} + +// UpdatedPTOCount mocks base method +func (m *MockTracer) UpdatedPTOCount(arg0 uint32) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "UpdatedPTOCount", arg0) +} + +// UpdatedPTOCount indicates an expected call of UpdatedPTOCount +func (mr *MockTracerMockRecorder) UpdatedPTOCount(arg0 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "UpdatedPTOCount", reflect.TypeOf((*MockTracer)(nil).UpdatedPTOCount), arg0) +} diff --git a/session.go b/session.go index 15cfb2cc..b30ca0ea 100644 --- a/session.go +++ b/session.go @@ -797,7 +797,7 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool / packet.hdr.Log(s.logger) } - if err := s.handleUnpackedPacket(packet, p.rcvTime); err != nil { + if err := s.handleUnpackedPacket(packet, p.rcvTime, protocol.ByteCount(len(p.data))); err != nil { s.closeLocal(err) return false } @@ -850,7 +850,11 @@ func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was t return true } -func (s *session) handleUnpackedPacket(packet *unpackedPacket, rcvTime time.Time) error { +func (s *session) handleUnpackedPacket( + packet *unpackedPacket, + rcvTime time.Time, + packetSize protocol.ByteCount, // only for logging +) error { if len(packet.data) == 0 { return qerr.NewError(qerr.ProtocolViolation, "empty packet") } @@ -911,7 +915,7 @@ func (s *session) handleUnpackedPacket(packet *unpackedPacket, rcvTime time.Time }) } if s.qlogger != nil { - s.qlogger.ReceivedPacket(packet.hdr, protocol.ByteCount(len(packet.data)), frames) + s.qlogger.ReceivedPacket(packet.hdr, packetSize, frames) for _, frame := range frames { if err := s.handleFrame(frame, packet.encryptionLevel); err != nil { return err diff --git a/session_test.go b/session_test.go index 8434ce37..22f14367 100644 --- a/session_test.go +++ b/session_test.go @@ -12,10 +12,6 @@ import ( "strings" "time" - . "github.com/onsi/ginkgo" - . "github.com/onsi/gomega" - - "github.com/golang/mock/gomock" "github.com/lucas-clemente/quic-go/internal/ackhandler" "github.com/lucas-clemente/quic-go/internal/handshake" "github.com/lucas-clemente/quic-go/internal/mocks" @@ -25,6 +21,12 @@ import ( "github.com/lucas-clemente/quic-go/internal/testutils" "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/qlog" + + "github.com/golang/mock/gomock" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" ) func areSessionsRunning() bool { @@ -47,6 +49,7 @@ var _ = Describe("Session", func() { streamManager *MockStreamManager packer *MockPacker cryptoSetup *mocks.MockCryptoSetup + qlogger *mocks.MockTracer ) srcConnID := protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8} destConnID := protocol.ConnectionID{8, 7, 6, 5, 4, 3, 2, 1} @@ -59,6 +62,7 @@ var _ = Describe("Session", func() { buffer: buffer, packetContents: &packetContents{ header: &wire.ExtendedHeader{PacketNumber: pn}, + length: 6, // foobar }, } } @@ -81,6 +85,9 @@ var _ = Describe("Session", func() { mconn.EXPECT().LocalAddr().Return(&net.UDPAddr{}) 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() sess = newSession( mconn, sessionRunner, @@ -93,7 +100,7 @@ var _ = Describe("Session", func() { nil, // tls.Config tokenGenerator, false, - nil, + qlogger, utils.DefaultLogger, protocol.VersionTLS, ).(*session) @@ -327,17 +334,17 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake().MaxTimes(1) Expect(sess.run()).To(MatchError(testErr)) }() - ccf := &wire.ConnectionCloseFrame{ + Expect(sess.handleFrame(&wire.ConnectionCloseFrame{ ErrorCode: qerr.StreamLimitError, ReasonPhrase: "foobar", - } - Expect(sess.handleFrame(ccf, protocol.EncryptionUnspecified)).To(Succeed()) + }, protocol.EncryptionUnspecified)).To(Succeed()) Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -351,6 +358,7 @@ var _ = Describe("Session", func() { Expect(s).To(BeAssignableToTypeOf(&closedRemoteSession{})) }) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() go func() { defer GinkgoRecover() @@ -412,6 +420,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: buffer}, nil }) mconn.EXPECT().Write([]byte("connection close")) + qlogger.EXPECT().Export() sess.shutdown() Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -423,6 +432,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() sess.shutdown() sess.shutdown() Eventually(areSessionsRunning).Should(BeFalse()) @@ -440,6 +450,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.CloseWithError(0x1337, "test error") Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -458,6 +469,7 @@ var _ = Describe("Session", func() { return &coalescedPacket{buffer: getPacketBuffer()}, nil }) mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.closeLocal(testErr) Eventually(areSessionsRunning).Should(BeFalse()) Expect(sess.Context().Done()).To(BeClosed()) @@ -468,6 +480,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() sess.closeForRecreating() Eventually(areSessionsRunning).Should(BeFalse()) expectedRunErr = errCloseForRecreating @@ -479,6 +492,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() sess.destroy(testErr) Eventually(areSessionsRunning).Should(BeFalse()) expectedRunErr = testErr @@ -499,6 +513,7 @@ var _ = Describe("Session", func() { }() Consistently(returned).ShouldNot(BeClosed()) mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.shutdown() Eventually(returned).Should(BeClosed()) }) @@ -520,6 +535,10 @@ var _ = Describe("Session", func() { Expect((&wire.ConnectionCloseFrame{ErrorCode: qerr.StreamLimitError}).Write(buf, sess.version)).To(Succeed()) return &unpackedPacket{data: buf.Bytes(), encryptionLevel: protocol.Encryption1RTT}, nil }) + gomock.InOrder( + qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()), + qlogger.EXPECT().Export(), + ) // don't EXPECT any calls to packer.PackPacket() sess.handlePacket(&receivedPacket{ rcvTime: time.Now(), @@ -550,11 +569,12 @@ var _ = Describe("Session", func() { } It("drops Retry packets", func() { - hdr := wire.Header{ + p := getPacket(&wire.ExtendedHeader{Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketTypeRetry, - } - Expect(sess.handlePacketImpl(getPacket(&wire.ExtendedHeader{Header: hdr}, nil))).To(BeFalse()) + }}, nil) + qlogger.EXPECT().DroppedPacket(qlog.PacketTypeNotDetermined, protocol.ByteCount(len(p.data)), gomock.Any()) + Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) It("informs the ReceivedPacketHandler about non-ack-eliciting packets", func() { @@ -563,6 +583,7 @@ var _ = Describe("Session", func() { PacketNumber: 0x37, PacketNumberLen: protocol.PacketNumberLen1, } + packet := getPacket(hdr, nil) rcvTime := time.Now().Add(-10 * time.Second) unpacker.EXPECT().Unpack(gomock.Any(), rcvTime, gomock.Any()).Return(&unpackedPacket{ packetNumber: 0x1337, @@ -573,8 +594,8 @@ var _ = Describe("Session", func() { rph := mockackhandler.NewMockReceivedPacketHandler(mockCtrl) rph.EXPECT().ReceivedPacket(protocol.PacketNumber(0x1337), protocol.EncryptionInitial, rcvTime, false) sess.receivedPacketHandler = rph - packet := getPacket(hdr, nil) packet.rcvTime = rcvTime + qlogger.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), nil) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -587,6 +608,7 @@ var _ = Describe("Session", func() { rcvTime := time.Now().Add(-10 * time.Second) buf := &bytes.Buffer{} Expect((&wire.PingFrame{}).Write(buf, sess.version)).To(Succeed()) + packet := getPacket(hdr, nil) unpacker.EXPECT().Unpack(gomock.Any(), rcvTime, gomock.Any()).Return(&unpackedPacket{ packetNumber: 0x1337, encryptionLevel: protocol.Encryption1RTT, @@ -596,8 +618,8 @@ var _ = Describe("Session", func() { rph := mockackhandler.NewMockReceivedPacketHandler(mockCtrl) rph.EXPECT().ReceivedPacket(protocol.PacketNumber(0x1337), protocol.Encryption1RTT, rcvTime, true) sess.receivedPacketHandler = rph - packet := getPacket(hdr, nil) packet.rcvTime = rcvTime + qlogger.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), []wire.Frame{&wire.PingFrame{}}) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -612,12 +634,22 @@ var _ = Describe("Session", func() { sess.run() }() expectReplaceWithClosed() - sess.handlePacket(getPacket(&wire.ExtendedHeader{ - Header: wire.Header{DestConnectionID: srcConnID}, - PacketNumberLen: protocol.PacketNumberLen1, - }, nil)) + p := getPacket(&wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeHandshake, + DestConnectionID: srcConnID, + Version: sess.version, + Length: 2 + 6, + }, + PacketNumber: 0x1337, + PacketNumberLen: protocol.PacketNumberLen2, + }, []byte("foobar")) + qlogger.EXPECT().DroppedPacket(qlog.PacketTypeHandshake, protocol.ByteCount(len(p.data)), qlog.PacketDropPayloadDecryptError) + sess.handlePacket(p) Consistently(sess.Context().Done()).ShouldNot(BeClosed()) // make the go routine return + qlogger.EXPECT().Export() mconn.EXPECT().Write(gomock.Any()) sess.closeLocal(errors.New("close")) Eventually(sess.Context().Done()).Should(BeClosed()) @@ -639,10 +671,12 @@ var _ = Describe("Session", func() { }() expectReplaceWithClosed() mconn.EXPECT().Write(gomock.Any()) - sess.handlePacket(getPacket(&wire.ExtendedHeader{ + packet := getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, - }, nil)) + }, nil) + qlogger.EXPECT().Export() + sess.handlePacket(packet) Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -659,12 +693,14 @@ var _ = Describe("Session", func() { runErr <- sess.run() }() expectReplaceWithClosed() + qlogger.EXPECT().DroppedPacket(qlog.PacketType1RTT, gomock.Any(), qlog.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() mconn.EXPECT().Write(gomock.Any()) sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) @@ -682,12 +718,12 @@ var _ = Describe("Session", func() { go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake().MaxTimes(1) - err := sess.run() - Expect(err).To(MatchError("PROTOCOL_VIOLATION: empty packet")) + Expect(sess.run()).To(MatchError("PROTOCOL_VIOLATION: empty packet")) close(done) }() expectReplaceWithClosed() mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.handlePacket(getPacket(&wire.ExtendedHeader{ Header: wire.Header{DestConnectionID: srcConnID}, PacketNumberLen: protocol.PacketNumberLen1, @@ -728,9 +764,12 @@ var _ = Describe("Session", func() { hdr: hdr1, data: []byte{0}, // one PADDING frame }, nil) - Expect(sess.handlePacketImpl(getPacket(hdr1, nil))).To(BeTrue()) + p1 := getPacket(hdr1, nil) + qlogger.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. - Expect(sess.handlePacketImpl(getPacket(hdr2, nil))).To(BeFalse()) + p2 := getPacket(hdr2, nil) + Expect(sess.handlePacketImpl(p2)).To(BeFalse()) }) It("queues undecryptable packets", func() { @@ -749,6 +788,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(qlog.PacketTypeHandshake) Expect(sess.handlePacketImpl(packet)).To(BeFalse()) Expect(sess.undecryptablePackets).To(Equal([]*receivedPacket{packet})) }) @@ -765,6 +805,7 @@ var _ = Describe("Session", func() { PacketNumberLen: protocol.PacketNumberLen1, }, nil) packet.remoteAddr = &net.IPAddr{IP: net.IPv4(192, 168, 0, 100)} + qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) }) @@ -798,6 +839,7 @@ var _ = Describe("Session", func() { data: []byte{0}, }, nil }) + qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet.data)), gomock.Any()) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -818,6 +860,10 @@ var _ = Describe("Session", func() { data: []byte{0}, }, 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()), + ) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) }) @@ -836,6 +882,10 @@ var _ = Describe("Session", func() { }, nil }), ) + gomock.InOrder( + qlogger.EXPECT().BufferedPacket(gomock.Any()), + qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), + ) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) @@ -855,7 +905,8 @@ var _ = Describe("Session", func() { }, nil }) _, packet2 := getPacketWithLength(wrongConnID, 123) - // don't EXPECT any calls to unpacker.Unpack() + // don't EXPECT any more calls to unpacker.Unpack() + qlogger.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data)), gomock.Any()) packet1.data = append(packet1.data, packet2.data...) Expect(sess.handlePacketImpl(packet1)).To(BeTrue()) }) @@ -877,15 +928,18 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) It("sends packets", func() { sess.handshakeConfirmed = true - packer.EXPECT().PackPacket().Return(getPacket(1), nil) + p := getPacket(1) + packer.EXPECT().PackPacket().Return(p, nil) sess.receivedPacketHandler.ReceivedPacket(0x035e, protocol.Encryption1RTT, time.Now(), true) mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().SentPacket(p.header, p.buffer.Len(), nil, []wire.Frame{}) sent, err := sess.sendPacket() Expect(err).NotTo(HaveOccurred()) Expect(sent).To(BeTrue()) @@ -914,9 +968,11 @@ var _ = Describe("Session", func() { sess.handshakeConfirmed = true fc := mocks.NewMockConnectionFlowController(mockCtrl) fc.EXPECT().IsNewlyBlocked().Return(true, protocol.ByteCount(1337)) - packer.EXPECT().PackPacket().Return(getPacket(1), nil) + p := getPacket(1) + packer.EXPECT().PackPacket().Return(p, nil) sess.connFlowController = fc mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().SentPacket(p.header, p.length, nil, []wire.Frame{}) sent, err := sess.sendPacket() Expect(err).NotTo(HaveOccurred()) Expect(sent).To(BeTrue()) @@ -960,12 +1016,14 @@ var _ = Describe("Session", func() { sph.EXPECT().SendMode().Return(sendMode) sph.EXPECT().ShouldSendNumPackets().Return(1) sph.EXPECT().QueueProbePacket(encLevel) - packer.EXPECT().MaybePackProbePacket(encLevel).Return(getPacket(123), nil) + p := getPacket(123) + packer.EXPECT().MaybePackProbePacket(encLevel).Return(p, nil) sph.EXPECT().SentPacket(gomock.Any()).Do(func(packet *ackhandler.Packet) { Expect(packet.PacketNumber).To(Equal(protocol.PacketNumber(123))) }) sess.sentPacketHandler = sph mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) Expect(sess.sendPackets()).To(Succeed()) }) @@ -976,12 +1034,14 @@ var _ = Describe("Session", func() { sph.EXPECT().SendMode().Return(sendMode) sph.EXPECT().ShouldSendNumPackets().Return(1) sph.EXPECT().QueueProbePacket(encLevel).Return(false) - packer.EXPECT().MaybePackProbePacket(encLevel).Return(getPacket(123), nil) + p := getPacket(123) + packer.EXPECT().MaybePackProbePacket(encLevel).Return(p, nil) sph.EXPECT().SentPacket(gomock.Any()).Do(func(packet *ackhandler.Packet) { Expect(packet.PacketNumber).To(Equal(protocol.PacketNumber(123))) }) sess.sentPacketHandler = sph mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().SentPacket(p.header, p.length, gomock.Any(), gomock.Any()) Expect(sess.sendPackets()).To(Succeed()) // We're using a mock packet packer in this test. // We therefore need to test separately that the PING was actually queued. @@ -995,6 +1055,7 @@ var _ = Describe("Session", func() { var sph *mockackhandler.MockSentPacketHandler BeforeEach(func() { + qlogger.EXPECT().SentPacket(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).AnyTimes() sph = mockackhandler.NewMockSentPacketHandler(mockCtrl) sph.EXPECT().GetLossDetectionTimeout().AnyTimes() sess.handshakeConfirmed = true @@ -1008,6 +1069,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1126,6 +1188,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1150,6 +1213,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() sess.scheduleSending() Eventually(written).Should(BeClosed()) }) @@ -1174,6 +1238,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() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake().MaxTimes(1) @@ -1220,16 +1285,27 @@ var _ = Describe("Session", func() { sph.EXPECT().SendMode().Return(ackhandler.SendAny).AnyTimes() sph.EXPECT().TimeUntilSend().Return(time.Now()).AnyTimes() sph.EXPECT().ShouldSendNumPackets().Return(1).AnyTimes() - sph.EXPECT().SentPacket(gomock.Any()).Do(func(p *ackhandler.Packet) { - Expect(p.EncryptionLevel).To(Equal(protocol.EncryptionInitial)) - Expect(p.PacketNumber).To(Equal(protocol.PacketNumber(13))) - Expect(p.Length).To(BeEquivalentTo(123)) - }) - sph.EXPECT().SentPacket(gomock.Any()).Do(func(p *ackhandler.Packet) { - Expect(p.EncryptionLevel).To(Equal(protocol.EncryptionHandshake)) - Expect(p.PacketNumber).To(Equal(protocol.PacketNumber(37))) - Expect(p.Length).To(BeEquivalentTo(1234)) - }) + gomock.InOrder( + sph.EXPECT().SentPacket(gomock.Any()).Do(func(p *ackhandler.Packet) { + Expect(p.EncryptionLevel).To(Equal(protocol.EncryptionInitial)) + Expect(p.PacketNumber).To(Equal(protocol.PacketNumber(13))) + Expect(p.Length).To(BeEquivalentTo(123)) + }), + sph.EXPECT().SentPacket(gomock.Any()).Do(func(p *ackhandler.Packet) { + Expect(p.EncryptionLevel).To(Equal(protocol.EncryptionHandshake)) + Expect(p.PacketNumber).To(Equal(protocol.PacketNumber(37))) + Expect(p.Length).To(BeEquivalentTo(1234)) + }), + ) + gomock.InOrder( + qlogger.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) { + Expect(hdr.Type).To(Equal(protocol.PacketTypeHandshake)) + }), + ) + sent := make(chan struct{}) mconn.EXPECT().Write([]byte("foobar")).Do(func([]byte) { close(sent) }) @@ -1248,6 +1324,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1284,6 +1361,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1328,6 +1406,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1338,6 +1417,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake() @@ -1383,6 +1463,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1400,6 +1481,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() sess.shutdown() Eventually(done).Should(BeClosed()) }) @@ -1419,6 +1501,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() Expect(sess.CloseWithError(0x1337, testErr.Error())).To(Succeed()) Eventually(done).Should(BeClosed()) }) @@ -1444,6 +1527,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) sess.processTransportParameters(params) Expect(sess.earlySessionReady()).To(BeClosed()) @@ -1456,6 +1540,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1465,6 +1550,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()) sess.processTransportParameters(&wire.TransportParameters{MaxIdleTimeout: t}) } @@ -1488,6 +1574,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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1547,6 +1634,7 @@ var _ = Describe("Session", func() { sess.lastPacketReceivedTime = time.Now().Add(-time.Hour) done := make(chan struct{}) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() go func() { defer GinkgoRecover() cryptoSetup.EXPECT().RunHandshake().MaxTimes(1) @@ -1565,6 +1653,7 @@ var _ = Describe("Session", func() { sess.sessionCreationTime = time.Now().Add(-protocol.DefaultHandshakeTimeout).Add(-time.Second) sessionRunner.EXPECT().Remove(gomock.Any()).Times(2) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() done := make(chan struct{}) go func() { defer GinkgoRecover() @@ -1587,6 +1676,7 @@ var _ = Describe("Session", func() { Expect(quicErr.ErrorCode).To(Equal(qerr.NoError)) return &coalescedPacket{buffer: getPacketBuffer()}, nil }) + qlogger.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() { @@ -1611,6 +1701,7 @@ var _ = Describe("Session", func() { sessionRunner.EXPECT().Remove(gomock.Any()), ) cryptoSetup.EXPECT().Close() + qlogger.EXPECT().Export() sess.idleTimeout = 0 done := make(chan struct{}) go func() { @@ -1645,6 +1736,7 @@ var _ = Describe("Session", func() { expectReplaceWithClosed() cryptoSetup.EXPECT().Close() mconn.EXPECT().Write(gomock.Any()) + qlogger.EXPECT().Export() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1732,6 +1824,7 @@ var _ = Describe("Client Session", func() { packer *MockPacker mconn *MockConnection cryptoSetup *mocks.MockCryptoSetup + qlogger *mocks.MockTracer tlsConf *tls.Config quicConf *Config ) @@ -1770,6 +1863,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() sess = newClientSession( mconn, sessionRunner, @@ -1780,7 +1876,7 @@ var _ = Describe("Client Session", func() { 42, // initial packet number protocol.VersionTLS, false, - nil, + qlogger, utils.DefaultLogger, protocol.VersionTLS, ).(*session) @@ -1806,21 +1902,25 @@ var _ = Describe("Client Session", func() { sess.run() }() newConnID := protocol.ConnectionID{1, 3, 3, 7, 1, 3, 3, 7} - Expect(sess.handlePacketImpl(getPacket(&wire.ExtendedHeader{ + p := getPacket(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketTypeHandshake, SrcConnectionID: newConnID, DestConnectionID: srcConnID, - Length: 1, + Length: 2 + 6, + Version: sess.version, }, PacketNumberLen: protocol.PacketNumberLen2, - }, []byte{0}))).To(BeTrue()) + }, []byte("foobar")) + qlogger.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() sess.shutdown() Eventually(sess.Context().Done()).Should(BeClosed()) }) @@ -1848,6 +1948,7 @@ var _ = Describe("Client Session", func() { DestConnectionID: srcConnID, SrcConnectionID: destConnID, } + qlogger.EXPECT().ReceivedPacket(gomock.Any(), gomock.Any(), gomock.Any()) Expect(sess.handleSinglePacket(&receivedPacket{buffer: getPacketBuffer()}, hdr)).To(BeTrue()) }) @@ -1900,6 +2001,11 @@ var _ = Describe("Client Session", func() { It("handles Retry packets", func() { cryptoSetup.EXPECT().ChangeConnectionID(protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}) packer.EXPECT().SetToken([]byte("foobar")) + qlogger.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)) + }) Expect(sess.handlePacketImpl(getPacket(retryHdr, getRetryTag(retryHdr)))).To(BeTrue()) }) @@ -1945,6 +2051,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() } closed = true } @@ -1966,6 +2073,7 @@ var _ = Describe("Client Session", func() { } packer.EXPECT().HandleTransportParameters(gomock.Any()) packer.EXPECT().PackCoalescedPacket().MaxTimes(1) + qlogger.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) // make sure the connection ID is not retired cf, _ := sess.framer.AppendControlFrames(nil, protocol.MaxByteCount) @@ -1983,26 +2091,29 @@ var _ = Describe("Client Session", func() { MaxIdleTimeout: 18 * time.Second, } packer.EXPECT().HandleTransportParameters(gomock.Any()) + qlogger.EXPECT().ReceivedTransportParameters(params) sess.processTransportParameters(params) Expect(sess.idleTimeout).To(Equal(18 * time.Second)) }) It("errors if the TransportParameters contain an original_connection_id, although no Retry was performed", func() { - expectClose() - sess.processTransportParameters(&wire.TransportParameters{ + params := &wire.TransportParameters{ OriginalConnectionID: protocol.ConnectionID{0xde, 0xca, 0xfb, 0xad}, StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, - }) + } + expectClose() + sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: expected original_connection_id to equal (empty), is 0xdecafbad"))) }) It("errors if the TransportParameters contain a wrong original_connection_id", func() { sess.origDestConnID = protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef} - expectClose() - sess.processTransportParameters(&wire.TransportParameters{ + params := &wire.TransportParameters{ OriginalConnectionID: protocol.ConnectionID{0xde, 0xca, 0xfb, 0xad}, StatelessResetToken: &[16]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16}, - }) + } + expectClose() + sess.processTransportParameters(params) Eventually(errChan).Should(Receive(MatchError("TRANSPORT_PARAMETER_ERROR: expected original_connection_id to equal 0xdeadbeef, is 0xdecafbad"))) }) }) @@ -2066,13 +2177,14 @@ var _ = Describe("Client Session", func() { hdr: hdr1, data: []byte{0}, // one PADDING frame }, nil) + qlogger.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. Expect(sess.handlePacketImpl(getPacket(hdr2, nil))).To(BeFalse()) }) It("ignores 0-RTT packets", func() { - hdr := &wire.ExtendedHeader{ + p := getPacket(&wire.ExtendedHeader{ Header: wire.Header{ IsLongHeader: true, Type: protocol.PacketType0RTT, @@ -2082,8 +2194,8 @@ var _ = Describe("Client Session", func() { }, PacketNumber: 0x42, PacketNumberLen: protocol.PacketNumberLen2, - } - Expect(sess.handlePacketImpl(getPacket(hdr, []byte("foobar")))).To(BeFalse()) + }, []byte("foobar")) + Expect(sess.handlePacketImpl(p)).To(BeFalse()) }) // Illustrates that an injected Initial with an ACK frame for an unsent packet causes @@ -2091,6 +2203,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()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeFalse()) }) @@ -2099,6 +2212,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()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeTrue()) }) @@ -2109,8 +2223,10 @@ var _ = Describe("Client Session", func() { cryptoSetup.EXPECT().ChangeConnectionID(newSrcConnID) packer.EXPECT().SetToken([]byte("foobar")) + qlogger.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()) Expect(sess.handlePacketImpl(wrapPacket(initialPacket))).To(BeFalse()) })