From 94b3fd5737203cf26a4dcf7b6887a42a0050e238 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Tue, 13 Jun 2023 01:42:07 -0400 Subject: [PATCH 01/11] wip --- src/frontend/http.rs | 10 +++++++++- src/frontend/mod.rs | 2 ++ src/frontend/timing.rs | 15 +++++++++++++++ 3 files changed, 26 insertions(+), 1 deletion(-) create mode 100644 src/frontend/timing.rs diff --git a/src/frontend/http.rs b/src/frontend/http.rs index acd44dfc..f7b7c049 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -43,6 +43,7 @@ use crate::{ is_read_only, is_statement_read_only, DefaultSeafowlContext, SeafowlContext, }, }; +use crate::frontend::{instrument, handle_request}; use super::http_utils::{handle_rejection, into_response, ApiError}; @@ -477,7 +478,6 @@ pub fn filters( .max_age(CORS_MAXAGE); let log = warp::log(module_path!()); - // Cached read query let ctx = context.clone(); let cached_read_query_route = warp::path!(String / "q" / String) @@ -549,11 +549,19 @@ pub fn filters( .then(upload) .map(into_response); + let instrument_filter = instrument().clone(); + cached_read_query_route .or(uncached_read_write_query_route) .or(upload_route) + .and(instrument_filter) + .and(warp::body::bytes()) + .and_then(|start_time, body| async move { + handle_request(start_time, body).await + }) .with(cors) .with(log) + .with(warp::trace::request())// experiment: print warp's built-in tracing .map(|r| with_header(r, header::VARY, VARY)) .recover(handle_rejection) } diff --git a/src/frontend/mod.rs b/src/frontend/mod.rs index 3897a3ac..cdc0e420 100644 --- a/src/frontend/mod.rs +++ b/src/frontend/mod.rs @@ -2,3 +2,5 @@ pub mod http; pub mod http_utils; #[cfg(feature = "frontend-postgres")] pub mod postgres; +pub mod timing; +pub use self::timing::{instrument, handle_request}; \ No newline at end of file diff --git a/src/frontend/timing.rs b/src/frontend/timing.rs new file mode 100644 index 00000000..4f31aa57 --- /dev/null +++ b/src/frontend/timing.rs @@ -0,0 +1,15 @@ +use std::time::Instant; +use warp::{Filter, Rejection, Reply}; + +pub fn instrument() -> impl Filter + Copy { + warp::any().map(|| Instant::now()) +} + +pub async fn handle_request( + start_time: Instant, + body: warp::hyper::body::Bytes, +) -> Result { + let elapsed = start_time.elapsed(); + let response_with_header = warp::reply::with_header(body, "X-Runtime", format!("{:?}", elapsed)); + Ok(response_with_header) +} \ No newline at end of file From 8466d6bbf426973067197f0c31cbbea0840b9c6f Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Thu, 15 Jun 2023 02:21:23 -0400 Subject: [PATCH 02/11] Use an explicit timing approach - Adopt `X-Seafowl-Runtime` header - TODO: make it configurable - TODO: confirm that this is measuring what we want it to measure --- src/frontend/http.rs | 25 +++++++++++++++++-------- src/frontend/mod.rs | 2 -- src/frontend/timing.rs | 15 --------------- 3 files changed, 17 insertions(+), 25 deletions(-) delete mode 100644 src/frontend/timing.rs diff --git a/src/frontend/http.rs b/src/frontend/http.rs index f7b7c049..b0b389a5 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -43,7 +43,6 @@ use crate::{ is_read_only, is_statement_read_only, DefaultSeafowlContext, SeafowlContext, }, }; -use crate::frontend::{instrument, handle_request}; use super::http_utils::{handle_rejection, into_response, ApiError}; @@ -52,6 +51,7 @@ const BEARER_PREFIX: &str = "Bearer "; // We have a very lax CORS on this, so we don't mind browsers // caching it for as long as possible. const CORS_MAXAGE: u32 = 86400; +const RUNTIME_HEADER: &str = "X-Seafowl-Runtime"; // Vary on Origin, as warp's CORS responds with Access-Control-Allow-Origin: [origin], // so we can't cache the response in the browser if the origin changes. @@ -156,6 +156,9 @@ pub async fn uncached_read_write_query( query: String, mut context: Arc, ) -> Result { + // Start a timer + let start_time = std::time::Instant::now(); + // If a specific DB name was used as a parameter in the route, scope the context to it, // effectively making it the default DB for the duration of the session. if database_name != context.database { @@ -216,6 +219,12 @@ pub async fn uncached_read_write_query( .headers_mut() .insert(header::CONTENT_TYPE, content_type_with_schema(schema)); } + + let elapsed = start_time.elapsed(); + response + .headers_mut() + .insert(RUNTIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); + Ok(response) } @@ -286,6 +295,8 @@ pub async fn cached_read_query( if_none_match: Option, mut context: Arc, ) -> Result { + // Start a timer + let start_time = std::time::Instant::now(); // Ignore dots at the end let query_or_hash = query_or_hash.split('.').next().unwrap(); @@ -347,6 +358,11 @@ pub async fn cached_read_query( let schema = physical.schema().clone(); let mut response = plan_to_response(context, physical).await?; + // Compute runtime + let elapsed = start_time.elapsed(); + response + .headers_mut() + .insert(RUNTIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); response .headers_mut() .insert(header::ETAG, etag.parse().unwrap()); @@ -549,16 +565,9 @@ pub fn filters( .then(upload) .map(into_response); - let instrument_filter = instrument().clone(); - cached_read_query_route .or(uncached_read_write_query_route) .or(upload_route) - .and(instrument_filter) - .and(warp::body::bytes()) - .and_then(|start_time, body| async move { - handle_request(start_time, body).await - }) .with(cors) .with(log) .with(warp::trace::request())// experiment: print warp's built-in tracing diff --git a/src/frontend/mod.rs b/src/frontend/mod.rs index cdc0e420..3897a3ac 100644 --- a/src/frontend/mod.rs +++ b/src/frontend/mod.rs @@ -2,5 +2,3 @@ pub mod http; pub mod http_utils; #[cfg(feature = "frontend-postgres")] pub mod postgres; -pub mod timing; -pub use self::timing::{instrument, handle_request}; \ No newline at end of file diff --git a/src/frontend/timing.rs b/src/frontend/timing.rs deleted file mode 100644 index 4f31aa57..00000000 --- a/src/frontend/timing.rs +++ /dev/null @@ -1,15 +0,0 @@ -use std::time::Instant; -use warp::{Filter, Rejection, Reply}; - -pub fn instrument() -> impl Filter + Copy { - warp::any().map(|| Instant::now()) -} - -pub async fn handle_request( - start_time: Instant, - body: warp::hyper::body::Bytes, -) -> Result { - let elapsed = start_time.elapsed(); - let response_with_header = warp::reply::with_header(body, "X-Runtime", format!("{:?}", elapsed)); - Ok(response_with_header) -} \ No newline at end of file From f7e2995c40f2061eef6342e61a3d87031ba4acea Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Thu, 15 Jun 2023 14:24:50 -0400 Subject: [PATCH 03/11] Drop Warp built-in timing --- src/frontend/http.rs | 1 - 1 file changed, 1 deletion(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index b0b389a5..cc813259 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -570,7 +570,6 @@ pub fn filters( .or(upload_route) .with(cors) .with(log) - .with(warp::trace::request())// experiment: print warp's built-in tracing .map(|r| with_header(r, header::VARY, VARY)) .recover(handle_rejection) } From 6b32a624f0c9fb888bd97a26651150bc192aca83 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Mon, 19 Jun 2023 14:13:05 -0400 Subject: [PATCH 04/11] Adopt a new header name - Decided to stick with one metric for now, so rename accordingly --- src/frontend/http.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index cc813259..0f56e982 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -51,7 +51,7 @@ const BEARER_PREFIX: &str = "Bearer "; // We have a very lax CORS on this, so we don't mind browsers // caching it for as long as possible. const CORS_MAXAGE: u32 = 86400; -const RUNTIME_HEADER: &str = "X-Seafowl-Runtime"; +const QUERY_TIME_HEADER: &str = "X-Seafowl-Query-Time"; // Vary on Origin, as warp's CORS responds with Access-Control-Allow-Origin: [origin], // so we can't cache the response in the browser if the origin changes. @@ -223,7 +223,7 @@ pub async fn uncached_read_write_query( let elapsed = start_time.elapsed(); response .headers_mut() - .insert(RUNTIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); + .insert(QUERY_TIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); Ok(response) } @@ -362,7 +362,7 @@ pub async fn cached_read_query( let elapsed = start_time.elapsed(); response .headers_mut() - .insert(RUNTIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); + .insert(QUERY_TIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); response .headers_mut() .insert(header::ETAG, etag.parse().unwrap()); From 1931ab2b70cf7e719d5f600824e9259fcbe96636 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Mon, 19 Jun 2023 21:03:43 -0400 Subject: [PATCH 05/11] Extract Timer code into own impl - Improve safety by wrapping with Option - Apparently old Rust versions could panic when time "went backwards" in the OS, hopefully using types will help safeguard against that. - Optionally return a raw .elapsed(), or use formatted_elapsed() which is suitable for headers (Probably wasteful to return `ms` in every response) --- src/frontend/http.rs | 20 ++++++++++---------- src/frontend/mod.rs | 1 + src/frontend/profile_utils.rs | 34 ++++++++++++++++++++++++++++++++++ 3 files changed, 45 insertions(+), 10 deletions(-) create mode 100644 src/frontend/profile_utils.rs diff --git a/src/frontend/http.rs b/src/frontend/http.rs index 0f56e982..db20f3ce 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -43,7 +43,7 @@ use crate::{ is_read_only, is_statement_read_only, DefaultSeafowlContext, SeafowlContext, }, }; - +use crate::frontend::profile_utils::Timer; use super::http_utils::{handle_rejection, into_response, ApiError}; const QUERY_HEADER: &str = "X-Seafowl-Query"; @@ -156,8 +156,8 @@ pub async fn uncached_read_write_query( query: String, mut context: Arc, ) -> Result { - // Start a timer - let start_time = std::time::Instant::now(); + let mut timer = Timer::new(); + timer.start_timer(); // If a specific DB name was used as a parameter in the route, scope the context to it, // effectively making it the default DB for the duration of the session. @@ -220,10 +220,10 @@ pub async fn uncached_read_write_query( .insert(header::CONTENT_TYPE, content_type_with_schema(schema)); } - let elapsed = start_time.elapsed(); + let elapsed = timer.formatted_elapsed(); response .headers_mut() - .insert(QUERY_TIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); + .insert(QUERY_TIME_HEADER, elapsed.parse().unwrap()); Ok(response) } @@ -295,8 +295,9 @@ pub async fn cached_read_query( if_none_match: Option, mut context: Arc, ) -> Result { - // Start a timer - let start_time = std::time::Instant::now(); + let mut timer = Timer::new(); + timer.start_timer(); + // Ignore dots at the end let query_or_hash = query_or_hash.split('.').next().unwrap(); @@ -358,11 +359,10 @@ pub async fn cached_read_query( let schema = physical.schema().clone(); let mut response = plan_to_response(context, physical).await?; - // Compute runtime - let elapsed = start_time.elapsed(); + let elapsed = timer.formatted_elapsed(); response .headers_mut() - .insert(QUERY_TIME_HEADER, format!("{:?}", elapsed).parse().unwrap()); + .insert(QUERY_TIME_HEADER, elapsed.parse().unwrap()); response .headers_mut() .insert(header::ETAG, etag.parse().unwrap()); diff --git a/src/frontend/mod.rs b/src/frontend/mod.rs index 3897a3ac..ca30177c 100644 --- a/src/frontend/mod.rs +++ b/src/frontend/mod.rs @@ -2,3 +2,4 @@ pub mod http; pub mod http_utils; #[cfg(feature = "frontend-postgres")] pub mod postgres; +pub mod profile_utils; diff --git a/src/frontend/profile_utils.rs b/src/frontend/profile_utils.rs new file mode 100644 index 00000000..c086ff26 --- /dev/null +++ b/src/frontend/profile_utils.rs @@ -0,0 +1,34 @@ +use std::time::{Duration, Instant}; + +// Simple timer intended for profiling +// Lazily inits. Returns `Duration`s or raw string (in ms) +// Use Option as a safeguard because apparently previous Rust versions panicked +// when current time was earlier than self. + +pub struct Timer { + start_time: Option, +} + +impl Timer { + pub fn new() -> Self { + Self { + start_time: None + } + } + + pub fn start_timer(&mut self) { + self.start_time = Some(Instant::now()) + } + + pub fn elapsed(&self) -> Option { + self.start_time.map(|start| start.elapsed()) + } + + pub fn formatted_elapsed(&self) -> String { + self.elapsed().map(|duration| { + let millis = duration.as_millis(); + format!("{}", millis) + }) + .unwrap_or_else(|| String::new()) + } +} From d71d738092e5fa852ed361171acab965bc88bc46 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Mon, 19 Jun 2023 22:15:22 -0400 Subject: [PATCH 06/11] Keep fmt happy - Add a Default attribute - Accept linter changes --- src/frontend/http.rs | 4 ++-- src/frontend/profile_utils.rs | 16 ++++++++-------- 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index db20f3ce..f4df106e 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -34,17 +34,17 @@ use warp::multipart::{FormData, Part}; use warp::reply::{with_header, Response}; use warp::{hyper::header, hyper::StatusCode, Filter, Reply}; +use super::http_utils::{handle_rejection, into_response, ApiError}; use crate::auth::{token_to_principal, AccessPolicy, Action, UserContext}; use crate::catalog::DEFAULT_DB; use crate::config::schema::{AccessSettings, MEBIBYTES}; +use crate::frontend::profile_utils::Timer; use crate::{ config::schema::{str_to_hex_hash, HttpFrontend}, context::{ is_read_only, is_statement_read_only, DefaultSeafowlContext, SeafowlContext, }, }; -use crate::frontend::profile_utils::Timer; -use super::http_utils::{handle_rejection, into_response, ApiError}; const QUERY_HEADER: &str = "X-Seafowl-Query"; const BEARER_PREFIX: &str = "Bearer "; diff --git a/src/frontend/profile_utils.rs b/src/frontend/profile_utils.rs index c086ff26..db0a8fde 100644 --- a/src/frontend/profile_utils.rs +++ b/src/frontend/profile_utils.rs @@ -5,15 +5,14 @@ use std::time::{Duration, Instant}; // Use Option as a safeguard because apparently previous Rust versions panicked // when current time was earlier than self. +#[derive(Default)] pub struct Timer { start_time: Option, } impl Timer { pub fn new() -> Self { - Self { - start_time: None - } + Self { start_time: None } } pub fn start_timer(&mut self) { @@ -25,10 +24,11 @@ impl Timer { } pub fn formatted_elapsed(&self) -> String { - self.elapsed().map(|duration| { - let millis = duration.as_millis(); - format!("{}", millis) - }) - .unwrap_or_else(|| String::new()) + self.elapsed() + .map(|duration| { + let millis = duration.as_millis(); + format!("{}", millis) + }) + .unwrap_or_else(String::new) } } From c836955060655322decfe5b89cc279a2993d8302 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Mon, 19 Jun 2023 22:56:44 -0400 Subject: [PATCH 07/11] Test for presence of QUERY_TIME_HEADER in uncached read response --- src/frontend/http.rs | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index f4df106e..6a99c03b 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -624,7 +624,7 @@ pub mod tests { use crate::testutils::schema_from_header; use crate::{ context::{test_utils::in_memory_context, DefaultSeafowlContext, SeafowlContext}, - frontend::http::{filters, QUERY_HEADER}, + frontend::http::{filters, QUERY_HEADER, QUERY_TIME_HEADER}, }; fn http_config_from_access_policy_and_cache_control( @@ -1589,4 +1589,17 @@ SELECT ) ); } + + #[rstest] + #[tokio::test] + async fn test_get_uncached_read_query_timing_header_present( + #[values(None, Some("test_db"))] new_db: Option<&str>, + ) { + let context = in_memory_context_with_single_table(new_db).await; + let handler = filters(context, http_config_from_access_policy(free_for_all())); + + let resp = query_uncached_endpoint(&handler, SELECT_QUERY, new_db, None).await; + + assert!(resp.headers().contains_key(QUERY_TIME_HEADER)); + } } From 1bb617d860ee6a3f2f46b10d7152cdb0dc600844 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Tue, 20 Jun 2023 20:09:38 -0400 Subject: [PATCH 08/11] Include both GET and POST coverage in test - Also add a test helper to testutils.rs --- src/frontend/http.rs | 22 +++++++++------------- src/testutils.rs | 7 +++++++ 2 files changed, 16 insertions(+), 13 deletions(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index 6a99c03b..0e37d0fc 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -621,7 +621,7 @@ pub mod tests { use crate::catalog::DEFAULT_DB; use crate::config::schema::{str_to_hex_hash, HttpFrontend}; - use crate::testutils::schema_from_header; + use crate::testutils::{assert_header_is_float, schema_from_header}; use crate::{ context::{test_utils::in_memory_context, DefaultSeafowlContext, SeafowlContext}, frontend::http::{filters, QUERY_HEADER, QUERY_TIME_HEADER}, @@ -1534,7 +1534,10 @@ pub mod tests { )] #[case::uncached_post("POST", "/q")] #[tokio::test] - async fn test_http_type_conversion(#[case] method: &str, #[case] path: &str) { + async fn test_http_type_conversion_and_timing_header( + #[case] method: &str, + #[case] path: &str, + ) { let context = Arc::new(in_memory_context().await); let handler = filters( context.clone(), @@ -1588,18 +1591,11 @@ SELECT "# ) ); - } - - #[rstest] - #[tokio::test] - async fn test_get_uncached_read_query_timing_header_present( - #[values(None, Some("test_db"))] new_db: Option<&str>, - ) { - let context = in_memory_context_with_single_table(new_db).await; - let handler = filters(context, http_config_from_access_policy(free_for_all())); - - let resp = query_uncached_endpoint(&handler, SELECT_QUERY, new_db, None).await; + // Assert the "request-to-response" time header is present assert!(resp.headers().contains_key(QUERY_TIME_HEADER)); + // Assert that it's a float + let header_value = resp.headers().get(QUERY_TIME_HEADER).unwrap(); + assert_header_is_float(header_value); } } diff --git a/src/testutils.rs b/src/testutils.rs index 38daa48b..78b7574f 100644 --- a/src/testutils.rs +++ b/src/testutils.rs @@ -1,4 +1,5 @@ use std::cmp::min; +use std::str::FromStr; use std::sync::Arc; use arrow::array::Int32Array; @@ -161,3 +162,9 @@ pub fn schema_from_header(headers: &HeaderMap) -> Schema { schema_from_json(&schema_json).expect("arrow schema reconstructable from JSON") } + +pub fn assert_header_is_float(header: &HeaderValue) -> bool { + let float_str = header.to_str().unwrap(); + let parsed_float = f64::from_str(float_str).unwrap(); + parsed_float.is_finite() +} From 1e48150fabd45d8ba902e8462ff1776b431694ee Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Wed, 21 Jun 2023 12:16:18 -0400 Subject: [PATCH 09/11] Use Rust triple slash comments --- src/frontend/profile_utils.rs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/frontend/profile_utils.rs b/src/frontend/profile_utils.rs index db0a8fde..0d87422a 100644 --- a/src/frontend/profile_utils.rs +++ b/src/frontend/profile_utils.rs @@ -1,9 +1,9 @@ use std::time::{Duration, Instant}; -// Simple timer intended for profiling -// Lazily inits. Returns `Duration`s or raw string (in ms) -// Use Option as a safeguard because apparently previous Rust versions panicked -// when current time was earlier than self. +/// Simple timer intended for profiling +/// Lazily inits. Returns `Duration`s or raw string (in ms) +/// Use Option as a safeguard because apparently previous Rust versions panicked +/// when current time was earlier than self. #[derive(Default)] pub struct Timer { From b0307b8c1978aef0465cfdc8be8c8320a6b01614 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Wed, 21 Jun 2023 14:23:34 -0400 Subject: [PATCH 10/11] Use time directly and drop Option wrapping - Previously we wrapped with Option, per the warnings at https://doc.rust-lang.org/src/std/time.rs.html#86 - After code review perhaps the fact we still call .unwrap() obviates the benefit anyway, thus dropped. --- src/frontend/http.rs | 6 ++---- src/frontend/profile_utils.rs | 20 +++++--------------- 2 files changed, 7 insertions(+), 19 deletions(-) diff --git a/src/frontend/http.rs b/src/frontend/http.rs index 0e37d0fc..4bd052d4 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -156,8 +156,7 @@ pub async fn uncached_read_write_query( query: String, mut context: Arc, ) -> Result { - let mut timer = Timer::new(); - timer.start_timer(); + let timer = Timer::new(); // If a specific DB name was used as a parameter in the route, scope the context to it, // effectively making it the default DB for the duration of the session. @@ -295,8 +294,7 @@ pub async fn cached_read_query( if_none_match: Option, mut context: Arc, ) -> Result { - let mut timer = Timer::new(); - timer.start_timer(); + let timer = Timer::new(); // Ignore dots at the end let query_or_hash = query_or_hash.split('.').next().unwrap(); diff --git a/src/frontend/profile_utils.rs b/src/frontend/profile_utils.rs index 0d87422a..d57bdefe 100644 --- a/src/frontend/profile_utils.rs +++ b/src/frontend/profile_utils.rs @@ -5,30 +5,20 @@ use std::time::{Duration, Instant}; /// Use Option as a safeguard because apparently previous Rust versions panicked /// when current time was earlier than self. -#[derive(Default)] pub struct Timer { - start_time: Option, + start_time: Instant, } impl Timer { pub fn new() -> Self { - Self { start_time: None } + Self { start_time: Instant::now() } } - pub fn start_timer(&mut self) { - self.start_time = Some(Instant::now()) - } - - pub fn elapsed(&self) -> Option { - self.start_time.map(|start| start.elapsed()) + pub fn elapsed(&self) -> Duration { + self.start_time.elapsed() } pub fn formatted_elapsed(&self) -> String { - self.elapsed() - .map(|duration| { - let millis = duration.as_millis(); - format!("{}", millis) - }) - .unwrap_or_else(String::new) + self.elapsed().as_millis().to_string() } } From 1071e8664c705a7dbe8d5a13fe8c646ec2352b24 Mon Sep 17 00:00:00 2001 From: Patrick Skinner Date: Wed, 21 Jun 2023 15:01:38 -0400 Subject: [PATCH 11/11] Use Instant directly --- src/frontend/http.rs | 10 +++++----- src/frontend/mod.rs | 1 - src/frontend/profile_utils.rs | 24 ------------------------ 3 files changed, 5 insertions(+), 30 deletions(-) delete mode 100644 src/frontend/profile_utils.rs diff --git a/src/frontend/http.rs b/src/frontend/http.rs index 4bd052d4..09305aa1 100644 --- a/src/frontend/http.rs +++ b/src/frontend/http.rs @@ -3,6 +3,7 @@ use datafusion::error::DataFusionError; use std::fmt::Debug; use std::io::Write; +use std::time::Instant; use std::{net::SocketAddr, sync::Arc}; use warp::{hyper, Rejection}; @@ -38,7 +39,6 @@ use super::http_utils::{handle_rejection, into_response, ApiError}; use crate::auth::{token_to_principal, AccessPolicy, Action, UserContext}; use crate::catalog::DEFAULT_DB; use crate::config::schema::{AccessSettings, MEBIBYTES}; -use crate::frontend::profile_utils::Timer; use crate::{ config::schema::{str_to_hex_hash, HttpFrontend}, context::{ @@ -156,7 +156,7 @@ pub async fn uncached_read_write_query( query: String, mut context: Arc, ) -> Result { - let timer = Timer::new(); + let timer = Instant::now(); // If a specific DB name was used as a parameter in the route, scope the context to it, // effectively making it the default DB for the duration of the session. @@ -219,7 +219,7 @@ pub async fn uncached_read_write_query( .insert(header::CONTENT_TYPE, content_type_with_schema(schema)); } - let elapsed = timer.formatted_elapsed(); + let elapsed = timer.elapsed().as_millis().to_string(); response .headers_mut() .insert(QUERY_TIME_HEADER, elapsed.parse().unwrap()); @@ -294,7 +294,7 @@ pub async fn cached_read_query( if_none_match: Option, mut context: Arc, ) -> Result { - let timer = Timer::new(); + let timer = Instant::now(); // Ignore dots at the end let query_or_hash = query_or_hash.split('.').next().unwrap(); @@ -357,7 +357,7 @@ pub async fn cached_read_query( let schema = physical.schema().clone(); let mut response = plan_to_response(context, physical).await?; - let elapsed = timer.formatted_elapsed(); + let elapsed = timer.elapsed().as_millis().to_string(); response .headers_mut() .insert(QUERY_TIME_HEADER, elapsed.parse().unwrap()); diff --git a/src/frontend/mod.rs b/src/frontend/mod.rs index ca30177c..3897a3ac 100644 --- a/src/frontend/mod.rs +++ b/src/frontend/mod.rs @@ -2,4 +2,3 @@ pub mod http; pub mod http_utils; #[cfg(feature = "frontend-postgres")] pub mod postgres; -pub mod profile_utils; diff --git a/src/frontend/profile_utils.rs b/src/frontend/profile_utils.rs deleted file mode 100644 index d57bdefe..00000000 --- a/src/frontend/profile_utils.rs +++ /dev/null @@ -1,24 +0,0 @@ -use std::time::{Duration, Instant}; - -/// Simple timer intended for profiling -/// Lazily inits. Returns `Duration`s or raw string (in ms) -/// Use Option as a safeguard because apparently previous Rust versions panicked -/// when current time was earlier than self. - -pub struct Timer { - start_time: Instant, -} - -impl Timer { - pub fn new() -> Self { - Self { start_time: Instant::now() } - } - - pub fn elapsed(&self) -> Duration { - self.start_time.elapsed() - } - - pub fn formatted_elapsed(&self) -> String { - self.elapsed().as_millis().to_string() - } -}