From d38699f921ad270c5e4ca1beacccdd4072e35c50 Mon Sep 17 00:00:00 2001 From: Andy Grover Date: Wed, 17 Jun 2020 17:22:38 -0700 Subject: [PATCH] qlog: Implement packet_lost This is easiest if we change SentPacket to contain packet type and packet number. This change is mostly straightforward because we already were passing these around *with* SentPacket, so now it's not too painful to just put them *in* SentPacket. Having PNSpace derivable from PacketType also helps. Do not put qlog probe in handle_lost_packets(), because this is called for retry, 0rtt, and PTO, which should not be logged as lost. Go up a level and add qlog probe calls in process_timer() and handle_ack(). --- neqo-transport/src/connection.rs | 13 +-- neqo-transport/src/qlog.rs | 22 +++++ neqo-transport/src/recovery.rs | 138 ++++++++++++++++++++----------- neqo-transport/src/tracking.rs | 6 ++ 4 files changed, 126 insertions(+), 53 deletions(-) diff --git a/neqo-transport/src/connection.rs b/neqo-transport/src/connection.rs index 22a487af2d..0d12d156c5 100644 --- a/neqo-transport/src/connection.rs +++ b/neqo-transport/src/connection.rs @@ -872,6 +872,7 @@ impl Connection { let lost = self.loss_recovery.timeout(now); self.handle_lost_packets(&lost); + qlog::packets_lost(&mut self.qlog.borrow_mut(), &lost); } /// Call in to process activity on the connection. Either new packets have @@ -1618,6 +1619,8 @@ impl Connection { self.idle_timeout.on_packet_sent(now); } let sent = SentPacket::new( + pt, + pn, now, ack_eliciting, Rc::new(tokens), @@ -1627,13 +1630,13 @@ impl Connection { if pt == PacketType::Initial && self.role == Role::Client { // Packets containing Initial packets might need padding, and we want to // track that padding along with the Initial packet. So defer tracking. - initial_sent = Some((pn, sent)); + initial_sent = Some(sent); needs_padding = true; } else { if pt != PacketType::ZeroRtt { needs_padding = false; } - self.loss_recovery.on_packet_sent(*space, pn, sent); + self.loss_recovery.on_packet_sent(sent); } if *space == PNSpace::Handshake { @@ -1652,14 +1655,13 @@ impl Connection { } else { // Pad Initial packets sent by the client to mtu bytes. let mut packets: Vec = encoder.into(); - if let Some((initial_pn, mut initial)) = initial_sent.take() { + if let Some(mut initial) = initial_sent.take() { if needs_padding { qdebug!([self], "pad Initial to path MTU {}", path.mtu()); initial.size += path.mtu() - packets.len(); packets.resize(path.mtu(), 0); } - self.loss_recovery - .on_packet_sent(PNSpace::Initial, initial_pn, initial); + self.loss_recovery.on_packet_sent(initial); } Ok(SendOption::Yes(path.datagram(packets))) } @@ -2151,6 +2153,7 @@ impl Connection { } } self.handle_lost_packets(&lost_packets); + qlog::packets_lost(&mut self.qlog.borrow_mut(), &lost_packets); Ok(()) } diff --git a/neqo-transport/src/qlog.rs b/neqo-transport/src/qlog.rs index 7af965c9d0..497e759053 100644 --- a/neqo-transport/src/qlog.rs +++ b/neqo-transport/src/qlog.rs @@ -22,6 +22,7 @@ use crate::frame::{self, Frame}; use crate::packet::{DecryptedPacket, PacketNumber, PacketType, PublicPacket}; use crate::path::Path; use crate::tparams::{self, TransportParametersHandler}; +use crate::tracking::SentPacket; use crate::QuicVersion; pub fn connection_tparams_set(maybe_qlog: &mut Option, tph: &TransportParametersHandler) { @@ -161,6 +162,27 @@ pub fn packet_dropped(maybe_qlog: &mut Option, payload: &PublicPacket) } } +pub fn packets_lost(maybe_qlog: &mut Option, pkts: &[SentPacket]) { + if let Some(qlog) = maybe_qlog { + let mut res = Ok(()); + for pkt in pkts { + res = (|| { + qlog.stream().add_event(Event::packet_lost_min( + to_qlog_pkt_type(pkt.pt), + pkt.pn.to_string(), + Vec::new(), + ))?; + + qlog.stream().finish_frames() + })(); + if res.is_err() { + break; + } + } + handle_qlog_result(maybe_qlog, res) + } +} + pub fn packet_received(maybe_qlog: &mut Option, payload: &DecryptedPacket) { if let Some(qlog) = maybe_qlog { let mut d = Decoder::from(&payload[..]); diff --git a/neqo-transport/src/recovery.rs b/neqo-transport/src/recovery.rs index 2b67418408..01ba0e2b91 100644 --- a/neqo-transport/src/recovery.rs +++ b/neqo-transport/src/recovery.rs @@ -248,14 +248,14 @@ impl LossRecoverySpace { } } - pub fn on_packet_sent(&mut self, packet_number: u64, sent_packet: SentPacket) { + pub fn on_packet_sent(&mut self, sent_packet: SentPacket) { if sent_packet.ack_eliciting() { self.pto_base_time = Some(sent_packet.time_sent); if sent_packet.cc_in_flight() { self.in_flight_outstanding += 1; } } - self.sent_packets.insert(packet_number, sent_packet); + self.sent_packets.insert(sent_packet.pn, sent_packet); } pub fn remove_packet(&mut self, pn: u64) -> Option { @@ -548,14 +548,20 @@ impl LossRecovery { .collect() } - pub fn on_packet_sent(&mut self, pn_space: PNSpace, pn: u64, sent_packet: SentPacket) { - qdebug!([self], "packet {}-{} sent", pn_space, pn); + pub fn on_packet_sent(&mut self, sent_packet: SentPacket) { + let pn_space = PNSpace::from(sent_packet.pt); + qdebug!([self], "packet {}-{} sent", pn_space, sent_packet.pn); let rtt = self.rtt(); if let Some(space) = self.spaces.get_mut(pn_space) { self.cc.on_packet_sent(&sent_packet, rtt); - space.on_packet_sent(pn, sent_packet); + space.on_packet_sent(sent_packet); } else { - qinfo!([self], "ignoring {}-{} from dropped space", pn_space, pn); + qinfo!( + [self], + "ignoring {}-{} from dropped space", + pn_space, + sent_packet.pn + ); } } @@ -815,6 +821,7 @@ impl ::std::fmt::Display for LossRecovery { #[cfg(test)] mod tests { use super::{LossRecovery, LossRecoverySpace, PNSpace, SentPacket}; + use crate::packet::PacketType; use std::convert::TryInto; use std::rc::Rc; use std::time::{Duration, Instant}; @@ -891,11 +898,15 @@ mod tests { fn pace(lr: &mut LossRecovery, count: u64) { for pn in 0..count { - lr.on_packet_sent( - PNSpace::ApplicationData, + lr.on_packet_sent(SentPacket::new( + PacketType::Short, pn, - SentPacket::new(pn_time(pn), true, Rc::default(), ON_SENT_SIZE, true), - ); + pn_time(pn), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); } } @@ -1012,22 +1023,24 @@ mod tests { // So send two packets with 1/4 RTT between them. Acknowledge pn 1 after 1 RTT. // pn 0 should then be marked lost because it is then outstanding for 5RTT/4 // the loss time for packets is 9RTT/8. - lr.on_packet_sent( - PNSpace::ApplicationData, + lr.on_packet_sent(SentPacket::new( + PacketType::Short, 0, - SentPacket::new(pn_time(0), true, Rc::default(), ON_SENT_SIZE, true), - ); - lr.on_packet_sent( - PNSpace::ApplicationData, + pn_time(0), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); + lr.on_packet_sent(SentPacket::new( + PacketType::Short, 1, - SentPacket::new( - pn_time(0) + INITIAL_RTT / 4, - true, - Rc::default(), - ON_SENT_SIZE, - true, - ), - ); + pn_time(0) + INITIAL_RTT / 4, + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); let (_, lost) = lr.on_ack_received( PNSpace::ApplicationData, 1, @@ -1122,32 +1135,57 @@ mod tests { fn drop_spaces() { let mut lr = LossRecovery::new(); lr.start_pacer(now()); - lr.on_packet_sent( - PNSpace::Initial, + lr.on_packet_sent(SentPacket::new( + PacketType::Initial, 0, - SentPacket::new(pn_time(0), true, Rc::default(), ON_SENT_SIZE, true), - ); - lr.on_packet_sent( - PNSpace::Handshake, + pn_time(0), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); + lr.on_packet_sent(SentPacket::new( + PacketType::Handshake, 0, - SentPacket::new(pn_time(1), true, Rc::default(), ON_SENT_SIZE, true), - ); - lr.on_packet_sent( - PNSpace::ApplicationData, + pn_time(1), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); + lr.on_packet_sent(SentPacket::new( + PacketType::Short, 0, - SentPacket::new(pn_time(2), true, Rc::default(), ON_SENT_SIZE, true), - ); + pn_time(2), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); // Now put all spaces on the LR timer so we can see them. - let pkt = SentPacket::new(pn_time(3), true, Rc::default(), ON_SENT_SIZE, true); - for sp in PNSpace::iter() { - lr.on_packet_sent(*sp, 1, pkt.clone()); - lr.on_ack_received(*sp, 1, vec![(1, 1)], Duration::from_secs(0), pn_time(3)); + for sp in &[ + PacketType::Initial, + PacketType::Handshake, + PacketType::Short, + ] { + let sent_pkt = + SentPacket::new(*sp, 1, pn_time(3), true, Rc::default(), ON_SENT_SIZE, true); + let pn_space = PNSpace::from(sent_pkt.pt); + lr.on_packet_sent(sent_pkt); + lr.on_ack_received( + pn_space, + 1, + vec![(1, 1)], + Duration::from_secs(0), + pn_time(3), + ); let mut lost = Vec::new(); - lr.spaces - .get_mut(*sp) - .unwrap() - .detect_lost_packets(pn_time(3), INITIAL_RTT, &mut lost); + lr.spaces.get_mut(pn_space).unwrap().detect_lost_packets( + pn_time(3), + INITIAL_RTT, + &mut lost, + ); assert!(lost.is_empty()); } @@ -1159,11 +1197,15 @@ mod tests { // There are cases where we send a packet that is not subsequently tracked. // So check that this works. - lr.on_packet_sent( - PNSpace::Initial, + lr.on_packet_sent(SentPacket::new( + PacketType::Initial, 0, - SentPacket::new(pn_time(3), true, Rc::default(), ON_SENT_SIZE, true), - ); + pn_time(3), + true, + Rc::default(), + ON_SENT_SIZE, + true, + )); assert_sent_times(&lr, None, None, Some(pn_time(2))); } } diff --git a/neqo-transport/src/tracking.rs b/neqo-transport/src/tracking.rs index 8447d0d932..0e31354f8a 100644 --- a/neqo-transport/src/tracking.rs +++ b/neqo-transport/src/tracking.rs @@ -65,6 +65,8 @@ impl From for PNSpace { #[derive(Debug, Clone)] pub struct SentPacket { + pub pt: PacketType, + pub pn: u64, ack_eliciting: bool, pub time_sent: Instant, pub tokens: Rc>, @@ -79,6 +81,8 @@ pub struct SentPacket { impl SentPacket { pub fn new( + pt: PacketType, + pn: u64, time_sent: Instant, ack_eliciting: bool, tokens: Rc>, @@ -86,6 +90,8 @@ impl SentPacket { in_flight: bool, ) -> Self { Self { + pt, + pn, time_sent, ack_eliciting, tokens,