log the size of buffered packets (#3571)

This commit is contained in:
Marten Seemann 2022-10-11 12:27:26 +03:00 committed by GitHub
parent 438942b888
commit fe277dc663
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
11 changed files with 28 additions and 21 deletions

View file

@ -2080,7 +2080,7 @@ func (s *connection) tryQueueingUndecryptablePacket(p *receivedPacket, pt loggin
} }
s.logger.Infof("Queueing packet (%d bytes) for later decryption", p.Size()) s.logger.Infof("Queueing packet (%d bytes) for later decryption", p.Size())
if s.tracer != nil { if s.tracer != nil {
s.tracer.BufferedPacket(pt) s.tracer.BufferedPacket(pt, p.Size())
} }
s.undecryptablePackets = append(s.undecryptablePackets, p) s.undecryptablePackets = append(s.undecryptablePackets, p)
} }

View file

@ -1043,7 +1043,7 @@ var _ = Describe("Connection", func() {
} }
unpacker.EXPECT().UnpackLongHeader(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil, handshake.ErrKeysNotYetAvailable) unpacker.EXPECT().UnpackLongHeader(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil, handshake.ErrKeysNotYetAvailable)
packet := getPacket(hdr, nil) packet := getPacket(hdr, nil)
tracer.EXPECT().BufferedPacket(logging.PacketTypeHandshake) tracer.EXPECT().BufferedPacket(logging.PacketTypeHandshake, packet.Size())
Expect(conn.handlePacketImpl(packet)).To(BeFalse()) Expect(conn.handlePacketImpl(packet)).To(BeFalse())
Expect(conn.undecryptablePackets).To(Equal([]*receivedPacket{packet})) Expect(conn.undecryptablePackets).To(Equal([]*receivedPacket{packet}))
}) })
@ -1147,7 +1147,7 @@ var _ = Describe("Connection", func() {
}), }),
) )
gomock.InOrder( gomock.InOrder(
tracer.EXPECT().BufferedPacket(gomock.Any()), tracer.EXPECT().BufferedPacket(gomock.Any(), protocol.ByteCount(len(packet1.data))),
tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()), tracer.EXPECT().ReceivedLongHeaderPacket(gomock.Any(), protocol.ByteCount(len(packet2.data)), gomock.Any()),
) )
packet1.data = append(packet1.data, packet2.data...) packet1.data = append(packet1.data, packet2.data...)

View file

@ -52,15 +52,15 @@ func (mr *MockConnectionTracerMockRecorder) AcknowledgedPacket(arg0, arg1 interf
} }
// BufferedPacket mocks base method. // BufferedPacket mocks base method.
func (m *MockConnectionTracer) BufferedPacket(arg0 logging.PacketType) { func (m *MockConnectionTracer) BufferedPacket(arg0 logging.PacketType, arg1 protocol.ByteCount) {
m.ctrl.T.Helper() m.ctrl.T.Helper()
m.ctrl.Call(m, "BufferedPacket", arg0) m.ctrl.Call(m, "BufferedPacket", arg0, arg1)
} }
// BufferedPacket indicates an expected call of BufferedPacket. // BufferedPacket indicates an expected call of BufferedPacket.
func (mr *MockConnectionTracerMockRecorder) BufferedPacket(arg0 interface{}) *gomock.Call { func (mr *MockConnectionTracerMockRecorder) BufferedPacket(arg0, arg1 interface{}) *gomock.Call {
mr.mock.ctrl.T.Helper() mr.mock.ctrl.T.Helper()
return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).BufferedPacket), arg0) return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).BufferedPacket), arg0, arg1)
} }
// Close mocks base method. // Close mocks base method.

View file

@ -126,7 +126,7 @@ type ConnectionTracer interface {
ReceivedRetry(*Header) ReceivedRetry(*Header)
ReceivedLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, frames []Frame) ReceivedLongHeaderPacket(hdr *ExtendedHeader, size ByteCount, frames []Frame)
ReceivedShortHeaderPacket(hdr *ShortHeader, size ByteCount, frames []Frame) ReceivedShortHeaderPacket(hdr *ShortHeader, size ByteCount, frames []Frame)
BufferedPacket(PacketType) BufferedPacket(PacketType, ByteCount)
DroppedPacket(PacketType, ByteCount, PacketDropReason) DroppedPacket(PacketType, ByteCount, PacketDropReason)
UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int)
AcknowledgedPacket(EncryptionLevel, PacketNumber) AcknowledgedPacket(EncryptionLevel, PacketNumber)

View file

@ -51,15 +51,15 @@ func (mr *MockConnectionTracerMockRecorder) AcknowledgedPacket(arg0, arg1 interf
} }
// BufferedPacket mocks base method. // BufferedPacket mocks base method.
func (m *MockConnectionTracer) BufferedPacket(arg0 PacketType) { func (m *MockConnectionTracer) BufferedPacket(arg0 PacketType, arg1 protocol.ByteCount) {
m.ctrl.T.Helper() m.ctrl.T.Helper()
m.ctrl.Call(m, "BufferedPacket", arg0) m.ctrl.Call(m, "BufferedPacket", arg0, arg1)
} }
// BufferedPacket indicates an expected call of BufferedPacket. // BufferedPacket indicates an expected call of BufferedPacket.
func (mr *MockConnectionTracerMockRecorder) BufferedPacket(arg0 interface{}) *gomock.Call { func (mr *MockConnectionTracerMockRecorder) BufferedPacket(arg0, arg1 interface{}) *gomock.Call {
mr.mock.ctrl.T.Helper() mr.mock.ctrl.T.Helper()
return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).BufferedPacket), arg0) return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "BufferedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).BufferedPacket), arg0, arg1)
} }
// Close mocks base method. // Close mocks base method.

