only export changed metrics in the metrics_updated event

qlog/event.go

@@ -182,7 +182,7 @@ func (e eventPacketDropped) MarshalJSONObject(enc *gojay.Encoder) {
 
 func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 }
 
-type eventMetricsUpdated struct {
+type metrics struct {
 	MinRTT      time.Duration
 	SmoothedRTT time.Duration
 	LatestRTT   time.Duration
@@ -193,19 +193,38 @@ type eventMetricsUpdated struct {
 	PacketsInFlight  int
 }
 
+type eventMetricsUpdated struct {
+	Last    *metrics
+	Current *metrics
+}
+
 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))
+	if e.Last == nil || e.Last.MinRTT != e.Current.MinRTT {
+		enc.FloatKey("min_rtt", milliseconds(e.Current.MinRTT))
+	}
+	if e.Last == nil || e.Last.SmoothedRTT != e.Current.SmoothedRTT {
+		enc.FloatKey("smoothed_rtt", milliseconds(e.Current.SmoothedRTT))
+	}
+	if e.Last == nil || e.Last.LatestRTT != e.Current.LatestRTT {
+		enc.FloatKey("latest_rtt", milliseconds(e.Current.LatestRTT))
+	}
+	if e.Last == nil || e.Last.RTTVariance != e.Current.RTTVariance {
+		enc.FloatKey("rtt_variance", milliseconds(e.Current.RTTVariance))
+	}
 
-	enc.Uint64Key("congestion_window", uint64(e.CongestionWindow))
-	enc.Uint64Key("bytes_in_flight", uint64(e.BytesInFlight))
-	enc.Uint64KeyOmitEmpty("packets_in_flight", uint64(e.PacketsInFlight))
+	if e.Last == nil || e.Last.CongestionWindow != e.Current.CongestionWindow {
+		enc.Uint64Key("congestion_window", uint64(e.Current.CongestionWindow))
+	}
+	if e.Last == nil || e.Last.BytesInFlight != e.Current.BytesInFlight {
+		enc.Uint64Key("bytes_in_flight", uint64(e.Current.BytesInFlight))
+	}
+	if e.Last == nil || e.Last.PacketsInFlight != e.Current.PacketsInFlight {
+		enc.Uint64KeyOmitEmpty("packets_in_flight", uint64(e.Current.PacketsInFlight))
+	}
 }
 
 type eventUpdatedPTO struct {

qlog/qlog.go

@@ -46,6 +46,8 @@ type tracer struct {
 	events     chan event
 	encodeErr  error
 	runStopped chan struct{}
+
+	lastMetrics *metrics
 }
 
 var _ Tracer = &tracer{}
@@ -231,7 +233,7 @@ func (t *tracer) DroppedPacket(packetType PacketType, size protocol.ByteCount, d
 }
 
 func (t *tracer) UpdatedMetrics(rttStats *congestion.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) {
-	t.recordEvent(&eventMetricsUpdated{
+	m := &metrics{
 		MinRTT:           rttStats.MinRTT(),
 		SmoothedRTT:      rttStats.SmoothedRTT(),
 		LatestRTT:        rttStats.LatestRTT(),
@@ -239,7 +241,12 @@ func (t *tracer) UpdatedMetrics(rttStats *congestion.RTTStats, cwnd, bytesInFlig
 		CongestionWindow: cwnd,
 		BytesInFlight:    bytesInFlight,
 		PacketsInFlight:  packetsInFlight,
+	}
+	t.recordEvent(&eventMetricsUpdated{
+		Last:    t.lastMetrics,
+		Current: m,
 	})
+	t.lastMetrics = m
 }
 
 func (t *tracer) LostPacket(encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason PacketLossReason) {

qlog/qlog_test.go

@@ -377,6 +377,50 @@ var _ = Describe("Tracer", func() {
 			Expect(ev).To(HaveKeyWithValue("packets_in_flight", float64(42)))
 		})
 
+		It("only logs the diff between two 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))
+
+			rttStats2 := congestion.NewRTTStats()
+			rttStats2.UpdateRTT(15*time.Millisecond, 0, now)
+			rttStats2.UpdateRTT(15*time.Millisecond, 0, now)
+			rttStats2.UpdateRTT(15*time.Millisecond, 0, now)
+			Expect(rttStats2.MinRTT()).To(Equal(15 * time.Millisecond))
+
+			Expect(rttStats.LatestRTT()).To(Equal(25 * time.Millisecond))
+			tracer.UpdatedMetrics(
+				rttStats,
+				4321,
+				1234,
+				42,
+			)
+			tracer.UpdatedMetrics(
+				rttStats2,
+				4321,
+				12345, // changed
+				42,
+			)
+			entries := exportAndParse()
+			Expect(entries).To(HaveLen(2))
+			Expect(entries[0].Time).To(BeTemporally("~", time.Now(), 10*time.Millisecond))
+			Expect(entries[0].Category).To(Equal("recovery"))
+			Expect(entries[0].Name).To(Equal("metrics_updated"))
+			Expect(entries[0].Event).To(HaveLen(7))
+			Expect(entries[1].Time).To(BeTemporally("~", time.Now(), 10*time.Millisecond))
+			Expect(entries[1].Category).To(Equal("recovery"))
+			Expect(entries[1].Name).To(Equal("metrics_updated"))
+			ev := entries[1].Event
+			Expect(ev).ToNot(HaveKey("min_rtt"))
+			Expect(ev).ToNot(HaveKey("congestion_window"))
+			Expect(ev).ToNot(HaveKey("packets_in_flight"))
+			Expect(ev).To(HaveKeyWithValue("bytes_in_flight", float64(12345)))
+			Expect(ev).To(HaveKeyWithValue("smoothed_rtt", float64(15)))
+		})
+
 		It("records lost packets", func() {
 			tracer.LostPacket(protocol.EncryptionHandshake, 42, PacketLossReorderingThreshold)
 			entry := exportAndParseSingle()