From 14fa7834dabef53c82b38979343d68971b75e0f5 Mon Sep 17 00:00:00 2001 From: Calvin Giroud Date: Wed, 25 Mar 2026 01:08:19 +0000 Subject: [PATCH] Add connection-level timing metrics and key update tracking to Stats Add new fields to the public Stats struct for production observability: - handshake_duration: time from connection creation to handshake completion - key_update_count: number of 1-RTT key updates - peer_max_idle_timeout: peer's max idle timeout from transport params - connection_duration: wall-clock time since connection creation Implementation details: - Track created_at (Instant) and handshake_completed_at (Option) on Connection, initialized in with_tls() and set on handshake completion - Track key_update_count on Connection, incremented when a peer-initiated key update is verified - Populate new Stats fields in stats() method - Update Debug impl for Stats to include new fields - Expose via FFI: new fields in the C Stats struct plus standalone query functions (quiche_conn_stats_handshake_duration_ms, etc.) - Add unit tests verifying pre/post handshake behavior Co-Authored-By: Staging-Devin AI <166158716+staging-devin-ai-integration[bot]@users.noreply.github.com> --- quiche/src/ffi.rs | 48 +++++++++++++++++++++++++++++++++++ quiche/src/lib.rs | 62 +++++++++++++++++++++++++++++++++++++++++++++ quiche/src/tests.rs | 50 ++++++++++++++++++++++++++++++++++++ 3 files changed, 160 insertions(+) diff --git a/quiche/src/ffi.rs b/quiche/src/ffi.rs index 827fb01b382..c91ba8c9cd7 100644 --- a/quiche/src/ffi.rs +++ b/quiche/src/ffi.rs @@ -1346,6 +1346,10 @@ pub struct Stats { path_challenge_rx_count: u64, bytes_in_flight_duration_msec: u64, tx_buffered_inconsistent: bool, + handshake_duration_ms: i64, + key_update_count: u64, + peer_max_idle_timeout_ms: i64, + connection_duration_ms: u64, } pub struct TransportParams { @@ -1396,6 +1400,50 @@ pub extern "C" fn quiche_conn_stats(conn: &Connection, out: &mut Stats) { stats.bytes_in_flight_duration.as_millis() as u64; out.tx_buffered_inconsistent = stats.tx_buffered_state != TxBufferTrackingState::Ok; + out.handshake_duration_ms = stats + .handshake_duration + .map_or(-1, |d| d.as_millis() as i64); + out.key_update_count = stats.key_update_count; + out.peer_max_idle_timeout_ms = stats + .peer_max_idle_timeout + .map_or(-1, |d| d.as_millis() as i64); + out.connection_duration_ms = stats.connection_duration.as_millis() as u64; +} + +/// Returns the handshake duration in milliseconds, or -1 if the +/// handshake has not yet completed. +#[no_mangle] +pub extern "C" fn quiche_conn_stats_handshake_duration_ms( + conn: &Connection, +) -> i64 { + conn.stats() + .handshake_duration + .map_or(-1, |d| d.as_millis() as i64) +} + +/// Returns the number of 1-RTT key updates. +#[no_mangle] +pub extern "C" fn quiche_conn_stats_key_update_count(conn: &Connection) -> u64 { + conn.stats().key_update_count +} + +/// Returns the peer's max idle timeout in milliseconds, or -1 if +/// not available. +#[no_mangle] +pub extern "C" fn quiche_conn_stats_peer_max_idle_timeout_ms( + conn: &Connection, +) -> i64 { + conn.stats() + .peer_max_idle_timeout + .map_or(-1, |d| d.as_millis() as i64) +} + +/// Returns the connection duration in milliseconds. +#[no_mangle] +pub extern "C" fn quiche_conn_stats_connection_duration_ms( + conn: &Connection, +) -> u64 { + conn.stats().connection_duration.as_millis() as u64 } #[no_mangle] diff --git a/quiche/src/lib.rs b/quiche/src/lib.rs index 5610f833861..bdbe6f4a0c0 100644 --- a/quiche/src/lib.rs +++ b/quiche/src/lib.rs @@ -1503,6 +1503,15 @@ where /// Key phase bit used for outgoing protected packets. key_phase: bool, + /// The time the connection was created. + created_at: Instant, + + /// The time the handshake was completed. + handshake_completed_at: Option, + + /// The number of 1-RTT key updates. + key_update_count: u64, + /// Whether an ack-eliciting packet has been sent since last receiving a /// packet. ack_eliciting_sent: bool, @@ -2160,6 +2169,12 @@ impl Connection { key_phase: false, + created_at: Instant::now(), + + handshake_completed_at: None, + + key_update_count: 0, + ack_eliciting_sent: false, closed: false, @@ -3322,6 +3337,8 @@ impl Connection { trace!("{} key update verified", self.trace_id); + self.key_update_count += 1; + let _ = self.crypto_ctx[epoch].crypto_seal.replace(seal_next); let open_prev = self.crypto_ctx[epoch] @@ -7638,6 +7655,20 @@ impl Connection { path_challenge_rx_count: self.path_challenge_rx_count, bytes_in_flight_duration: self.bytes_in_flight_duration(), tx_buffered_state: self.tx_buffered_state, + handshake_duration: self + .handshake_completed_at + .map(|completed| completed.duration_since(self.created_at)), + key_update_count: self.key_update_count, + peer_max_idle_timeout: if self.parsed_peer_transport_params && + self.peer_transport_params.max_idle_timeout > 0 + { + Some(Duration::from_millis( + self.peer_transport_params.max_idle_timeout, + )) + } else { + None + }, + connection_duration: self.created_at.elapsed(), } } @@ -7889,6 +7920,10 @@ impl Connection { self.handshake_completed = self.handshake.is_completed(); + if self.handshake_completed && self.handshake_completed_at.is_none() { + self.handshake_completed_at = Some(Instant::now()); + } + self.alpn = self.handshake.alpn_protocol().to_vec(); let raw_params = self.handshake.quic_transport_params(); @@ -9242,6 +9277,19 @@ pub struct Stats { /// Health state of the connection's tx_buffered. pub tx_buffered_state: TxBufferTrackingState, + + /// The time from connection creation to handshake completion. + /// `None` if the handshake has not yet completed. + pub handshake_duration: Option, + + /// The number of 1-RTT key updates. + pub key_update_count: u64, + + /// The peer's max idle timeout from transport parameters. + pub peer_max_idle_timeout: Option, + + /// Wall-clock time since connection creation. + pub connection_duration: Duration, } impl std::fmt::Debug for Stats { @@ -9259,6 +9307,20 @@ impl std::fmt::Debug for Stats { self.sent_bytes, self.recv_bytes, self.lost_bytes, )?; + write!( + f, + " key_update_count={} connection_duration={:?}", + self.key_update_count, self.connection_duration, + )?; + + if let Some(hs) = self.handshake_duration { + write!(f, " handshake_duration={:?}", hs)?; + } + + if let Some(idle) = self.peer_max_idle_timeout { + write!(f, " peer_max_idle_timeout={:?}", idle)?; + } + Ok(()) } } diff --git a/quiche/src/tests.rs b/quiche/src/tests.rs index 0d7a1ecdffe..4ef73fa5b18 100644 --- a/quiche/src/tests.rs +++ b/quiche/src/tests.rs @@ -12486,3 +12486,53 @@ fn connect_custom_client_dcid_too_short() { ); assert_eq!(client.err().unwrap(), Error::InvalidDcidInitialization); } + +#[rstest] +fn connection_timing_stats_before_handshake( + #[values("cubic", "bbr2_gcongestion")] cc_algorithm_name: &str, +) { + let pipe = test_utils::Pipe::new(cc_algorithm_name).unwrap(); + + let client_stats = pipe.client.stats(); + let server_stats = pipe.server.stats(); + + // Before handshake, handshake_duration should be None. + assert!(client_stats.handshake_duration.is_none()); + assert!(server_stats.handshake_duration.is_none()); + + // connection_duration should be positive after creation. + assert!(client_stats.connection_duration > Duration::ZERO); + assert!(server_stats.connection_duration > Duration::ZERO); + + // key_update_count should start at 0. + assert_eq!(client_stats.key_update_count, 0); + assert_eq!(server_stats.key_update_count, 0); +} + +#[rstest] +fn connection_timing_stats_after_handshake( + #[values("cubic", "bbr2_gcongestion")] cc_algorithm_name: &str, +) { + let mut pipe = test_utils::Pipe::new(cc_algorithm_name).unwrap(); + assert_eq!(pipe.handshake(), Ok(())); + + let client_stats = pipe.client.stats(); + let server_stats = pipe.server.stats(); + + // After handshake, handshake_duration should be Some. + assert!(client_stats.handshake_duration.is_some()); + assert!(server_stats.handshake_duration.is_some()); + + // connection_duration should be positive. + assert!(client_stats.connection_duration > Duration::ZERO); + assert!(server_stats.connection_duration > Duration::ZERO); + + // key_update_count should still be 0 after handshake. + assert_eq!(client_stats.key_update_count, 0); + assert_eq!(server_stats.key_update_count, 0); + + // peer_max_idle_timeout should reflect transport params. + // The default test config sets max_idle_timeout to 180000ms. + assert!(client_stats.peer_max_idle_timeout.is_some()); + assert!(server_stats.peer_max_idle_timeout.is_some()); +}