gr1ffon/quic-go
1
0
Fork 0
forked from quic-go/quic-go
Code Pull Requests Activity

qlog loss recovery metrics

Browse Source
This commit is contained in:
Marten Seemann
2020-01-27 15:26:59 +07:00
parent a58bcb747b
commit f13ca7e791
6 changed files with 101 additions and 4 deletions
Download Patch File Download Diff File Expand all files Collapse all files

16
internal/ackhandler/sent_packet_handler.go
View File

@@ -10,6 +10,7 @@ import (
"github.com/lucas-clemente/quic-go/internal/qerr"
"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/lucas-clemente/quic-go/quictrace"
)
@@ -73,7 +74,8 @@ type sentPacketHandler struct {
traceCallback func(quictrace.Event)
logger utils.Logger
qlogger qlog.Tracer
logger utils.Logger
}
// NewSentPacketHandler creates a new sentPacketHandler
@@ -81,6 +83,7 @@ func NewSentPacketHandler(
initialPacketNumber protocol.PacketNumber,
rttStats *congestion.RTTStats,
traceCallback func(quictrace.Event),
qlogger qlog.Tracer,
logger utils.Logger,
) SentPacketHandler {
congestion := congestion.NewCubicSender(
@@ -96,6 +99,7 @@ func NewSentPacketHandler(
rttStats: rttStats,
congestion: congestion,
traceCallback: traceCallback,
qlogger: qlogger,
logger: logger,
}
}
@@ -209,6 +213,16 @@ func (h *sentPacketHandler) ReceivedAck(ackFrame *wire.AckFrame, withPacketNumbe
h.logger.Debugf("\tupdated RTT: %s (σ: %s)", h.rttStats.SmoothedRTT(), h.rttStats.MeanDeviation())
}
h.congestion.MaybeExitSlowStart()
if h.qlogger != nil {
packetsInFlight := h.appDataPackets.history.Len()
if h.handshakePackets != nil {
packetsInFlight += h.handshakePackets.history.Len()
}
if h.initialPackets != nil {
packetsInFlight += h.initialPackets.history.Len()
}
h.qlogger.UpdatedMetrics(rcvTime, h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, packetsInFlight)
}
}
ackedPackets, err := h.determineNewlyAckedPackets(ackFrame, encLevel)

2
internal/ackhandler/sent_packet_handler_test.go
View File

