diff --git a/src/client.rs b/src/client.rs index 94940dea..c4cf3500 100644 --- a/src/client.rs +++ b/src/client.rs @@ -7,6 +7,7 @@ use hyper_util::rt::{TokioExecutor, TokioIo}; use rand::prelude::*; use std::{ io::Write, + num::NonZeroU64, sync::{ Arc, atomic::{AtomicBool, Ordering::Relaxed}, @@ -43,25 +44,45 @@ fn format_host_port(host: &str, port: u16) -> String { #[derive(Debug, Clone, Copy)] pub struct ConnectionTime { - pub dns_lookup: std::time::Duration, - pub dialup: std::time::Duration, + /// nanoseconds + dns_lookup: NonZeroU64, + /// nanoseconds + dialup: NonZeroU64, +} + +impl ConnectionTime { + pub fn new(dns_lookup: std::time::Duration, dialup: std::time::Duration) -> Self { + Self { + dns_lookup: NonZeroU64::new((dns_lookup.as_nanos() as u64).max(1)).unwrap(), + dialup: NonZeroU64::new((dialup.as_nanos() as u64).max(1)).unwrap(), + } + } +} + +impl ConnectionTime { + pub fn dns_lookup(&self) -> std::time::Duration { + std::time::Duration::from_nanos(self.dns_lookup.get()) + } + + pub fn dialup(&self) -> std::time::Duration { + std::time::Duration::from_nanos(self.dialup.get()) + } } #[derive(Debug, Clone)] /// a result for a request pub struct RequestResult { pub rng: Pcg64Si, - // When the query should started - pub start_latency_correction: Option, /// When the query started + /// It maybe corrected time when latency correction is applied pub start: std::time::Instant, /// DNS + dialup /// None when reuse connection pub connection_time: Option, /// First body byte received - pub first_byte: Option, - /// When the query ends - pub end: std::time::Instant, + pub first_byte: Option, + /// Total duration in nanoseconds + pub duration: u64, /// HTTP status pub status: http::StatusCode, /// Length of body @@ -71,7 +92,16 @@ pub struct RequestResult { impl RequestResult { /// Duration the request takes. pub fn duration(&self) -> std::time::Duration { - self.end - self.start_latency_correction.unwrap_or(self.start) + std::time::Duration::from_nanos(self.duration) + } + + pub fn first_byte(&self) -> Option { + self.first_byte + .map(|fb| std::time::Duration::from_nanos(fb.get())) + } + + pub fn end(&self) -> std::time::Instant { + self.start + self.duration() } } @@ -698,10 +728,7 @@ impl Client { self.client_http1(&self.url, &mut client_state.rng).await?; let dialup = std::time::Instant::now(); - connection_time = Some(ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }); + connection_time = Some(ConnectionTime::new(dns_lookup - start, dialup - start)); send_request }; while send_request.ready().await.is_err() { @@ -712,10 +739,7 @@ impl Client { self.client_http1(&self.url, &mut client_state.rng).await?; send_request = send_request_; let dialup = std::time::Instant::now(); - connection_time = Some(ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }); + connection_time = Some(ConnectionTime::new(dns_lookup - start, dialup - start)); } match send_request.send_request(request).await { Ok(res) => { @@ -752,10 +776,11 @@ impl Client { let result = RequestResult { rng, - start_latency_correction: None, start, - first_byte, - end, + first_byte: first_byte.map(|t| { + NonZeroU64::new((t - start).as_nanos().max(1) as u64).unwrap() + }), + duration: (end - start).as_nanos() as u64, status, len_bytes, connection_time, @@ -846,20 +871,14 @@ impl Client { let dialup = std::time::Instant::now(); Ok(( - ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }, + ConnectionTime::new(dns_lookup - start, dialup - start), send_request, )) } else { let send_request = stream.handshake_http2().await?; let dialup = std::time::Instant::now(); Ok(( - ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }, + ConnectionTime::new(dns_lookup - start, dialup - start), send_request, )) } @@ -868,10 +887,7 @@ impl Client { let send_request = stream.handshake_http2().await?; let dialup = std::time::Instant::now(); Ok(( - ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }, + ConnectionTime::new(dns_lookup - start, dialup - start), send_request, )) } @@ -904,10 +920,11 @@ impl Client { let result = RequestResult { rng, - start_latency_correction: None, start, - first_byte, - end, + first_byte: first_byte.map(|t| { + NonZeroU64::new((t - start).as_nanos().max(1) as u64).unwrap() + }), + duration: (end - start).as_nanos() as u64, status, len_bytes, connection_time, @@ -1093,7 +1110,16 @@ pub(crate) fn set_start_latency_correction( start_latency_correction: std::time::Instant, ) { if let Ok(res) = res { - res.start_latency_correction = Some(start_latency_correction); + let delta_nanos = (res.start - start_latency_correction).as_nanos() as u64; + res.start = start_latency_correction; + res.duration += delta_nanos; + if let Some(first_byte) = res.first_byte.as_mut() { + *first_byte = first_byte.saturating_add(delta_nanos); + } + if let Some(connection_time) = res.connection_time.as_mut() { + connection_time.dns_lookup = connection_time.dns_lookup.saturating_add(delta_nanos); + connection_time.dialup = connection_time.dialup.saturating_add(delta_nanos); + } } } diff --git a/src/client_h3.rs b/src/client_h3.rs index 83831591..8e228b98 100644 --- a/src/client_h3.rs +++ b/src/client_h3.rs @@ -8,6 +8,7 @@ use kanal::AsyncReceiver; use quinn::default_runtime; use std::net::SocketAddr; use std::net::UdpSocket; +use std::num::NonZeroU64; use std::sync::Arc; use std::sync::atomic::AtomicBool; use std::sync::atomic::AtomicIsize; @@ -73,10 +74,7 @@ impl Client { let send_request = stream.handshake_http3().await?; let dialup = std::time::Instant::now(); Ok(( - ConnectionTime { - dns_lookup: dns_lookup - start, - dialup: dialup - start, - }, + ConnectionTime::new(dns_lookup - start, dialup - start), send_request, )) } @@ -158,10 +156,10 @@ impl Client { let result = RequestResult { rng, - start_latency_correction: None, start, - first_byte, - end, + first_byte: first_byte + .map(|fb| NonZeroU64::new((fb - start).as_nanos().max(1) as u64).unwrap()), + duration: (end - start).as_nanos() as u64, status, len_bytes, connection_time, diff --git a/src/db.rs b/src/db.rs index a021721c..b226f5b1 100644 --- a/src/db.rs +++ b/src/db.rs @@ -7,8 +7,7 @@ fn create_db(conn: &Connection) -> Result { "CREATE TABLE IF NOT EXISTS oha ( url TEXT NOT NULL, start REAL NOT NULL, - start_latency_correction REAL, - end REAL NOT NULL, + first_byte REAL, duration REAL NOT NULL, status INTEGER NOT NULL, len_bytes INTEGER NOT NULL, @@ -35,12 +34,11 @@ pub fn store( let req = client.generate_request(&mut request.rng.clone()).unwrap().0; let url = req.uri(); affected_rows += t.execute( - "INSERT INTO oha (url, start, start_latency_correction, end, duration, status, len_bytes, run) VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8)", + "INSERT INTO oha (url, start, first_byte, duration, status, len_bytes, run) VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7)", ( url.to_string(), (request.start - start).as_secs_f64(), - request.start_latency_correction.map(|d| (d - start).as_secs_f64()), - (request.end - start).as_secs_f64(), + request.first_byte().map(|fb| fb.as_secs_f64()), request.duration().as_secs_f64(), request.status.as_u16() as i64, request.len_bytes, @@ -71,11 +69,10 @@ mod test_db { rng: SeedableRng::seed_from_u64(0), status: hyper::StatusCode::OK, len_bytes: 100, - start_latency_correction: None, start: std::time::Instant::now(), connection_time: None, first_byte: None, - end: std::time::Instant::now(), + duration: 1000000, }; let test_vec = vec![test_val.clone(), test_val.clone()]; let client = Client::default(); diff --git a/src/monitor.rs b/src/monitor.rs index eb6fd3f1..765dc734 100644 --- a/src/monitor.rs +++ b/src/monitor.rs @@ -137,7 +137,7 @@ impl Monitor { let mut bar_num_req = vec![0u64; count]; let short_bin = (now - self.start).as_secs_f64() % bin; for r in all.success().iter().rev() { - let past = (now - r.end).as_secs_f64(); + let past = (now - r.end()).as_secs_f64(); let i = if past <= short_bin { 0 } else { @@ -224,7 +224,7 @@ impl Monitor { let last_1_timescale = { let success = all.success(); let index = match success.binary_search_by(|probe| { - (now - probe.end) + (now - probe.end()) .as_secs_f64() .partial_cmp(×cale.as_secs_f64()) // Should be fine diff --git a/src/printer.rs b/src/printer.rs index 1551a051..81c2dc41 100644 --- a/src/printer.rs +++ b/src/printer.rs @@ -392,13 +392,10 @@ fn print_csv(w: &mut W, start: Instant, res: &ResultData) -> std::io:: for request in success_requests { let dns_and_dialup = match request.connection_time { - Some(connection_time) => (connection_time.dns_lookup, connection_time.dialup), + Some(connection_time) => (connection_time.dns_lookup(), connection_time.dialup()), None => (std::time::Duration::ZERO, std::time::Duration::ZERO), }; - let first_byte = match request.first_byte { - Some(first_byte) => first_byte - request.start, - None => std::time::Duration::ZERO, - }; + let first_byte = request.first_byte().unwrap_or(std::time::Duration::ZERO); writeln!( w, "{},{},{},{},{},{},{}", diff --git a/src/result_data.rs b/src/result_data.rs index 30b6a388..86caa3b5 100644 --- a/src/result_data.rs +++ b/src/result_data.rs @@ -108,7 +108,7 @@ impl ResultData { } pub fn end_times_from_start(&self, start: Instant) -> impl Iterator + '_ { - self.success.iter().map(move |result| result.end - start) + self.success.iter().map(move |result| result.end() - start) } pub fn status_code_distribution(&self) -> BTreeMap { @@ -123,14 +123,14 @@ impl ResultData { pub fn dns_dialup_stat(&self) -> MinMaxMean { self.success .iter() - .filter_map(|r| r.connection_time.map(|ct| ct.dialup.as_secs_f64())) + .filter_map(|r| r.connection_time.map(|ct| ct.dialup().as_secs_f64())) .collect() } pub fn dns_lookup_stat(&self) -> MinMaxMean { self.success .iter() - .filter_map(|r| r.connection_time.map(|ct| ct.dns_lookup.as_secs_f64())) + .filter_map(|r| r.connection_time.map(|ct| ct.dns_lookup().as_secs_f64())) .collect() } @@ -185,7 +185,7 @@ mod tests { use super::*; use crate::client::{ClientError, ConnectionTime, RequestResult}; - use std::time::{Duration, Instant}; + use std::{num::NonZeroU64, time::Instant}; fn build_mock_request_result( status: StatusCode, @@ -198,16 +198,13 @@ mod tests { let now = Instant::now(); Ok(RequestResult { rng: SeedableRng::seed_from_u64(0), - start_latency_correction: None, start: now, - connection_time: Some(ConnectionTime { - dns_lookup: Duration::from_millis(connection_time_dns_lookup), - dialup: Duration::from_millis(connection_time_dialup), - }), - first_byte: Some(now.checked_add(Duration::from_millis(first_byte)).unwrap()), - end: now - .checked_add(Duration::from_millis(request_time)) - .unwrap(), + connection_time: Some(ConnectionTime::new( + std::time::Duration::from_millis(connection_time_dns_lookup), + std::time::Duration::from_millis(connection_time_dialup), + )), + first_byte: Some(NonZeroU64::new(first_byte * 1_000_000).unwrap()), + duration: request_time * 1_000_000, status, len_bytes: size, }) diff --git a/tests/tests.rs b/tests/tests.rs index 1f0166e0..d1bb9911 100644 --- a/tests/tests.rs +++ b/tests/tests.rs @@ -1240,8 +1240,9 @@ async fn test_csv_output() { let current_start = f64::from_str(parts[0]).unwrap(); assert!(current_start >= latest_start); latest_start = current_start; + // This value could be zero if connections are reused, so we use >= assert!(f64::from_str(parts[1]).unwrap() >= 0f64); - assert!(f64::from_str(parts[2]).unwrap() > 0f64); + assert!(f64::from_str(parts[2]).unwrap() >= 0f64); assert!(f64::from_str(parts[3]).unwrap() > 0f64); assert!(f64::from_str(parts[4]).unwrap() > 0f64); assert_eq!(usize::from_str(parts[5]).unwrap(), 11);