From 4ecc76c6c933b801750e6a04677fd0801d1080e3 Mon Sep 17 00:00:00 2001 From: Nico Burniske Date: Sun, 20 Aug 2023 15:37:51 -0400 Subject: [PATCH] first attempt at tracing --- Cargo.lock | 1 + Cargo.toml | 3 +- example/start-axum/Cargo.toml | 11 +++- example/start-axum/src/app.rs | 22 ++++---- example/start-axum/src/lib.rs | 19 +++++-- example/start-axum/src/main.rs | 2 +- example/start-axum/src/todo.rs | 2 +- src/query_client.rs | 9 ++-- src/query_executor.rs | 97 ++++++++++++++++++++++++---------- src/use_query.rs | 8 ++- 10 files changed, 119 insertions(+), 55 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 900137d..207a3ca 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -834,6 +834,7 @@ dependencies = [ "js-sys", "leptos", "tokio", + "tracing", ] [[package]] diff --git a/Cargo.toml b/Cargo.toml index c31952d..dd4e6b6 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -16,10 +16,11 @@ cfg-if = "1" js-sys = {version = "0.3.64", optional = true} gloo-timers = { version = "0.2.6", optional = true, features = ["futures"] } tokio = { version = "1.29.1", optional = true, features = ["time"]} +tracing = "0.1.37" [features] hydrate = ["dep:js-sys", "dep:gloo-timers"] ssr = ["dep:tokio"] [package.metadata.docs.rs] -all-features = true \ No newline at end of file +all-features = true diff --git a/example/start-axum/Cargo.toml b/example/start-axum/Cargo.toml index b649561..4b95b3c 100644 --- a/example/start-axum/Cargo.toml +++ b/example/start-axum/Cargo.toml @@ -26,9 +26,18 @@ tracing = { version = "0.1.37", optional = true } http = "0.2.8" serde = "1.0.171" leptos_query = { path = "../../"} +tracing-subscriber = { version = "0.3.17", optional = true } +tracing-subscriber-wasm = { version = "0.1.0", optional = true } [features] -hydrate = ["leptos/hydrate", "leptos_meta/hydrate", "leptos_router/hydrate", "leptos_query/hydrate"] +hydrate = [ + "leptos/hydrate", + "leptos_meta/hydrate", + "leptos_router/hydrate", + "leptos_query/hydrate", + "tracing-subscriber", + "tracing-subscriber-wasm" +] ssr = [ "dep:axum", "dep:tokio", diff --git a/example/start-axum/src/app.rs b/example/start-axum/src/app.rs index 616da2c..09bdd42 100644 --- a/example/start-axum/src/app.rs +++ b/example/start-axum/src/app.rs @@ -194,7 +194,8 @@ fn Post(cx: Scope, #[prop(into)] post_id: MaybeSignal) -> impl IntoView { refetch, } = use_post_query(cx, post_id); - create_effect(cx, move |_| log!("State: {:#?}", state.get())); + // Log the state of the query. + // create_effect(cx, move |_| log!("State: {:#?}", state.get())); view! { cx,
@@ -222,16 +223,15 @@ fn Post(cx: Scope, #[prop(into)] post_id: MaybeSignal) -> impl IntoView { view! { cx,

"Loading..."

} }>

- { - data - .get() - .map(|post| { - match post { - Some(post) => post, - None => "Not Found".into(), - } - }) - } + {move || { + data.get() + .map(|post| { + match post { + Some(post) => post, + None => "Not Found".into(), + } + }) + }}

diff --git a/example/start-axum/src/lib.rs b/example/start-axum/src/lib.rs index 0bb979a..c552268 100644 --- a/example/start-axum/src/lib.rs +++ b/example/start-axum/src/lib.rs @@ -11,12 +11,23 @@ cfg_if! { if #[cfg(feature = "hydrate")] { #[wasm_bindgen] pub fn hydrate() { - // initializes logging using the `log` crate - _ = console_log::init_with_level(log::Level::Debug); - console_error_panic_hook::set_once(); - + setup_logging(); leptos::mount_to_body(move |cx| { view! { cx, } }); } + + /// Setup browser console logging using [tracing_subscriber_wasm] + fn setup_logging() { + tracing_subscriber::fmt() + .with_writer( + // To avoide trace events in the browser from showing their + // JS backtrace, which is very annoying, in my opinion + tracing_subscriber_wasm::MakeConsoleWriter::default().map_trace_level_to(tracing::Level::DEBUG), + ) + // For some reason, if we don't do this in the browser, we get + // a runtime error. + .without_time() + .init(); + } }} diff --git a/example/start-axum/src/main.rs b/example/start-axum/src/main.rs index bd8f071..1930efc 100644 --- a/example/start-axum/src/main.rs +++ b/example/start-axum/src/main.rs @@ -7,7 +7,7 @@ async fn main() { use start_axum::app::*; use start_axum::fileserv::file_and_error_handler; - simple_logger::init_with_level(log::Level::Info).expect("couldn't initialize logging"); + simple_logger::init_with_level(log::Level::Debug).expect("couldn't initialize logging"); // Setting get_configuration(None) means we'll be using cargo-leptos's env values // For deployment these variables are: diff --git a/example/start-axum/src/todo.rs b/example/start-axum/src/todo.rs index de1ff4d..0cb8bc0 100644 --- a/example/start-axum/src/todo.rs +++ b/example/start-axum/src/todo.rs @@ -3,7 +3,7 @@ use leptos_query::*; use leptos_router::ActionForm; use serde::*; -#[derive(Serialize, Deserialize, Clone)] +#[derive(Debug, Serialize, Deserialize, Clone)] pub struct Todo { id: u32, content: String, diff --git a/src/query_client.rs b/src/query_client.rs index 62336c5..9d48030 100644 --- a/src/query_client.rs +++ b/src/query_client.rs @@ -9,6 +9,7 @@ use std::{ cell::RefCell, collections::hash_map::Entry, collections::HashMap, + fmt::Debug, future::Future, hash::Hash, rc::Rc, @@ -115,8 +116,8 @@ impl QueryClient { isomorphic: bool, ) -> QueryResult where - K: Hash + Eq + Clone + 'static, - V: Clone + 'static, + K: Debug + Hash + Eq + Clone + 'static, + V: Debug + Clone + 'static, Fu: Future + 'static, { let state = self.get_query_signal(cx, key); @@ -159,8 +160,8 @@ impl QueryClient { query: impl Fn(K) -> Fu + 'static, isomorphic: bool, ) where - K: Hash + Eq + Clone + 'static, - V: Clone + 'static, + K: Debug + Hash + Eq + Clone + 'static, + V: Debug + Clone + 'static, Fu: Future + 'static, { let state = self.get_query_signal(cx, key); diff --git a/src/query_executor.rs b/src/query_executor.rs index f5716d8..92af480 100644 --- a/src/query_executor.rs +++ b/src/query_executor.rs @@ -1,7 +1,9 @@ use leptos::*; +use tracing::{field::debug, Instrument, debug_span}; use std::{ cell::{Cell, RefCell}, collections::HashMap, + fmt::Debug, future::Future, hash::Hash, rc::Rc, @@ -29,43 +31,84 @@ pub(crate) fn create_executor( fetcher: impl Fn(K) -> Fu + 'static, ) -> impl Fn() + Clone where - K: Clone + Hash + Eq + 'static, - V: Clone + 'static, + K: Debug + Clone + Hash + Eq + 'static, + V: Debug + Clone + 'static, Fu: Future + 'static, { let fetcher = Rc::new(fetcher); move || { let fetcher = fetcher.clone(); + SUPPRESS_QUERY_LOAD.with(|supressed| { if !supressed.get() { - spawn_local(async move { - let query = query.get_untracked(); - let data_state = query.state.get_untracked(); - match data_state { - QueryState::Fetching(_) | QueryState::Loading => (), - // First load. - QueryState::Created => { - query.state.set(QueryState::Loading); - let data = fetcher(query.key.clone()).await; - let updated_at = crate::Instant::now(); - let data = QueryData { data, updated_at }; - query.state.set(QueryState::Loaded(data)); - } - // Subsequent loads. - QueryState::Loaded(data) | QueryState::Invalid(data) => { - query.state.set(QueryState::Fetching(data)); - let data = fetcher(query.key.clone()).await; - let updated_at = crate::Instant::now(); - let data = QueryData { data, updated_at }; - query.state.set(QueryState::Loaded(data)); - } - } - }) + let query = query.get_untracked(); + spawn_local(query_executor(query, fetcher)) } }) } } +#[tracing::instrument( + level = "info", + skip(query, fetcher), + fields( + key_type = std::any::type_name::(), + value_type = std::any::type_name::(), + key = ?query.key, + ) +)] +async fn query_executor( + query: Query, + fetcher: Rc, +) where + K: Debug + Clone + Hash + Eq + 'static, + V: Debug + Clone + 'static, + F: Fn(K) -> Fu + 'static, + Fu: Future + 'static, +{ + let state = query.state.get_untracked(); + + let span = tracing::Span::current(); + + match state { + QueryState::Loading => { + tracing::info!("Query load in progress"); + } + QueryState::Fetching(_) => { + tracing::info!("Query fetch in progress"); + } + // First load. + QueryState::Created => { + tracing::info!("Query loading"); + + query.state.set(QueryState::Loading); + let data = fetcher(query.key.clone()).instrument(span).await; + + let updated_at = crate::Instant::now(); + let data = QueryData { data, updated_at }; + let state = QueryState::Loaded(data); + + tracing::info!("Query load complete"); + query.state.set(state); + } + // Subsequent loads. + QueryState::Loaded(data) | QueryState::Invalid(data) => { + let state = QueryState::Fetching(data); + tracing::info!("Query fetching"); + + query.state.set(state); + let data = fetcher(query.key.clone()).instrument(span).await; + + let updated_at = crate::Instant::now(); + let data = QueryData { data, updated_at }; + let state = QueryState::Loaded(data); + + tracing::info!("Query fetch complete"); + query.state.set(state); + } + } +} + // Start synchronization effects. pub(crate) fn synchronize_state( cx: Scope, @@ -253,8 +296,8 @@ where let dispose = { let query = query.clone(); move || { - let removed = - use_query_client(root_scope).evict_and_notify::(&query.key); + let removed = use_query_client(root_scope) + .evict_and_notify::(&query.key); if let Some(query) = removed { if query.observers.get() == 0 { query.dispose(); diff --git a/src/use_query.rs b/src/use_query.rs index ac4aeb3..52ebcca 100644 --- a/src/use_query.rs +++ b/src/use_query.rs @@ -5,9 +5,7 @@ use crate::{ ResourceOption, }; use leptos::*; -use std::future::Future; -use std::hash::Hash; -use std::time::Duration; +use std::{fmt::Debug, future::Future, hash::Hash, time::Duration}; /// Creates a query. Useful for data fetching, caching, and synchronization with server state. /// @@ -63,8 +61,8 @@ pub fn use_query( options: QueryOptions, ) -> QueryResult where - K: Hash + Eq + Clone + 'static, - V: Clone + Serializable + 'static, + K: Debug + Hash + Eq + Clone + 'static, + V: Debug + Clone + Serializable + 'static, Fu: Future + 'static, { // Find relevant state.