From ed120f670c4d8edf12b97725a57d4909f6d9c8e8 Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Thu, 2 Jul 2020 15:59:33 +0700 Subject: [PATCH] add logging aliases for frames, create a logging.STREAM and CRYPTO frame --- internal/logutils/frame.go | 29 ++++ internal/logutils/frame_test.go | 44 ++++++ internal/logutils/logutils_suite_test.go | 13 ++ internal/mocks/connection_tracer.go | 8 +- logging/frame.go | 61 ++++++++ logging/interface.go | 4 +- qlog/frame.go | 178 +++++++++-------------- qlog/frame_test.go | 69 +++++---- qlog/qlog.go | 10 +- qlog/qlog_test.go | 41 +++--- session.go | 11 +- session_test.go | 16 +- 12 files changed, 300 insertions(+), 184 deletions(-) create mode 100644 internal/logutils/frame.go create mode 100644 internal/logutils/frame_test.go create mode 100644 internal/logutils/logutils_suite_test.go create mode 100644 logging/frame.go diff --git a/internal/logutils/frame.go b/internal/logutils/frame.go new file mode 100644 index 00000000..b1d3e672 --- /dev/null +++ b/internal/logutils/frame.go @@ -0,0 +1,29 @@ +package logutils + +import ( + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/logging" +) + +// ConvertFrame converts a wire.Frame into a logging.Frame. +// This makes it possible for external packages to access the frames. +// Furthermore, it removes the data slices from CRYPTO and STREAM frames. +func ConvertFrame(frame wire.Frame) logging.Frame { + switch f := frame.(type) { + case *wire.CryptoFrame: + return &logging.CryptoFrame{ + Offset: f.Offset, + Length: protocol.ByteCount(len(f.Data)), + } + case *wire.StreamFrame: + return &logging.StreamFrame{ + StreamID: f.StreamID, + Offset: f.Offset, + Length: f.DataLen(), + Fin: f.Fin, + } + default: + return logging.Frame(frame) + } +} diff --git a/internal/logutils/frame_test.go b/internal/logutils/frame_test.go new file mode 100644 index 00000000..dd6b14e4 --- /dev/null +++ b/internal/logutils/frame_test.go @@ -0,0 +1,44 @@ +package logutils + +import ( + "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/logging" + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +var _ = Describe("CRYPTO frame", func() { + It("converts CRYPTO frames", func() { + f := ConvertFrame(&wire.CryptoFrame{ + Offset: 1234, + Data: []byte("foobar"), + }) + Expect(f).To(BeAssignableToTypeOf(&logging.CryptoFrame{})) + cf := f.(*logging.CryptoFrame) + Expect(cf.Offset).To(Equal(logging.ByteCount(1234))) + Expect(cf.Length).To(Equal(logging.ByteCount(6))) + }) + + It("converts STREAM frames", func() { + f := ConvertFrame(&wire.StreamFrame{ + StreamID: 42, + Offset: 1234, + Data: []byte("foo"), + Fin: true, + }) + Expect(f).To(BeAssignableToTypeOf(&logging.StreamFrame{})) + sf := f.(*logging.StreamFrame) + Expect(sf.StreamID).To(Equal(logging.StreamID(42))) + Expect(sf.Offset).To(Equal(logging.ByteCount(1234))) + Expect(sf.Length).To(Equal(logging.ByteCount(3))) + Expect(sf.Fin).To(BeTrue()) + }) + + It("converts other frames", func() { + f := ConvertFrame(&wire.MaxDataFrame{MaximumData: 1234}) + Expect(f).To(BeAssignableToTypeOf(&logging.MaxDataFrame{})) + Expect(f).ToNot(BeAssignableToTypeOf(&logging.MaxStreamDataFrame{})) + mdf := f.(*logging.MaxDataFrame) + Expect(mdf.MaximumData).To(Equal(logging.ByteCount(1234))) + }) +}) diff --git a/internal/logutils/logutils_suite_test.go b/internal/logutils/logutils_suite_test.go new file mode 100644 index 00000000..dc496b2d --- /dev/null +++ b/internal/logutils/logutils_suite_test.go @@ -0,0 +1,13 @@ +package logutils + +import ( + "testing" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +func TestLogutils(t *testing.T) { + RegisterFailHandler(Fail) + RunSpecs(t, "Logutils Suite") +} diff --git a/internal/mocks/connection_tracer.go b/internal/mocks/connection_tracer.go index 0993d10f..5b0c7e30 100644 --- a/internal/mocks/connection_tracer.go +++ b/internal/mocks/connection_tracer.go @@ -40,7 +40,7 @@ func (m *MockConnectionTracer) EXPECT() *MockConnectionTracerMockRecorder { } // BufferedPacket mocks base method -func (m *MockConnectionTracer) BufferedPacket(arg0 logging.PacketType) { +func (m *MockConnectionTracer) BufferedPacket(arg0 protocol.PacketType) { m.ctrl.T.Helper() m.ctrl.Call(m, "BufferedPacket", arg0) } @@ -88,7 +88,7 @@ func (mr *MockConnectionTracerMockRecorder) DroppedEncryptionLevel(arg0 interfac } // DroppedPacket mocks base method -func (m *MockConnectionTracer) DroppedPacket(arg0 logging.PacketType, arg1 protocol.ByteCount, arg2 logging.PacketDropReason) { +func (m *MockConnectionTracer) DroppedPacket(arg0 protocol.PacketType, arg1 protocol.ByteCount, arg2 logging.PacketDropReason) { m.ctrl.T.Helper() m.ctrl.Call(m, "DroppedPacket", arg0, arg1, arg2) } @@ -136,7 +136,7 @@ func (mr *MockConnectionTracerMockRecorder) LostPacket(arg0, arg1, arg2 interfac } // ReceivedPacket mocks base method -func (m *MockConnectionTracer) ReceivedPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 []wire.Frame) { +func (m *MockConnectionTracer) ReceivedPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 []logging.Frame) { m.ctrl.T.Helper() m.ctrl.Call(m, "ReceivedPacket", arg0, arg1, arg2) } @@ -196,7 +196,7 @@ func (mr *MockConnectionTracerMockRecorder) ReceivedVersionNegotiationPacket(arg } // SentPacket mocks base method -func (m *MockConnectionTracer) SentPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []wire.Frame) { +func (m *MockConnectionTracer) SentPacket(arg0 *wire.ExtendedHeader, arg1 protocol.ByteCount, arg2 *wire.AckFrame, arg3 []logging.Frame) { m.ctrl.T.Helper() m.ctrl.Call(m, "SentPacket", arg0, arg1, arg2, arg3) } diff --git a/logging/frame.go b/logging/frame.go new file mode 100644 index 00000000..dfb875f0 --- /dev/null +++ b/logging/frame.go @@ -0,0 +1,61 @@ +package logging + +import "github.com/lucas-clemente/quic-go/internal/wire" + +// A Frame is a QUIC frame +type Frame interface{} + +// The AckRange is used within the AckFrame. +// It is a range of packet numbers that is being acknowledged. +type AckRange = wire.AckRange + +type ( + // An AckFrame is an ACK frame. + AckFrame = wire.AckFrame + // A ConnectionCloseFrame is a CONNECTION_CLOSE frame. + ConnectionCloseFrame = wire.ConnectionCloseFrame + // A DataBlockedFrame is a DATA_BLOCKED frame. + DataBlockedFrame = wire.DataBlockedFrame + // A HandshakeDoneFrame is a HANDSHAKE_DONE frame. + HandshakeDoneFrame = wire.HandshakeDoneFrame + // A MaxDataFrame is a MAX_DATA frame. + MaxDataFrame = wire.MaxDataFrame + // A MaxStreamDataFrame is a MAX_STREAM_DATA frame. + MaxStreamDataFrame = wire.MaxStreamDataFrame + // A MaxStreamsFrame is a MAX_STREAMS_FRAME. + MaxStreamsFrame = wire.MaxStreamsFrame + // A NewConnectionIDFrame is a NEW_CONNECTION_ID frame. + NewConnectionIDFrame = wire.NewConnectionIDFrame + // A NewTokenFrame is a NEW_TOKEN frame. + NewTokenFrame = wire.NewTokenFrame + // A PathChallengeFrame is a PATH_CHALLENGE frame. + PathChallengeFrame = wire.PathChallengeFrame + // A PathResponseFrame is a PATH_RESPONSE frame. + PathResponseFrame = wire.PathResponseFrame + // A PingFrame is a PING frame. + PingFrame = wire.PingFrame + // A ResetStreamFrame is a RESET_STREAM frame. + ResetStreamFrame = wire.ResetStreamFrame + // A RetireConnectionIDFrame is a RETIRE_CONNECTION_ID frame. + RetireConnectionIDFrame = wire.RetireConnectionIDFrame + // A StopSendingFrame is a STOP_SENDING frame. + StopSendingFrame = wire.StopSendingFrame + // A StreamsBlockedFrame is a STREAMS_BLOCKED frame. + StreamsBlockedFrame = wire.StreamsBlockedFrame + // A StreamDataBlockedFrame is a STREAM_DATA_BLOCKED frame. + StreamDataBlockedFrame = wire.StreamDataBlockedFrame +) + +// A CryptoFrame is a CRYPTO frame. +type CryptoFrame struct { + Offset ByteCount + Length ByteCount +} + +// A StreamFrame is a STREAM frame. +type StreamFrame struct { + StreamID StreamID + Offset ByteCount + Length ByteCount + Fin bool +} diff --git a/logging/interface.go b/logging/interface.go index 0c754fd5..03bb10a0 100644 --- a/logging/interface.go +++ b/logging/interface.go @@ -80,10 +80,10 @@ type ConnectionTracer interface { ClosedConnection(CloseReason) SentTransportParameters(*TransportParameters) ReceivedTransportParameters(*TransportParameters) - SentPacket(hdr *ExtendedHeader, packetSize ByteCount, ack *wire.AckFrame, frames []wire.Frame) + SentPacket(hdr *ExtendedHeader, packetSize ByteCount, ack *AckFrame, frames []Frame) ReceivedVersionNegotiationPacket(*Header) ReceivedRetry(*Header) - ReceivedPacket(hdr *ExtendedHeader, packetSize ByteCount, frames []wire.Frame) + ReceivedPacket(hdr *ExtendedHeader, packetSize ByteCount, frames []Frame) ReceivedStatelessReset(token *[16]byte) BufferedPacket(PacketType) DroppedPacket(PacketType, ByteCount, PacketDropReason) diff --git a/qlog/frame.go b/qlog/frame.go index c81bb429..4c19123c 100644 --- a/qlog/frame.go +++ b/qlog/frame.go @@ -3,18 +3,67 @@ package qlog import ( "fmt" - "github.com/francoispqt/gojay" - - "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/logging" + + "github.com/francoispqt/gojay" ) type frame struct { - Frame interface{} + Frame logging.Frame } var _ gojay.MarshalerJSONObject = frame{} +var _ gojay.MarshalerJSONArray = frames{} + +func (f frame) MarshalJSONObject(enc *gojay.Encoder) { + switch frame := f.Frame.(type) { + case *logging.PingFrame: + marshalPingFrame(enc, frame) + case *logging.AckFrame: + marshalAckFrame(enc, frame) + case *logging.ResetStreamFrame: + marshalResetStreamFrame(enc, frame) + case *logging.StopSendingFrame: + marshalStopSendingFrame(enc, frame) + case *logging.CryptoFrame: + marshalCryptoFrame(enc, frame) + case *logging.NewTokenFrame: + marshalNewTokenFrame(enc, frame) + case *logging.StreamFrame: + marshalStreamFrame(enc, frame) + case *logging.MaxDataFrame: + marshalMaxDataFrame(enc, frame) + case *logging.MaxStreamDataFrame: + marshalMaxStreamDataFrame(enc, frame) + case *logging.MaxStreamsFrame: + marshalMaxStreamsFrame(enc, frame) + case *logging.DataBlockedFrame: + marshalDataBlockedFrame(enc, frame) + case *logging.StreamDataBlockedFrame: + marshalStreamDataBlockedFrame(enc, frame) + case *logging.StreamsBlockedFrame: + marshalStreamsBlockedFrame(enc, frame) + case *logging.NewConnectionIDFrame: + marshalNewConnectionIDFrame(enc, frame) + case *logging.RetireConnectionIDFrame: + marshalRetireConnectionIDFrame(enc, frame) + case *logging.PathChallengeFrame: + marshalPathChallengeFrame(enc, frame) + case *logging.PathResponseFrame: + marshalPathResponseFrame(enc, frame) + case *logging.ConnectionCloseFrame: + marshalConnectionCloseFrame(enc, frame) + case *logging.HandshakeDoneFrame: + marshalHandshakeDoneFrame(enc, frame) + default: + panic("unknown frame type") + } +} + +func (f frame) IsNil() bool { return false } + type frames []frame func (fs frames) IsNil() bool { return fs == nil } @@ -24,89 +73,6 @@ func (fs frames) MarshalJSONArray(enc *gojay.Encoder) { } } -var _ gojay.MarshalerJSONArray = frames{} - -type cryptoFrame struct { - Offset protocol.ByteCount - Length protocol.ByteCount -} - -type streamFrame struct { - StreamID protocol.StreamID - Offset protocol.ByteCount - Length protocol.ByteCount - FinBit bool -} - -func transformFrame(wf wire.Frame) *frame { - // We don't want to store CRYPTO and STREAM frames, for multiple reasons: - // * They both contain data, and we want to make this byte slice GC'able as soon as possible. - // * STREAM frames use a slice from the buffer pool, which is released as soon as the frame is processed. - switch f := wf.(type) { - case *wire.CryptoFrame: - return &frame{Frame: &cryptoFrame{ - Offset: f.Offset, - Length: protocol.ByteCount(len(f.Data)), - }} - case *wire.StreamFrame: - return &frame{Frame: &streamFrame{ - StreamID: f.StreamID, - Offset: f.Offset, - Length: f.DataLen(), - FinBit: f.Fin, - }} - default: - return &frame{Frame: wf} - } -} - -func (f frame) MarshalJSONObject(enc *gojay.Encoder) { - switch frame := f.Frame.(type) { - case *wire.PingFrame: - marshalPingFrame(enc, frame) - case *wire.AckFrame: - marshalAckFrame(enc, frame) - case *wire.ResetStreamFrame: - marshalResetStreamFrame(enc, frame) - case *wire.StopSendingFrame: - marshalStopSendingFrame(enc, frame) - case *cryptoFrame: - marshalCryptoFrame(enc, frame) - case *wire.NewTokenFrame: - marshalNewTokenFrame(enc, frame) - case *streamFrame: - marshalStreamFrame(enc, frame) - case *wire.MaxDataFrame: - marshalMaxDataFrame(enc, frame) - case *wire.MaxStreamDataFrame: - marshalMaxStreamDataFrame(enc, frame) - case *wire.MaxStreamsFrame: - marshalMaxStreamsFrame(enc, frame) - case *wire.DataBlockedFrame: - marshalDataBlockedFrame(enc, frame) - case *wire.StreamDataBlockedFrame: - marshalStreamDataBlockedFrame(enc, frame) - case *wire.StreamsBlockedFrame: - marshalStreamsBlockedFrame(enc, frame) - case *wire.NewConnectionIDFrame: - marshalNewConnectionIDFrame(enc, frame) - case *wire.RetireConnectionIDFrame: - marshalRetireConnectionIDFrame(enc, frame) - case *wire.PathChallengeFrame: - marshalPathChallengeFrame(enc, frame) - case *wire.PathResponseFrame: - marshalPathResponseFrame(enc, frame) - case *wire.ConnectionCloseFrame: - marshalConnectionCloseFrame(enc, frame) - case *wire.HandshakeDoneFrame: - marshalHandshakeDoneFrame(enc, frame) - default: - panic("unknown frame type") - } -} - -func (f frame) IsNil() bool { return false } - func marshalPingFrame(enc *gojay.Encoder, _ *wire.PingFrame) { enc.StringKey("frame_type", "ping") } @@ -132,80 +98,80 @@ func (ar ackRange) MarshalJSONArray(enc *gojay.Encoder) { func (ar ackRange) IsNil() bool { return false } -func marshalAckFrame(enc *gojay.Encoder, f *wire.AckFrame) { +func marshalAckFrame(enc *gojay.Encoder, f *logging.AckFrame) { enc.StringKey("frame_type", "ack") enc.FloatKeyOmitEmpty("ack_delay", milliseconds(f.DelayTime)) enc.ArrayKey("acked_ranges", ackRanges(f.AckRanges)) } -func marshalResetStreamFrame(enc *gojay.Encoder, f *wire.ResetStreamFrame) { +func marshalResetStreamFrame(enc *gojay.Encoder, f *logging.ResetStreamFrame) { enc.StringKey("frame_type", "reset_stream") enc.Int64Key("stream_id", int64(f.StreamID)) enc.Int64Key("error_code", int64(f.ErrorCode)) enc.Int64Key("final_size", int64(f.FinalSize)) } -func marshalStopSendingFrame(enc *gojay.Encoder, f *wire.StopSendingFrame) { +func marshalStopSendingFrame(enc *gojay.Encoder, f *logging.StopSendingFrame) { enc.StringKey("frame_type", "stop_sending") enc.Int64Key("stream_id", int64(f.StreamID)) enc.Int64Key("error_code", int64(f.ErrorCode)) } -func marshalCryptoFrame(enc *gojay.Encoder, f *cryptoFrame) { +func marshalCryptoFrame(enc *gojay.Encoder, f *logging.CryptoFrame) { enc.StringKey("frame_type", "crypto") enc.Int64Key("offset", int64(f.Offset)) enc.Int64Key("length", int64(f.Length)) } -func marshalNewTokenFrame(enc *gojay.Encoder, f *wire.NewTokenFrame) { +func marshalNewTokenFrame(enc *gojay.Encoder, f *logging.NewTokenFrame) { enc.StringKey("frame_type", "new_token") enc.IntKey("length", len(f.Token)) enc.StringKey("token", fmt.Sprintf("%x", f.Token)) } -func marshalStreamFrame(enc *gojay.Encoder, f *streamFrame) { +func marshalStreamFrame(enc *gojay.Encoder, f *logging.StreamFrame) { enc.StringKey("frame_type", "stream") enc.Int64Key("stream_id", int64(f.StreamID)) enc.Int64Key("offset", int64(f.Offset)) enc.IntKey("length", int(f.Length)) - enc.BoolKeyOmitEmpty("fin", f.FinBit) + enc.BoolKeyOmitEmpty("fin", f.Fin) } -func marshalMaxDataFrame(enc *gojay.Encoder, f *wire.MaxDataFrame) { +func marshalMaxDataFrame(enc *gojay.Encoder, f *logging.MaxDataFrame) { enc.StringKey("frame_type", "max_data") enc.Int64Key("maximum", int64(f.MaximumData)) } -func marshalMaxStreamDataFrame(enc *gojay.Encoder, f *wire.MaxStreamDataFrame) { +func marshalMaxStreamDataFrame(enc *gojay.Encoder, f *logging.MaxStreamDataFrame) { enc.StringKey("frame_type", "max_stream_data") enc.Int64Key("stream_id", int64(f.StreamID)) enc.Int64Key("maximum", int64(f.MaximumStreamData)) } -func marshalMaxStreamsFrame(enc *gojay.Encoder, f *wire.MaxStreamsFrame) { +func marshalMaxStreamsFrame(enc *gojay.Encoder, f *logging.MaxStreamsFrame) { enc.StringKey("frame_type", "max_streams") enc.StringKey("stream_type", streamType(f.Type).String()) enc.Int64Key("maximum", int64(f.MaxStreamNum)) } -func marshalDataBlockedFrame(enc *gojay.Encoder, f *wire.DataBlockedFrame) { +func marshalDataBlockedFrame(enc *gojay.Encoder, f *logging.DataBlockedFrame) { enc.StringKey("frame_type", "data_blocked") enc.Int64Key("limit", int64(f.MaximumData)) } -func marshalStreamDataBlockedFrame(enc *gojay.Encoder, f *wire.StreamDataBlockedFrame) { +func marshalStreamDataBlockedFrame(enc *gojay.Encoder, f *logging.StreamDataBlockedFrame) { enc.StringKey("frame_type", "stream_data_blocked") enc.Int64Key("stream_id", int64(f.StreamID)) enc.Int64Key("limit", int64(f.MaximumStreamData)) } -func marshalStreamsBlockedFrame(enc *gojay.Encoder, f *wire.StreamsBlockedFrame) { +func marshalStreamsBlockedFrame(enc *gojay.Encoder, f *logging.StreamsBlockedFrame) { enc.StringKey("frame_type", "streams_blocked") enc.StringKey("stream_type", streamType(f.Type).String()) enc.Int64Key("limit", int64(f.StreamLimit)) } -func marshalNewConnectionIDFrame(enc *gojay.Encoder, f *wire.NewConnectionIDFrame) { +func marshalNewConnectionIDFrame(enc *gojay.Encoder, f *logging.NewConnectionIDFrame) { enc.StringKey("frame_type", "new_connection_id") enc.Int64Key("sequence_number", int64(f.SequenceNumber)) enc.Int64Key("retire_prior_to", int64(f.RetirePriorTo)) @@ -214,22 +180,22 @@ func marshalNewConnectionIDFrame(enc *gojay.Encoder, f *wire.NewConnectionIDFram enc.StringKey("stateless_reset_token", fmt.Sprintf("%x", f.StatelessResetToken)) } -func marshalRetireConnectionIDFrame(enc *gojay.Encoder, f *wire.RetireConnectionIDFrame) { +func marshalRetireConnectionIDFrame(enc *gojay.Encoder, f *logging.RetireConnectionIDFrame) { enc.StringKey("frame_type", "retire_connection_id") enc.Int64Key("sequence_number", int64(f.SequenceNumber)) } -func marshalPathChallengeFrame(enc *gojay.Encoder, f *wire.PathChallengeFrame) { +func marshalPathChallengeFrame(enc *gojay.Encoder, f *logging.PathChallengeFrame) { enc.StringKey("frame_type", "path_challenge") enc.StringKey("data", fmt.Sprintf("%x", f.Data[:])) } -func marshalPathResponseFrame(enc *gojay.Encoder, f *wire.PathResponseFrame) { +func marshalPathResponseFrame(enc *gojay.Encoder, f *logging.PathResponseFrame) { enc.StringKey("frame_type", "path_response") enc.StringKey("data", fmt.Sprintf("%x", f.Data[:])) } -func marshalConnectionCloseFrame(enc *gojay.Encoder, f *wire.ConnectionCloseFrame) { +func marshalConnectionCloseFrame(enc *gojay.Encoder, f *logging.ConnectionCloseFrame) { errorSpace := "transport" if f.IsApplicationError { errorSpace = "application" @@ -245,6 +211,6 @@ func marshalConnectionCloseFrame(enc *gojay.Encoder, f *wire.ConnectionCloseFram enc.StringKey("reason", f.ReasonPhrase) } -func marshalHandshakeDoneFrame(enc *gojay.Encoder, _ *wire.HandshakeDoneFrame) { +func marshalHandshakeDoneFrame(enc *gojay.Encoder, _ *logging.HandshakeDoneFrame) { enc.StringKey("frame_type", "handshake_done") } diff --git a/qlog/frame_test.go b/qlog/frame_test.go index 5f35ce05..2bd9a9ed 100644 --- a/qlog/frame_test.go +++ b/qlog/frame_test.go @@ -5,22 +5,21 @@ import ( "encoding/json" "time" + "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/qerr" + "github.com/lucas-clemente/quic-go/logging" "github.com/francoispqt/gojay" - "github.com/lucas-clemente/quic-go/internal/protocol" - "github.com/lucas-clemente/quic-go/internal/wire" - . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" ) var _ = Describe("Frames", func() { - check := func(f wire.Frame, expected map[string]interface{}) { + check := func(f logging.Frame, expected map[string]interface{}) { buf := &bytes.Buffer{} enc := gojay.NewEncoder(buf) - ExpectWithOffset(1, enc.Encode(transformFrame(f))).To(Succeed()) + ExpectWithOffset(1, enc.Encode(frame{Frame: f})).To(Succeed()) data := buf.Bytes() ExpectWithOffset(1, json.Valid(data)).To(BeTrue()) checkEncoding(data, expected) @@ -28,7 +27,7 @@ var _ = Describe("Frames", func() { It("marshals PING frames", func() { check( - &wire.PingFrame{}, + &logging.PingFrame{}, map[string]interface{}{ "frame_type": "ping", }, @@ -37,9 +36,9 @@ var _ = Describe("Frames", func() { It("marshals ACK frames with a range acknowledging a single packet", func() { check( - &wire.AckFrame{ + &logging.AckFrame{ DelayTime: 86 * time.Millisecond, - AckRanges: []wire.AckRange{{Smallest: 120, Largest: 120}}, + AckRanges: []logging.AckRange{{Smallest: 120, Largest: 120}}, }, map[string]interface{}{ "frame_type": "ack", @@ -51,8 +50,8 @@ var _ = Describe("Frames", func() { It("marshals ACK frames without a delay", func() { check( - &wire.AckFrame{ - AckRanges: []wire.AckRange{{Smallest: 120, Largest: 120}}, + &logging.AckFrame{ + AckRanges: []logging.AckRange{{Smallest: 120, Largest: 120}}, }, map[string]interface{}{ "frame_type": "ack", @@ -63,9 +62,9 @@ var _ = Describe("Frames", func() { It("marshals ACK frames with a range acknowledging ranges of packets", func() { check( - &wire.AckFrame{ + &logging.AckFrame{ DelayTime: 86 * time.Millisecond, - AckRanges: []wire.AckRange{ + AckRanges: []logging.AckRange{ {Smallest: 5, Largest: 50}, {Smallest: 100, Largest: 120}, }, @@ -83,7 +82,7 @@ var _ = Describe("Frames", func() { It("marshals RESET_STREAM frames", func() { check( - &wire.ResetStreamFrame{ + &logging.ResetStreamFrame{ StreamID: 987, FinalSize: 1234, ErrorCode: 42, @@ -99,7 +98,7 @@ var _ = Describe("Frames", func() { It("marshals STOP_SENDING frames", func() { check( - &wire.StopSendingFrame{ + &logging.StopSendingFrame{ StreamID: 987, ErrorCode: 42, }, @@ -113,9 +112,9 @@ var _ = Describe("Frames", func() { It("marshals CRYPTO frames", func() { check( - &wire.CryptoFrame{ + &logging.CryptoFrame{ Offset: 1337, - Data: []byte("foobar"), + Length: 6, }, map[string]interface{}{ "frame_type": "crypto", @@ -127,7 +126,7 @@ var _ = Describe("Frames", func() { It("marshals NEW_TOKEN frames", func() { check( - &wire.NewTokenFrame{ + &logging.NewTokenFrame{ Token: []byte{0xde, 0xad, 0xbe, 0xef}, }, map[string]interface{}{ @@ -140,28 +139,28 @@ var _ = Describe("Frames", func() { It("marshals STREAM frames with FIN", func() { check( - &wire.StreamFrame{ + &logging.StreamFrame{ StreamID: 42, Offset: 1337, Fin: true, - Data: []byte("foobar"), + Length: 9876, }, map[string]interface{}{ "frame_type": "stream", "stream_id": 42, "offset": 1337, "fin": true, - "length": 6, + "length": 9876, }, ) }) It("marshals STREAM frames without FIN", func() { check( - &wire.StreamFrame{ + &logging.StreamFrame{ StreamID: 42, Offset: 1337, - Data: []byte("foo"), + Length: 3, }, map[string]interface{}{ "frame_type": "stream", @@ -174,7 +173,7 @@ var _ = Describe("Frames", func() { It("marshals MAX_DATA frames", func() { check( - &wire.MaxDataFrame{ + &logging.MaxDataFrame{ MaximumData: 1337, }, map[string]interface{}{ @@ -186,7 +185,7 @@ var _ = Describe("Frames", func() { It("marshals MAX_STREAM_DATA frames", func() { check( - &wire.MaxStreamDataFrame{ + &logging.MaxStreamDataFrame{ StreamID: 1234, MaximumStreamData: 1337, }, @@ -200,7 +199,7 @@ var _ = Describe("Frames", func() { It("marshals MAX_STREAMS frames", func() { check( - &wire.MaxStreamsFrame{ + &logging.MaxStreamsFrame{ Type: protocol.StreamTypeBidi, MaxStreamNum: 42, }, @@ -214,7 +213,7 @@ var _ = Describe("Frames", func() { It("marshals DATA_BLOCKED frames", func() { check( - &wire.DataBlockedFrame{ + &logging.DataBlockedFrame{ MaximumData: 1337, }, map[string]interface{}{ @@ -226,7 +225,7 @@ var _ = Describe("Frames", func() { It("marshals STREAM_DATA_BLOCKED frames", func() { check( - &wire.StreamDataBlockedFrame{ + &logging.StreamDataBlockedFrame{ StreamID: 42, MaximumStreamData: 1337, }, @@ -240,7 +239,7 @@ var _ = Describe("Frames", func() { It("marshals STREAMS_BLOCKED frames", func() { check( - &wire.StreamsBlockedFrame{ + &logging.StreamsBlockedFrame{ Type: protocol.StreamTypeUni, StreamLimit: 123, }, @@ -254,7 +253,7 @@ var _ = Describe("Frames", func() { It("marshals NEW_CONNECTION_ID frames", func() { check( - &wire.NewConnectionIDFrame{ + &logging.NewConnectionIDFrame{ SequenceNumber: 42, RetirePriorTo: 24, ConnectionID: protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}, @@ -273,7 +272,7 @@ var _ = Describe("Frames", func() { It("marshals RETIRE_CONNECTION_ID frames", func() { check( - &wire.RetireConnectionIDFrame{ + &logging.RetireConnectionIDFrame{ SequenceNumber: 1337, }, map[string]interface{}{ @@ -285,7 +284,7 @@ var _ = Describe("Frames", func() { It("marshals PATH_CHALLENGE frames", func() { check( - &wire.PathChallengeFrame{ + &logging.PathChallengeFrame{ Data: [8]byte{0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xc0, 0x01}, }, map[string]interface{}{ @@ -297,7 +296,7 @@ var _ = Describe("Frames", func() { It("marshals PATH_RESPONSE frames", func() { check( - &wire.PathResponseFrame{ + &logging.PathResponseFrame{ Data: [8]byte{0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xc0, 0x01}, }, map[string]interface{}{ @@ -309,7 +308,7 @@ var _ = Describe("Frames", func() { It("marshals CONNECTION_CLOSE frames, for application error codes", func() { check( - &wire.ConnectionCloseFrame{ + &logging.ConnectionCloseFrame{ IsApplicationError: true, ErrorCode: 1337, ReasonPhrase: "lorem ipsum", @@ -326,7 +325,7 @@ var _ = Describe("Frames", func() { It("marshals CONNECTION_CLOSE frames, for transport error codes", func() { check( - &wire.ConnectionCloseFrame{ + &logging.ConnectionCloseFrame{ ErrorCode: qerr.FlowControlError, ReasonPhrase: "lorem ipsum", }, @@ -342,7 +341,7 @@ var _ = Describe("Frames", func() { It("marshals HANDSHAKE_DONE frames", func() { check( - &wire.HandshakeDoneFrame{}, + &logging.HandshakeDoneFrame{}, map[string]interface{}{ "frame_type": "handshake_done", }, diff --git a/qlog/qlog.go b/qlog/qlog.go index fc7de3a7..b47159cb 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -200,17 +200,17 @@ func (t *connectionTracer) recordTransportParameters(sentBy protocol.Perspective t.mutex.Unlock() } -func (t *connectionTracer) SentPacket(hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *wire.AckFrame, frames []wire.Frame) { +func (t *connectionTracer) SentPacket(hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *logging.AckFrame, frames []logging.Frame) { numFrames := len(frames) if ack != nil { numFrames++ } fs := make([]frame, 0, numFrames) if ack != nil { - fs = append(fs, *transformFrame(ack)) + fs = append(fs, frame{Frame: ack}) } for _, f := range frames { - fs = append(fs, *transformFrame(f)) + fs = append(fs, frame{Frame: f}) } header := *transformExtendedHeader(hdr) header.PacketSize = packetSize @@ -223,10 +223,10 @@ func (t *connectionTracer) SentPacket(hdr *wire.ExtendedHeader, packetSize proto t.mutex.Unlock() } -func (t *connectionTracer) ReceivedPacket(hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []wire.Frame) { +func (t *connectionTracer) ReceivedPacket(hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []logging.Frame) { fs := make([]frame, len(frames)) for i, f := range frames { - fs[i] = *transformFrame(f) + fs[i] = frame{Frame: f} } header := *transformExtendedHeader(hdr) header.PacketSize = packetSize diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index 3cceddfa..e1a99a1c 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -12,7 +12,6 @@ import ( "github.com/lucas-clemente/quic-go/internal/congestion" "github.com/lucas-clemente/quic-go/internal/protocol" - "github.com/lucas-clemente/quic-go/internal/wire" "github.com/lucas-clemente/quic-go/logging" . "github.com/onsi/ginkgo" @@ -178,7 +177,7 @@ var _ = Describe("Tracer", func() { }) It("records sent transport parameters", func() { - tracer.SentTransportParameters(&wire.TransportParameters{ + tracer.SentTransportParameters(&logging.TransportParameters{ InitialMaxStreamDataBidiLocal: 1000, InitialMaxStreamDataBidiRemote: 2000, InitialMaxStreamDataUni: 3000, @@ -219,7 +218,7 @@ var _ = Describe("Tracer", func() { }) It("records the server's transport parameters, without a stateless reset token", func() { - tracer.SentTransportParameters(&wire.TransportParameters{ + tracer.SentTransportParameters(&logging.TransportParameters{ OriginalDestinationConnectionID: protocol.ConnectionID{0xde, 0xad, 0xc0, 0xde}, ActiveConnectionIDLimit: 7, }) @@ -232,7 +231,7 @@ var _ = Describe("Tracer", func() { }) It("records transport parameters without retry_source_connection_id", func() { - tracer.SentTransportParameters(&wire.TransportParameters{ + tracer.SentTransportParameters(&logging.TransportParameters{ StatelessResetToken: &[16]byte{0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff, 0x00}, }) entry := exportAndParseSingle() @@ -245,7 +244,7 @@ var _ = Describe("Tracer", func() { }) It("records received transport parameters", func() { - tracer.ReceivedTransportParameters(&wire.TransportParameters{}) + tracer.ReceivedTransportParameters(&logging.TransportParameters{}) entry := exportAndParseSingle() Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) Expect(entry.Category).To(Equal("transport")) @@ -257,8 +256,8 @@ var _ = Describe("Tracer", func() { It("records a sent packet, without an ACK", func() { tracer.SentPacket( - &wire.ExtendedHeader{ - Header: wire.Header{ + &logging.ExtendedHeader{ + Header: logging.Header{ IsLongHeader: true, Type: protocol.PacketTypeHandshake, DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, @@ -269,9 +268,9 @@ var _ = Describe("Tracer", func() { }, 987, nil, - []wire.Frame{ - &wire.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, - &wire.StreamFrame{StreamID: 123, Offset: 1234, Data: []byte("foobar"), Fin: true}, + []logging.Frame{ + &logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, + &logging.StreamFrame{StreamID: 123, Offset: 1234, Length: 6, Fin: true}, }, ) entry := exportAndParseSingle() @@ -294,13 +293,13 @@ var _ = Describe("Tracer", func() { It("records a sent packet, without an ACK", func() { tracer.SentPacket( - &wire.ExtendedHeader{ - Header: wire.Header{DestConnectionID: protocol.ConnectionID{1, 2, 3, 4}}, + &logging.ExtendedHeader{ + Header: logging.Header{DestConnectionID: protocol.ConnectionID{1, 2, 3, 4}}, PacketNumber: 1337, }, 123, - &wire.AckFrame{AckRanges: []wire.AckRange{{Smallest: 1, Largest: 10}}}, - []wire.Frame{&wire.MaxDataFrame{MaximumData: 987}}, + &logging.AckFrame{AckRanges: []logging.AckRange{{Smallest: 1, Largest: 10}}}, + []logging.Frame{&logging.MaxDataFrame{MaximumData: 987}}, ) entry := exportAndParseSingle() ev := entry.Event @@ -315,8 +314,8 @@ var _ = Describe("Tracer", func() { It("records a received packet", func() { tracer.ReceivedPacket( - &wire.ExtendedHeader{ - Header: wire.Header{ + &logging.ExtendedHeader{ + Header: logging.Header{ IsLongHeader: true, Type: protocol.PacketTypeInitial, DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, @@ -326,9 +325,9 @@ var _ = Describe("Tracer", func() { PacketNumber: 1337, }, 789, - []wire.Frame{ - &wire.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, - &wire.StreamFrame{StreamID: 123, Offset: 1234, Data: []byte("foobar"), Fin: true}, + []logging.Frame{ + &logging.MaxStreamDataFrame{StreamID: 42, MaximumStreamData: 987}, + &logging.StreamFrame{StreamID: 123, Offset: 1234, Length: 6, Fin: true}, }, ) entry := exportAndParseSingle() @@ -348,7 +347,7 @@ var _ = Describe("Tracer", func() { It("records a received Retry packet", func() { tracer.ReceivedRetry( - &wire.Header{ + &logging.Header{ IsLongHeader: true, Type: protocol.PacketTypeRetry, DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, @@ -373,7 +372,7 @@ var _ = Describe("Tracer", func() { It("records a received Version Negotiation packet", func() { tracer.ReceivedVersionNegotiationPacket( - &wire.Header{ + &logging.Header{ IsLongHeader: true, Type: protocol.PacketTypeRetry, DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, diff --git a/session.go b/session.go index 8d527066..83c55b9f 100644 --- a/session.go +++ b/session.go @@ -16,6 +16,7 @@ import ( "github.com/lucas-clemente/quic-go/internal/congestion" "github.com/lucas-clemente/quic-go/internal/flowcontrol" "github.com/lucas-clemente/quic-go/internal/handshake" + "github.com/lucas-clemente/quic-go/internal/logutils" "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/qerr" "github.com/lucas-clemente/quic-go/internal/utils" @@ -1042,7 +1043,11 @@ func (s *session) handleUnpackedPacket( }) } if s.tracer != nil { - s.tracer.ReceivedPacket(packet.hdr, packetSize, frames) + fs := make([]logging.Frame, len(frames)) + for i, frame := range frames { + fs[i] = logutils.ConvertFrame(frame) + } + s.tracer.ReceivedPacket(packet.hdr, packetSize, fs) for _, frame := range frames { if err := s.handleFrame(frame, packet.encryptionLevel); err != nil { return err @@ -1556,9 +1561,9 @@ func (s *session) sendConnectionClose(quicErr *qerr.QuicError) ([]byte, error) { func (s *session) logPacketContents(now time.Time, p *packetContents) { // tracing if s.tracer != nil { - frames := make([]wire.Frame, 0, len(p.frames)) + frames := make([]logging.Frame, 0, len(p.frames)) for _, f := range p.frames { - frames = append(frames, f.Frame) + frames = append(frames, logutils.ConvertFrame(f.Frame)) } s.tracer.SentPacket(p.header, p.length, p.ack, frames) } diff --git a/session_test.go b/session_test.go index f28ad68d..329ca1ad 100644 --- a/session_test.go +++ b/session_test.go @@ -672,7 +672,7 @@ var _ = Describe("Session", func() { sess.receivedPacketHandler = rph packet.rcvTime = rcvTime tracer.EXPECT().StartedConnection(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()) - tracer.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), nil) + tracer.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), []logging.Frame{}) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -700,7 +700,7 @@ var _ = Describe("Session", func() { sess.receivedPacketHandler = rph packet.rcvTime = rcvTime 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{}}) + tracer.EXPECT().ReceivedPacket(hdr, protocol.ByteCount(len(packet.data)), []logging.Frame{&logging.PingFrame{}}) Expect(sess.handlePacketImpl(packet)).To(BeTrue()) }) @@ -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) }) - tracer.EXPECT().SentPacket(p.header, p.buffer.Len(), nil, []wire.Frame{}) + tracer.EXPECT().SentPacket(p.header, p.buffer.Len(), nil, []logging.Frame{}) sess.scheduleSending() Eventually(sent).Should(BeClosed()) }) @@ -1120,11 +1120,11 @@ var _ = Describe("Session", func() { runSession() sent := make(chan struct{}) mconn.EXPECT().Write(gomock.Any()).Do(func([]byte) { close(sent) }) - tracer.EXPECT().SentPacket(p.header, p.length, nil, []wire.Frame{}) + tracer.EXPECT().SentPacket(p.header, p.length, nil, []logging.Frame{}) sess.scheduleSending() Eventually(sent).Should(BeClosed()) frames, _ := sess.framer.AppendControlFrames(nil, 1000) - Expect(frames).To(Equal([]ackhandler.Frame{{Frame: &wire.DataBlockedFrame{MaximumData: 1337}}})) + Expect(frames).To(Equal([]ackhandler.Frame{{Frame: &logging.DataBlockedFrame{MaximumData: 1337}}})) }) It("doesn't send when the SentPacketHandler doesn't allow it", func() { @@ -1460,10 +1460,10 @@ var _ = Describe("Session", func() { }), ) gomock.InOrder( - tracer.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, _ []logging.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeInitial)) }), - tracer.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, _ []logging.Frame) { Expect(hdr.Type).To(Equal(protocol.PacketTypeHandshake)) }), ) @@ -2071,7 +2071,7 @@ var _ = Describe("Client Session", func() { }, PacketNumberLen: protocol.PacketNumberLen2, }, []byte("foobar")) - tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p.data)), nil) + tracer.EXPECT().ReceivedPacket(gomock.Any(), protocol.ByteCount(len(p.data)), []logging.Frame{}) Expect(sess.handlePacketImpl(p)).To(BeTrue()) // make sure the go routine returns packer.EXPECT().PackConnectionClose(gomock.Any()).Return(&coalescedPacket{buffer: getPacketBuffer()}, nil)