@@ -24,7 +24,7 @@ var _ = Describe("SentPacketHandler", func() {
BeforeEach(func() {
lostPackets = nil
rttStats := &congestion.RTTStats{}
handler = NewSentPacketHandler(42, rttStats, nil, utils.DefaultLogger).(*sentPacketHandler)
handler = NewSentPacketHandler(42, rttStats, nil, nil, utils.DefaultLogger).(*sentPacketHandler)
streamFrame = wire.StreamFrame{
StreamID: 5,
Data: []byte{0x13, 0x37},

30
qlog/event.go
View File

@@ -3,6 +3,8 @@ package qlog
import (
"time"
"github.com/lucas-clemente/quic-go/internal/protocol"
"github.com/francoispqt/gojay"
)
@@ -96,3 +98,31 @@ func (e eventRetryReceived) MarshalJSONObject(enc *gojay.Encoder) {
enc.StringKey("packet_type", packetTypeRetry.String())
enc.ObjectKey("header", e.Header)
}
func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 }
type eventMetricsUpdated struct {
MinRTT time.Duration
SmoothedRTT time.Duration
LatestRTT time.Duration
RTTVariance time.Duration
CongestionWindow protocol.ByteCount
BytesInFlight protocol.ByteCount
PacketsInFlight int
}
func (e eventMetricsUpdated) Category() category { return categoryRecovery }
func (e eventMetricsUpdated) Name() string { return "metrics_updated" }
func (e eventMetricsUpdated) IsNil() bool { return false }
func (e eventMetricsUpdated) MarshalJSONObject(enc *gojay.Encoder) {
enc.FloatKey("min_rtt", milliseconds(e.MinRTT))
enc.FloatKey("smoothed_rtt", milliseconds(e.SmoothedRTT))
enc.FloatKey("latest_rtt", milliseconds(e.LatestRTT))
enc.FloatKey("rtt_variance", milliseconds(e.RTTVariance))
enc.Uint64Key("congestion_window", uint64(e.CongestionWindow))
enc.Uint64Key("bytes_in_flight", uint64(e.BytesInFlight))
enc.Uint64KeyOmitEmpty("packets_in_flight", uint64(e.PacketsInFlight))
}

18
qlog/qlog.go
View File

@@ -4,6 +4,8 @@ import (
"io"
"time"
"github.com/lucas-clemente/quic-go/internal/congestion"
"github.com/francoispqt/gojay"
"github.com/lucas-clemente/quic-go/internal/protocol"
"github.com/lucas-clemente/quic-go/internal/wire"
@@ -15,6 +17,7 @@ type Tracer interface {
SentPacket(time.Time, *wire.ExtendedHeader, *wire.AckFrame, []wire.Frame)
ReceivedRetry(time.Time, *wire.Header)
ReceivedPacket(time.Time, *wire.ExtendedHeader, []wire.Frame)
UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, cwnd protocol.ByteCount, bytesInFLight protocol.ByteCount, packetsInFlight int)
}
type tracer struct {
@@ -101,3 +104,18 @@ func (t *tracer) ReceivedRetry(time time.Time, hdr *wire.Header) {
},
})
}
func (t *tracer) UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) {
t.events = append(t.events, event{
Time: time,
eventDetails: eventMetricsUpdated{
MinRTT: rttStats.MinRTT(),
SmoothedRTT: rttStats.SmoothedRTT(),
LatestRTT: rttStats.LatestRTT(),
RTTVariance: rttStats.MeanDeviation(),
CongestionWindow: cwnd,
BytesInFlight: bytesInFlight,
PacketsInFlight: packetsInFlight,
},
})
}

35
qlog/qlog_test.go
View File

@@ -6,6 +6,7 @@ import (
"io"
"time"
"github.com/lucas-clemente/quic-go/internal/congestion"
"github.com/lucas-clemente/quic-go/internal/protocol"
"github.com/lucas-clemente/quic-go/internal/wire"
@@ -180,5 +181,39 @@ var _ = Describe("Tracer", func() {
Expect(ev).To(HaveKey("header"))
Expect(ev).ToNot(HaveKey("frames"))
})
It("records metrics updates", func() {
now := time.Now()
rttStats := congestion.NewRTTStats()
rttStats.UpdateRTT(15*time.Millisecond, 0, now)
rttStats.UpdateRTT(20*time.Millisecond, 0, now)
rttStats.UpdateRTT(25*time.Millisecond, 0, now)
Expect(rttStats.MinRTT()).To(Equal(15 * time.Millisecond))
Expect(rttStats.SmoothedRTT()).To(And(
BeNumerically(">", 15*time.Millisecond),
BeNumerically("<", 25*time.Millisecond),
))
Expect(rttStats.LatestRTT()).To(Equal(25 * time.Millisecond))
tracer.UpdatedMetrics(
now,
rttStats,
4321,
1234,
42,
)
t, category, eventName, ev := exportAndParse()
Expect(t).To(BeTemporally("~", now, time.Millisecond))
Expect(category).To(Equal("recovery"))
Expect(eventName).To(Equal("metrics_updated"))
Expect(ev).To(HaveKeyWithValue("min_rtt", float64(15)))
Expect(ev).To(HaveKeyWithValue("latest_rtt", float64(25)))
Expect(ev).To(HaveKey("smoothed_rtt"))
Expect(time.Duration(ev["smoothed_rtt"].(float64)) * time.Millisecond).To(BeNumerically("~", rttStats.SmoothedRTT(), time.Millisecond))
Expect(ev).To(HaveKey("rtt_variance"))
Expect(time.Duration(ev["rtt_variance"].(float64)) * time.Millisecond).To(BeNumerically("~", rttStats.MeanDeviation(), time.Millisecond))
Expect(ev).To(HaveKeyWithValue("congestion_window", float64(4321)))
Expect(ev).To(HaveKeyWithValue("bytes_in_flight", float64(1234)))
Expect(ev).To(HaveKeyWithValue("packets_in_flight", float64(42)))
})
})
})

4
session.go
View File

@@ -248,7 +248,7 @@ var newSession = func(
s.queueControlFrame,
)
s.preSetup()
s.sentPacketHandler = ackhandler.NewSentPacketHandler(0, s.rttStats, s.traceCallback, s.logger)
s.sentPacketHandler = ackhandler.NewSentPacketHandler(0, s.rttStats, s.traceCallback, s.qlogger, s.logger)
initialStream := newCryptoStream()
handshakeStream := newCryptoStream()
params := &handshake.TransportParameters{
@@ -352,7 +352,7 @@ var newClientSession = func(
s.queueControlFrame,
)
s.preSetup()
s.sentPacketHandler = ackhandler.NewSentPacketHandler(initialPacketNumber, s.rttStats, s.traceCallback, s.logger)
s.sentPacketHandler = ackhandler.NewSentPacketHandler(initialPacketNumber, s.rttStats, s.traceCallback, s.qlogger, s.logger)
initialStream := newCryptoStream()
handshakeStream := newCryptoStream()
params := &handshake.TransportParameters{