Merge pull request #3134 from lucas-clemente/trace-acked-packets

make it possible to trace acknowledged packets

integrationtests/self/self_suite_test.go

@@ -355,6 +355,7 @@ func (t *connTracer) DroppedPacket(logging.PacketType, logging.ByteCount, loggin
 func (t *connTracer) UpdatedMetrics(rttStats *logging.RTTStats, cwnd, bytesInFlight logging.ByteCount, packetsInFlight int) {
 }
 
+func (t *connTracer) AcknowledgedPacket(logging.EncryptionLevel, logging.PacketNumber) {}
 func (t *connTracer) LostPacket(logging.EncryptionLevel, logging.PacketNumber, logging.PacketLossReason) {
 }
 func (t *connTracer) UpdatedCongestionState(logging.CongestionState)                     {}

integrationtests/self/tracer_test.go

@@ -57,6 +57,7 @@ func (t *customConnTracer) DroppedPacket(logging.PacketType, logging.ByteCount,
 func (t *customConnTracer) UpdatedMetrics(rttStats *logging.RTTStats, cwnd, bytesInFlight logging.ByteCount, packetsInFlight int) {
 }
 
+func (t *customConnTracer) AcknowledgedPacket(logging.EncryptionLevel, logging.PacketNumber) {}
 func (t *customConnTracer) LostPacket(logging.EncryptionLevel, logging.PacketNumber, logging.PacketLossReason) {
 }
 func (t *customConnTracer) UpdatedCongestionState(logging.CongestionState)                     {}

internal/ackhandler/sent_packet_handler.go

@@ -311,9 +311,6 @@ func (h *sentPacketHandler) ReceivedAck(ack *wire.AckFrame, encLevel protocol.En
 		return err
 	}
 	for _, p := range ackedPackets {
-		if p.skippedPacket {
-			return fmt.Errorf("received an ACK for skipped packet number: %d (%s)", p.PacketNumber, encLevel)
-		}
 		if p.includedInBytesInFlight && !p.declaredLost {
 			h.congestion.OnPacketAcked(p.PacketNumber, p.Length, priorInFlight, rcvTime)
 		}
@@ -367,15 +364,17 @@ func (h *sentPacketHandler) detectAndRemoveAckedPackets(ack *wire.AckFrame, encL
 				ackRange = ack.AckRanges[len(ack.AckRanges)-1-ackRangeIndex]
 			}
 
-			if p.PacketNumber >= ackRange.Smallest { // packet i contained in ACK range
+			if p.PacketNumber < ackRange.Smallest { // packet not contained in ACK range
-				if p.PacketNumber > ackRange.Largest {
+				return true, nil
-					return false, fmt.Errorf("BUG: ackhandler would have acked wrong packet %d, while evaluating range %d -> %d", p.PacketNumber, ackRange.Smallest, ackRange.Largest)
+			}
-				}
+			if p.PacketNumber > ackRange.Largest {
-				h.ackedPackets = append(h.ackedPackets, p)
+				return false, fmt.Errorf("BUG: ackhandler would have acked wrong packet %d, while evaluating range %d -> %d", p.PacketNumber, ackRange.Smallest, ackRange.Largest)
 			}
-		} else {
-			h.ackedPackets = append(h.ackedPackets, p)
 		}
+		if p.skippedPacket {
+			return false, fmt.Errorf("received an ACK for skipped packet number: %d (%s)", p.PacketNumber, encLevel)
+		}
+		h.ackedPackets = append(h.ackedPackets, p)
 		return true, nil
 	})
 	if h.logger.Debug() && len(h.ackedPackets) > 0 {
@@ -399,6 +398,9 @@ func (h *sentPacketHandler) detectAndRemoveAckedPackets(ack *wire.AckFrame, encL
 		if err := pnSpace.history.Remove(p.PacketNumber); err != nil {
 			return nil, err
 		}
+		if h.tracer != nil {
+			h.tracer.AcknowledgedPacket(encLevel, p.PacketNumber)
+		}
 	}
 
 	return h.ackedPackets, err

internal/mocks/logging/connection_tracer.go

@@ -39,6 +39,18 @@ func (m *MockConnectionTracer) EXPECT() *MockConnectionTracerMockRecorder {
 	return m.recorder
 }
 
+// AcknowledgedPacket mocks base method.
+func (m *MockConnectionTracer) AcknowledgedPacket(arg0 protocol.EncryptionLevel, arg1 protocol.PacketNumber) {
+	m.ctrl.T.Helper()
+	m.ctrl.Call(m, "AcknowledgedPacket", arg0, arg1)
+}
+
+// AcknowledgedPacket indicates an expected call of AcknowledgedPacket.
+func (mr *MockConnectionTracerMockRecorder) AcknowledgedPacket(arg0, arg1 interface{}) *gomock.Call {
+	mr.mock.ctrl.T.Helper()
+	return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "AcknowledgedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).AcknowledgedPacket), arg0, arg1)
+}
+
 // BufferedPacket mocks base method.
 func (m *MockConnectionTracer) BufferedPacket(arg0 logging.PacketType) {
 	m.ctrl.T.Helper()

logging/interface.go

@@ -115,6 +115,7 @@ type ConnectionTracer interface {
 	BufferedPacket(PacketType)
 	DroppedPacket(PacketType, ByteCount, PacketDropReason)
 	UpdatedMetrics(rttStats *RTTStats, cwnd, bytesInFlight ByteCount, packetsInFlight int)
+	AcknowledgedPacket(EncryptionLevel, PacketNumber)
 	LostPacket(EncryptionLevel, PacketNumber, PacketLossReason)
 	UpdatedCongestionState(CongestionState)
 	UpdatedPTOCount(value uint32)

logging/mock_connection_tracer_test.go

@@ -38,6 +38,18 @@ func (m *MockConnectionTracer) EXPECT() *MockConnectionTracerMockRecorder {
 	return m.recorder
 }
 
+// AcknowledgedPacket mocks base method.
+func (m *MockConnectionTracer) AcknowledgedPacket(arg0 protocol.EncryptionLevel, arg1 protocol.PacketNumber) {
+	m.ctrl.T.Helper()
+	m.ctrl.Call(m, "AcknowledgedPacket", arg0, arg1)
+}
+
+// AcknowledgedPacket indicates an expected call of AcknowledgedPacket.
+func (mr *MockConnectionTracerMockRecorder) AcknowledgedPacket(arg0, arg1 interface{}) *gomock.Call {
+	mr.mock.ctrl.T.Helper()
+	return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "AcknowledgedPacket", reflect.TypeOf((*MockConnectionTracer)(nil).AcknowledgedPacket), arg0, arg1)
+}
+
 // BufferedPacket mocks base method.
 func (m *MockConnectionTracer) BufferedPacket(arg0 PacketType) {
 	m.ctrl.T.Helper()

logging/multiplex.go

@@ -139,6 +139,12 @@ func (m *connTracerMultiplexer) UpdatedMetrics(rttStats *RTTStats, cwnd, bytesIn
 	}
 }
 
+func (m *connTracerMultiplexer) AcknowledgedPacket(encLevel EncryptionLevel, pn PacketNumber) {
+	for _, t := range m.tracers {
+		t.AcknowledgedPacket(encLevel, pn)
+	}
+}
+
 func (m *connTracerMultiplexer) LostPacket(encLevel EncryptionLevel, pn PacketNumber, reason PacketLossReason) {
 	for _, t := range m.tracers {
 		t.LostPacket(encLevel, pn, reason)

logging/multiplex_test.go

@@ -190,6 +190,12 @@ var _ = Describe("Tracing", func() {
 			tracer.UpdatedMetrics(rttStats, 1337, 42, 13)
 		})
 
+		It("traces the AcknowledgedPacket event", func() {
+			tr1.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42))
+			tr2.EXPECT().AcknowledgedPacket(EncryptionHandshake, PacketNumber(42))
+			tracer.AcknowledgedPacket(EncryptionHandshake, 42)
+		})
+
 		It("traces the LostPacket event", func() {
 			tr1.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold)
 			tr2.EXPECT().LostPacket(EncryptionHandshake, PacketNumber(42), PacketLossReorderingThreshold)

qlog/qlog.go

@@ -348,6 +348,8 @@ func (t *connectionTracer) UpdatedMetrics(rttStats *utils.RTTStats, cwnd, bytesI
 	t.mutex.Unlock()
 }
 
+func (t *connectionTracer) AcknowledgedPacket(protocol.EncryptionLevel, protocol.PacketNumber) {}
+
 func (t *connectionTracer) LostPacket(encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason logging.PacketLossReason) {
 	t.mutex.Lock()
 	t.recordEvent(time.Now(), &eventPacketLost{