Skip to content

Commit

Permalink
Fix Instant::now usage
Browse files Browse the repository at this point in the history
Replace `Instant::now` with a custom library, that will use appriate
time/date functions for the platforms. For native, it is `std::time`,
for WASM in should probably be `performance::now()` but it is a no-op
stub for now.
  • Loading branch information
SevInf committed Nov 22, 2023
1 parent a004fe6 commit 49271f6
Show file tree
Hide file tree
Showing 10 changed files with 104 additions and 41 deletions.
17 changes: 13 additions & 4 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

11 changes: 11 additions & 0 deletions libs/elapsed/Cargo.toml
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
[package]
name = "elapsed"
version = "0.1.0"
edition = "2021"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]

[target.'cfg(target_arch = "wasm32")'.dependencies]
js-sys.workspace = true
9 changes: 9 additions & 0 deletions libs/elapsed/src/lib.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
#[cfg(target_arch = "wasm32")]
mod wasm;
#[cfg(target_arch = "wasm32")]
pub use crate::wasm::ElapsedTimeCounter;

#[cfg(not(target_arch = "wasm32"))]
mod native;
#[cfg(not(target_arch = "wasm32"))]
pub use crate::native::ElapsedTimeCounter;
17 changes: 17 additions & 0 deletions libs/elapsed/src/native.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
use std::time::{Duration, Instant};

pub struct ElapsedTimeCounter {
instant: Instant,
}

impl ElapsedTimeCounter {
pub fn start() -> Self {
let instant = Instant::now();

Self { instant }
}

pub fn elapsed_time(&self) -> Duration {
self.instant.elapsed()
}
}
15 changes: 15 additions & 0 deletions libs/elapsed/src/wasm.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
use std::time::Duration;

/// TODO: this is a stub that always returns 0 as elapsed time
/// In should use performance::now() instead
pub struct ElapsedTimeCounter {}

impl ElapsedTimeCounter {
pub fn start() -> Self {
Self {}
}

pub fn elapsed_time(&self) -> Duration {
Duration::from_millis(0u64)
}
}
16 changes: 3 additions & 13 deletions quaint/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -29,12 +29,7 @@ docs = []
# way to access database-specific methods when you need extra control.
expose-drivers = []

native = [
"postgresql-native",
"mysql-native",
"mssql-native",
"sqlite-native",
]
native = ["postgresql-native", "mysql-native", "mssql-native", "sqlite-native"]

all = ["native", "pooled"]

Expand All @@ -57,13 +52,7 @@ postgresql-native = [
]
postgresql = []

mssql-native = [
"mssql",
"tiberius",
"tokio-util",
"tokio/time",
"tokio/net",
]
mssql-native = ["mssql", "tiberius", "tokio-util", "tokio/time", "tokio/net"]
mssql = []

mysql-native = ["mysql", "mysql_async", "tokio/time", "lru-cache"]
Expand Down Expand Up @@ -100,6 +89,7 @@ mobc = { version = "0.8", optional = true }
serde = { version = "1.0", optional = true }
sqlformat = { version = "0.2.0", optional = true }
uuid = { version = "1", features = ["v4"] }
elapsed = { path = "../libs/elapsed" }

[dev-dependencies]
once_cell = "1.3"
Expand Down
25 changes: 13 additions & 12 deletions quaint/src/connector/metrics.rs
Original file line number Diff line number Diff line change
@@ -1,7 +1,8 @@
use tracing::{info_span, Instrument};

use crate::ast::{Params, Value};
use std::{future::Future, time::Instant};
use elapsed::ElapsedTimeCounter;
use std::future::Future;

pub async fn query<'a, F, T, U>(tag: &'static str, query: &'a str, params: &'a [Value<'_>], f: F) -> crate::Result<T>
where
Expand All @@ -17,7 +18,7 @@ where
F: FnOnce() -> U + 'a,
U: Future<Output = crate::Result<T>>,
{
let start = Instant::now();
let start = ElapsedTimeCounter::start();
let res = f().await;

let result = match res {
Expand All @@ -34,19 +35,19 @@ where
sqlformat::FormatOptions::default(),
);

trace_query(&query_fmt, params, result, start);
trace_query(&query_fmt, params, result, &start);
} else {
trace_query(query, params, result, start);
trace_query(query, params, result, &start);
};
}

#[cfg(not(feature = "fmt-sql"))]
{
trace_query(query, params, result, start);
trace_query(query, params, result, &start);
}

histogram!(format!("{tag}.query.time"), start.elapsed());
histogram!("prisma_datasource_queries_duration_histogram_ms", start.elapsed());
histogram!(format!("{tag}.query.time"), start.elapsed_time());
histogram!("prisma_datasource_queries_duration_histogram_ms", start.elapsed_time());
increment_counter!("prisma_datasource_queries_total");

