TUN-8451: Log QUIC flow control frames and transport parameters received

This commit is contained in:
chungthuang 2024-06-06 15:02:18 -05:00 committed by Chung-Ting Huang
parent 354a5bb8af
commit a16532dbbb
2 changed files with 65 additions and 40 deletions

View File

@ -7,6 +7,7 @@ import (
"github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus"
"github.com/quic-go/quic-go/logging" "github.com/quic-go/quic-go/logging"
"github.com/rs/zerolog"
) )
const ( const (
@ -18,6 +19,7 @@ var (
clientMetrics = struct { clientMetrics = struct {
totalConnections prometheus.Counter totalConnections prometheus.Counter
closedConnections prometheus.Counter closedConnections prometheus.Counter
maxUDPPayloadSize *prometheus.GaugeVec
sentFrames *prometheus.CounterVec sentFrames *prometheus.CounterVec
sentBytes *prometheus.CounterVec sentBytes *prometheus.CounterVec
receivedFrames *prometheus.CounterVec receivedFrames *prometheus.CounterVec
@ -45,6 +47,15 @@ var (
Help: "Number of connections that has been closed", Help: "Number of connections that has been closed",
}, },
), ),
maxUDPPayloadSize: prometheus.NewGaugeVec(
prometheus.GaugeOpts{
Namespace: namespace,
Subsystem: "client",
Name: "max_udp_payload",
Help: "Maximum UDP payload size in bytes for a QUIC packet",
},
clientConnLabels,
),
sentFrames: prometheus.NewCounterVec( sentFrames: prometheus.NewCounterVec(
prometheus.CounterOpts{ prometheus.CounterOpts{
Namespace: namespace, Namespace: namespace,
@ -149,13 +160,15 @@ var (
type clientCollector struct { type clientCollector struct {
index string index string
logger *zerolog.Logger
} }
func newClientCollector(index uint8) *clientCollector { func newClientCollector(index string, logger *zerolog.Logger) *clientCollector {
registerClient.Do(func() { registerClient.Do(func() {
prometheus.MustRegister( prometheus.MustRegister(
clientMetrics.totalConnections, clientMetrics.totalConnections,
clientMetrics.closedConnections, clientMetrics.closedConnections,
clientMetrics.maxUDPPayloadSize,
clientMetrics.sentFrames, clientMetrics.sentFrames,
clientMetrics.sentBytes, clientMetrics.sentBytes,
clientMetrics.receivedFrames, clientMetrics.receivedFrames,
@ -169,8 +182,10 @@ func newClientCollector(index uint8) *clientCollector {
packetTooBigDropped, packetTooBigDropped,
) )
}) })
return &clientCollector{ return &clientCollector{
index: uint8ToString(index), index: index,
logger: logger,
} }
} }
@ -178,16 +193,21 @@ func (cc *clientCollector) startedConnection() {
clientMetrics.totalConnections.Inc() clientMetrics.totalConnections.Inc()
} }
func (cc *clientCollector) closedConnection(err error) { func (cc *clientCollector) closedConnection(error) {
clientMetrics.closedConnections.Inc() clientMetrics.closedConnections.Inc()
} }
func (cc *clientCollector) receivedTransportParameters(params *logging.TransportParameters) {
clientMetrics.maxUDPPayloadSize.WithLabelValues(cc.index).Set(float64(params.MaxUDPPayloadSize))
cc.logger.Debug().Msgf("Received transport parameters: MaxUDPPayloadSize=%d, MaxIdleTimeout=%v, MaxDatagramFrameSize=%d", params.MaxUDPPayloadSize, params.MaxIdleTimeout, params.MaxDatagramFrameSize)
}
func (cc *clientCollector) sentPackets(size logging.ByteCount, frames []logging.Frame) { func (cc *clientCollector) sentPackets(size logging.ByteCount, frames []logging.Frame) {
cc.collectPackets(size, frames, clientMetrics.sentFrames, clientMetrics.sentBytes) cc.collectPackets(size, frames, clientMetrics.sentFrames, clientMetrics.sentBytes, sent)
} }
func (cc *clientCollector) receivedPackets(size logging.ByteCount, frames []logging.Frame) { func (cc *clientCollector) receivedPackets(size logging.ByteCount, frames []logging.Frame) {
cc.collectPackets(size, frames, clientMetrics.receivedFrames, clientMetrics.receivedBytes) cc.collectPackets(size, frames, clientMetrics.receivedFrames, clientMetrics.receivedBytes, received)
} }
func (cc *clientCollector) bufferedPackets(packetType logging.PacketType) { func (cc *clientCollector) bufferedPackets(packetType logging.PacketType) {
@ -212,8 +232,14 @@ func (cc *clientCollector) updatedRTT(rtt *logging.RTTStats) {
clientMetrics.smoothedRTT.WithLabelValues(cc.index).Set(durationToPromGauge(rtt.SmoothedRTT())) clientMetrics.smoothedRTT.WithLabelValues(cc.index).Set(durationToPromGauge(rtt.SmoothedRTT()))
} }
func (cc *clientCollector) collectPackets(size logging.ByteCount, frames []logging.Frame, counter, bandwidth *prometheus.CounterVec) { func (cc *clientCollector) collectPackets(size logging.ByteCount, frames []logging.Frame, counter, bandwidth *prometheus.CounterVec, direction direction) {
for _, frame := range frames { for _, frame := range frames {
switch f := frame.(type) {
case logging.DataBlockedFrame:
cc.logger.Debug().Msgf("%s data_blocked frame", direction)
case logging.StreamDataBlockedFrame:
cc.logger.Debug().Int64("streamID", int64(f.StreamID)).Msgf("%s stream_data_blocked frame", direction)
}
counter.WithLabelValues(cc.index, frameName(frame)).Inc() counter.WithLabelValues(cc.index, frameName(frame)).Inc()
} }
bandwidth.WithLabelValues(cc.index).Add(byteCountToPromCount(size)) bandwidth.WithLabelValues(cc.index).Add(byteCountToPromCount(size))
@ -227,3 +253,17 @@ func frameName(frame logging.Frame) string {
return strings.TrimSuffix(name, "Frame") return strings.TrimSuffix(name, "Frame")
} }
} }
type direction uint8
const (
sent direction = iota
received
)
func (d direction) String() string {
if d == sent {
return "sent"
}
return "received"
}

View File

@ -10,26 +10,20 @@ import (
// QUICTracer is a wrapper to create new quicConnTracer // QUICTracer is a wrapper to create new quicConnTracer
type tracer struct { type tracer struct {
index string
logger *zerolog.Logger logger *zerolog.Logger
config *tracerConfig
}
type tracerConfig struct {
index uint8
} }
func NewClientTracer(logger *zerolog.Logger, index uint8) func(context.Context, logging.Perspective, logging.ConnectionID) *logging.ConnectionTracer { func NewClientTracer(logger *zerolog.Logger, index uint8) func(context.Context, logging.Perspective, logging.ConnectionID) *logging.ConnectionTracer {
t := &tracer{ t := &tracer{
index: uint8ToString(index),
logger: logger, logger: logger,
config: &tracerConfig{
index: index,
},
} }
return t.TracerForConnection return t.TracerForConnection
} }
func (t *tracer) TracerForConnection(_ctx context.Context, _p logging.Perspective, _odcid logging.ConnectionID) *logging.ConnectionTracer { func (t *tracer) TracerForConnection(_ctx context.Context, _p logging.Perspective, _odcid logging.ConnectionID) *logging.ConnectionTracer {
return newConnTracer(newClientCollector(t.config.index)) return newConnTracer(newClientCollector(t.index, t.logger))
} }
// connTracer collects connection level metrics // connTracer collects connection level metrics
@ -44,6 +38,7 @@ func newConnTracer(metricsCollector *clientCollector) *logging.ConnectionTracer
return &logging.ConnectionTracer{ return &logging.ConnectionTracer{
StartedConnection: tracer.StartedConnection, StartedConnection: tracer.StartedConnection,
ClosedConnection: tracer.ClosedConnection, ClosedConnection: tracer.ClosedConnection,
ReceivedTransportParameters: tracer.ReceivedTransportParameters,
SentLongHeaderPacket: tracer.SentLongHeaderPacket, SentLongHeaderPacket: tracer.SentLongHeaderPacket,
SentShortHeaderPacket: tracer.SentShortHeaderPacket, SentShortHeaderPacket: tracer.SentShortHeaderPacket,
ReceivedLongHeaderPacket: tracer.ReceivedLongHeaderPacket, ReceivedLongHeaderPacket: tracer.ReceivedLongHeaderPacket,
@ -63,6 +58,10 @@ func (ct *connTracer) ClosedConnection(err error) {
ct.metricsCollector.closedConnection(err) ct.metricsCollector.closedConnection(err)
} }
func (ct *connTracer) ReceivedTransportParameters(params *logging.TransportParameters) {
ct.metricsCollector.receivedTransportParameters(params)
}
func (ct *connTracer) BufferedPacket(pt logging.PacketType, size logging.ByteCount) { func (ct *connTracer) BufferedPacket(pt logging.PacketType, size logging.ByteCount) {
ct.metricsCollector.bufferedPackets(pt) ct.metricsCollector.bufferedPackets(pt)
} }
@ -94,17 +93,3 @@ func (ct *connTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, size
func (ct *connTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) { func (ct *connTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) {
ct.metricsCollector.receivedPackets(size, frames) ct.metricsCollector.receivedPackets(size, frames)
} }
type quicLogger struct {
logger *zerolog.Logger
connectionID string
}
func (qt *quicLogger) Write(p []byte) (n int, err error) {
qt.logger.Trace().Str("quicConnection", qt.connectionID).RawJSON("event", p).Msg("Quic event")
return len(p), nil
}
func (*quicLogger) Close() error {
return nil
}