View file

@ -134,9 +134,9 @@ func (m *connTracerMultiplexer) ReceivedShortHeaderPacket(hdr *ShortHeader, size
} }
} }
func (m *connTracerMultiplexer) BufferedPacket(typ PacketType) { func (m *connTracerMultiplexer) BufferedPacket(typ PacketType, size ByteCount) {
for _, t := range m.tracers { for _, t := range m.tracers {
t.BufferedPacket(typ) t.BufferedPacket(typ, size)
} }
} }

View file

@ -198,9 +198,9 @@ var _ = Describe("Tracing", func() {
}) })
It("traces the BufferedPacket event", func() { It("traces the BufferedPacket event", func() {
tr1.EXPECT().BufferedPacket(PacketTypeHandshake) tr1.EXPECT().BufferedPacket(PacketTypeHandshake, ByteCount(1337))
tr2.EXPECT().BufferedPacket(PacketTypeHandshake) tr2.EXPECT().BufferedPacket(PacketTypeHandshake, ByteCount(1337))
tracer.BufferedPacket(PacketTypeHandshake) tracer.BufferedPacket(PacketTypeHandshake, 1337)
}) })
It("traces the DroppedPacket event", func() { It("traces the DroppedPacket event", func() {

View file

@ -41,7 +41,7 @@ func (n NullConnectionTracer) ReceivedVersionNegotiationPacket(dest, src Arbitra
func (n NullConnectionTracer) ReceivedRetry(*Header) {} func (n NullConnectionTracer) ReceivedRetry(*Header) {}
func (n NullConnectionTracer) ReceivedLongHeaderPacket(*ExtendedHeader, ByteCount, []Frame) {} func (n NullConnectionTracer) ReceivedLongHeaderPacket(*ExtendedHeader, ByteCount, []Frame) {}
func (n NullConnectionTracer) ReceivedShortHeaderPacket(*ShortHeader, ByteCount, []Frame) {} func (n NullConnectionTracer) ReceivedShortHeaderPacket(*ShortHeader, ByteCount, []Frame) {}
func (n NullConnectionTracer) BufferedPacket(PacketType) {} func (n NullConnectionTracer) BufferedPacket(PacketType, ByteCount) {}
func (n NullConnectionTracer) DroppedPacket(PacketType, ByteCount, PacketDropReason) {} func (n NullConnectionTracer) DroppedPacket(PacketType, ByteCount, PacketDropReason) {}
func (n NullConnectionTracer) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int) { func (n NullConnectionTracer) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int) {

View file

@ -227,6 +227,7 @@ func (e eventVersionNegotiationReceived) MarshalJSONObject(enc *gojay.Encoder) {
type eventPacketBuffered struct { type eventPacketBuffered struct {
PacketType logging.PacketType PacketType logging.PacketType
PacketSize protocol.ByteCount
} }
func (e eventPacketBuffered) Category() category { return categoryTransport } func (e eventPacketBuffered) Category() category { return categoryTransport }
@ -236,6 +237,7 @@ func (e eventPacketBuffered) IsNil() bool { return false }
func (e eventPacketBuffered) MarshalJSONObject(enc *gojay.Encoder) { func (e eventPacketBuffered) MarshalJSONObject(enc *gojay.Encoder) {
//nolint:gosimple //nolint:gosimple
enc.ObjectKey("header", packetHeaderWithType{PacketType: e.PacketType}) enc.ObjectKey("header", packetHeaderWithType{PacketType: e.PacketType})
enc.ObjectKey("raw", rawInfo{Length: e.PacketSize})
enc.StringKey("trigger", "keys_unavailable") enc.StringKey("trigger", "keys_unavailable")
} }

View file

@ -354,9 +354,12 @@ func (t *connectionTracer) ReceivedVersionNegotiationPacket(dest, src logging.Ar
t.mutex.Unlock() t.mutex.Unlock()
} }
func (t *connectionTracer) BufferedPacket(pt logging.PacketType) { func (t *connectionTracer) BufferedPacket(pt logging.PacketType, size protocol.ByteCount) {
t.mutex.Lock() t.mutex.Lock()
t.recordEvent(time.Now(), &eventPacketBuffered{PacketType: pt}) t.recordEvent(time.Now(), &eventPacketBuffered{
PacketType: pt,
PacketSize: size,
})
t.mutex.Unlock() t.mutex.Unlock()
} }

View file

@ -610,7 +610,7 @@ var _ = Describe("Tracing", func() {
}) })
It("records buffered packets", func() { It("records buffered packets", func() {
tracer.BufferedPacket(logging.PacketTypeHandshake) tracer.BufferedPacket(logging.PacketTypeHandshake, 1337)
entry := exportAndParseSingle() entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:packet_buffered")) Expect(entry.Name).To(Equal("transport:packet_buffered"))
@ -619,6 +619,8 @@ var _ = Describe("Tracing", func() {
hdr := ev["header"].(map[string]interface{}) hdr := ev["header"].(map[string]interface{})
Expect(hdr).To(HaveLen(1)) Expect(hdr).To(HaveLen(1))
Expect(hdr).To(HaveKeyWithValue("packet_type", "handshake")) Expect(hdr).To(HaveKeyWithValue("packet_type", "handshake"))
Expect(ev).To(HaveKey("raw"))
Expect(ev["raw"].(map[string]interface{})).To(HaveKeyWithValue("length", float64(1337)))
Expect(ev).To(HaveKeyWithValue("trigger", "keys_unavailable")) Expect(ev).To(HaveKeyWithValue("trigger", "keys_unavailable"))
}) })