res
Expand All @@ -57,7 +58,7 @@ pub(crate) async fn check_out<F, T>(f: F) -> std::result::Result<T, mobc::Error<
where
F: Future<Output = std::result::Result<T, mobc::Error<crate::error::Error>>>,
{
let start = Instant::now();
let start = ElapsedTimeCounter::start();
let res = f.await;

let result = match res {
Expand All @@ -67,24 +68,24 @@ where

tracing::trace!(
message = "Fetched a connection from the pool",
duration_ms = start.elapsed().as_millis() as u64,
duration_ms = start.elapsed_time().as_millis() as u64,
item_type = "query",
is_query = true,
result,
);

histogram!("pool.check_out", start.elapsed());
histogram!("pool.check_out", start.elapsed_time());

res
}

fn trace_query<'a>(query: &'a str, params: &'a [Value<'_>], result: &str, start: Instant) {
fn trace_query<'a>(query: &'a str, params: &'a [Value<'_>], result: &str, start: &ElapsedTimeCounter) {
tracing::debug!(
query = %query,
params = %Params(params),
result,
item_type = "query",
is_query = true,
duration_ms = start.elapsed().as_millis() as u64,
duration_ms = start.elapsed_time().as_millis() as u64,
);
}
3 changes: 2 additions & 1 deletion query-engine/core/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ metrics = ["query-engine-metrics"]
async-trait = "0.1"
bigdecimal = "0.3"
chrono = "0.4"
connection-string.workspace = true
connection-string.workspace = true
connector = { path = "../connectors/query-connector", package = "query-connector" }
crossbeam-channel = "0.5.6"
psl.workspace = true
Expand All @@ -34,6 +34,7 @@ user-facing-errors = { path = "../../libs/user-facing-errors" }
uuid = "1"
cuid = { git = "https://github.com/prisma/cuid-rust", branch = "wasm32-support" }
schema = { path = "../schema" }
elapsed = { path = "../../libs/elapsed" }
lru = "0.7.7"
enumflags2 = "0.7"

Expand Down
30 changes: 20 additions & 10 deletions query-engine/core/src/executor/execute_operation.rs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ use crate::{
QueryGraphBuilder, QueryInterpreter, ResponseData,
};
use connector::{Connection, ConnectionLike, Connector};
use elapsed::ElapsedTimeCounter;
use futures::future;

#[cfg(feature = "metrics")]
Expand All @@ -14,7 +15,7 @@ use query_engine_metrics::{
};

use schema::{QuerySchema, QuerySchemaRef};
use std::time::{Duration, Instant};
use std::time::Duration;
use tracing::Instrument;
use tracing_futures::WithSubscriber;

Expand All @@ -24,13 +25,16 @@ pub async fn execute_single_operation(
operation: &Operation,
trace_id: Option<String>,
) -> crate::Result<ResponseData> {
let operation_timer = Instant::now();
let operation_timer = ElapsedTimeCounter::start();

let (graph, serializer) = build_graph(&query_schema, operation.clone())?;
let result = execute_on(conn, graph, serializer, query_schema.as_ref(), trace_id).await;

#[cfg(feature = "metrics")]
histogram!(PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS, operation_timer.elapsed());
histogram!(
PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS,
operation_timer.elapsed_time()
);

result
}
Expand All @@ -49,11 +53,14 @@ pub async fn execute_many_operations(
let mut results = Vec::with_capacity(queries.len());

for (i, (graph, serializer)) in queries.into_iter().enumerate() {
let operation_timer = Instant::now();
let operation_timer = ElapsedTimeCounter::start();
let result = execute_on(conn, graph, serializer, query_schema.as_ref(), trace_id.clone()).await;

#[cfg(feature = "metrics")]
histogram!(PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS, operation_timer.elapsed());
histogram!(
PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS,
operation_timer.elapsed_time()
);

match result {
Ok(result) => results.push(Ok(result)),
Expand Down Expand Up @@ -150,14 +157,14 @@ async fn execute_self_contained(
retry_on_transient_error: bool,
trace_id: Option<String>,
) -> crate::Result<ResponseData> {
let operation_timer = Instant::now();
let operation_timer = ElapsedTimeCounter::start();
let result = if retry_on_transient_error {
execute_self_contained_with_retry(
&mut conn,
query_schema,
operation,
force_transactions,
Instant::now(),
ElapsedTimeCounter::start(),
trace_id,
)
.await
Expand All @@ -168,7 +175,10 @@ async fn execute_self_contained(
};

#[cfg(feature = "metrics")]
histogram!(PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS, operation_timer.elapsed());
histogram!(
PRISMA_CLIENT_QUERIES_DURATION_HISTOGRAM_MS,
operation_timer.elapsed_time()
);

result
}
Expand Down Expand Up @@ -200,7 +210,7 @@ async fn execute_self_contained_with_retry(
query_schema: QuerySchemaRef,
operation: Operation,
force_transactions: bool,
retry_timeout: Instant,
retry_timeout: ElapsedTimeCounter,
trace_id: Option<String>,
) -> crate::Result<ResponseData> {
let (graph, serializer) = build_graph(&query_schema, operation.clone())?;
Expand All @@ -216,7 +226,7 @@ async fn execute_self_contained_with_retry(
let (graph, serializer) = build_graph(&query_schema, operation.clone())?;
let res = execute_in_tx(conn, graph, serializer, query_schema.as_ref(), trace_id.clone()).await;

if is_transient_error(&res) && retry_timeout.elapsed() < MAX_TX_TIMEOUT_RETRY_LIMIT {
if is_transient_error(&res) && retry_timeout.elapsed_time() < MAX_TX_TIMEOUT_RETRY_LIMIT {
tokio::time::sleep(TX_RETRY_BACKOFF).await;
continue;
} else {
Expand Down
2 changes: 1 addition & 1 deletion query-engine/query-engine-wasm/build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ OUT_NPM_NAME="@prisma/query-engine-wasm"
# This little `sed -i` trick below is a hack to publish "@prisma/query-engine-wasm"
# with the same binding filenames currently expected by the Prisma Client.
sed -i '' 's/name = "query_engine_wasm"/name = "query_engine"/g' Cargo.toml
wasm-pack build --release --target $OUT_TARGET
wasm-pack build --dev --target $OUT_TARGET
sed -i '' 's/name = "query_engine"/name = "query_engine_wasm"/g' Cargo.toml

sleep 1
Expand Down

0 comments on commit 49271f6

Please sign in to comment.