diff options
| -rw-r--r-- | incria/Cargo.lock | 33 | ||||
| -rw-r--r-- | incria/Cargo.toml | 1 | ||||
| -rw-r--r-- | incria/src/deps.rs | 6 | ||||
| -rw-r--r-- | incria/src/lazy_mapping.rs | 73 |
4 files changed, 96 insertions, 17 deletions
diff --git a/incria/Cargo.lock b/incria/Cargo.lock index 9a19675..3bd4965 100644 --- a/incria/Cargo.lock +++ b/incria/Cargo.lock @@ -298,6 +298,7 @@ dependencies = [ "blink-alloc", "criterion", "tokio", + "tracing", ] [[package]] @@ -645,6 +646,38 @@ dependencies = [ ] [[package]] +name = "tracing" +version = "0.1.37" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8ce8c33a8d48bd45d624a6e523445fd21ec13d3653cd51f681abf67418f54eb8" +dependencies = [ + "cfg-if", + "pin-project-lite", + "tracing-attributes", + "tracing-core", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0f57e3ca2a01450b1a921183a9c9cbfda207fd822cef4ccb00a65402cbba7a74" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "tracing-core" +version = "0.1.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0955b8137a1df6f1a2e9a37d8a6656291ff0297c1a97c24e0d8425fe2312f79a" +dependencies = [ + "once_cell", +] + +[[package]] name = "unicode-ident" version = "1.0.8" source = "registry+https://github.com/rust-lang/crates.io-index" diff --git a/incria/Cargo.toml b/incria/Cargo.toml index 55e6cdf..db0df01 100644 --- a/incria/Cargo.toml +++ b/incria/Cargo.toml @@ -6,6 +6,7 @@ edition = "2021" [dependencies] blink-alloc = { version = "0.3.0", features = ["sync"] } tokio = { version = "1.28.1", features = ["sync", "rt"] } +tracing = { version = "0.1" } [dev-dependencies] tokio = { version = "1.28.1", features = ["macros", "sync", "rt-multi-thread"] } diff --git a/incria/src/deps.rs b/incria/src/deps.rs index 924eb3f..f2fd8f8 100644 --- a/incria/src/deps.rs +++ b/incria/src/deps.rs @@ -18,6 +18,8 @@ use std::{ thread, }; +use tracing::instrument; + /// Identifier of a node, unique across a program run. pub type NodeId = u64; @@ -40,6 +42,7 @@ struct DepTracker { impl DepTracker { /// See [`self::add_dep`] + #[instrument(level = "trace", skip(self))] fn add_dep(&self, dep: NodeId) { self.deps .lock() @@ -65,6 +68,7 @@ impl DepTracker { } /// See [`self::mark_dirty`] + #[instrument(level = "trace", skip(self))] fn mark_dirty(&self, node: NodeId) { let mut lock = self.deps.lock().unwrap(); let mut frontier = VecDeque::new(); @@ -87,6 +91,7 @@ impl DepTracker { } /// See [`self::is_dirty`] + #[instrument(level = "trace", skip(self))] fn is_dirty(&self, node: NodeId) -> bool { self.deps .lock() @@ -97,6 +102,7 @@ impl DepTracker { } /// See [`self::clear`] + #[instrument(level = "trace", skip(self))] fn clear(&self, node: NodeId) { let mut lock = self.deps.lock().unwrap(); let node = match lock.get_mut(&node) { diff --git a/incria/src/lazy_mapping.rs b/incria/src/lazy_mapping.rs index 27bd76e..f206bdd 100644 --- a/incria/src/lazy_mapping.rs +++ b/incria/src/lazy_mapping.rs @@ -1,9 +1,11 @@ use std::{ - collections::HashMap, fmt::Debug, future::Future, hash::Hash, mem::transmute, sync::Arc, + any::type_name, collections::HashMap, fmt::Debug, future::Future, hash::Hash, mem::transmute, + sync::Arc, }; use blink_alloc::{Blink, SyncBlinkAlloc}; use tokio::sync::{Mutex, Notify, RwLock, RwLockReadGuard}; +use tracing::{debug_span, instrument, trace_span, Instrument}; use crate::{ deps::{self, NodeId}, @@ -56,7 +58,7 @@ impl<K: Clone + Eq + Hash + Send + Sync, V: Send + Sync, B: LazyMappingBackend<K impl<K, V, B> Mapper for LazyMapper<K, V, B> where - K: Clone + Eq + Hash + Send + Sync + Debug, + K: Clone + Eq + Hash + Send + Sync, V: Send + Sync + 'static, B: LazyMappingBackend<K, V>, { @@ -64,35 +66,64 @@ where type Value = V; type Wrapper<'a> = &'a V where V: 'a; + #[instrument(level = "debug", skip_all, fields(key_type = type_name::<K>(), value_type = type_name::<V>()))] async fn get<'a>(&'a self, key: &Self::Key) -> Self::Wrapper<'a> { // Attempt to reuse or evict the existing value let mut reuse_dep_id = None; { - let finished = self.calculated.read().await; - if let Some((val, node)) = finished.get(key) { - let dirty = deps::is_dirty(*node) || self.backend.is_dirty(key).await; + let finished = self + .calculated + .read() + .instrument(trace_span!("calculated.read")) + .await; + if let Some((val, node)) = finished.get(key).copied() { + drop(finished); + + let dirty = deps::is_dirty(node) + || self + .backend + .is_dirty(key) + .instrument(trace_span!("backend.is_dirty")) + .await; if !dirty { - deps::add_dep(*node); + deps::add_dep(node); return val; } else { - reuse_dep_id = Some(*node); - drop(finished); + reuse_dep_id = Some(node); // Dirty, so we'll recompute below but we should remove it now - if self.calculated.write().await.remove(key).is_none() { + let removed = async { self.calculated.write().await.remove(key).is_none() } + .instrument(trace_span!("remove dirty value")) + .await; + if removed { // Someone else already noticed it was dirty and removed it before us, so we need to deal with that todo!("dirty value removed between us noticing and us doing something") } } } - } + }; + + let barrier = self + .waiting + .lock() + .instrument(trace_span!("waiting.lock")) + .await + .get(key) + .cloned(); - let barrier = self.waiting.lock().await.get(key).cloned(); if let Some(barrier) = barrier { // Waiting for completion - barrier.notified().await; - - let (value, node_id) = - *RwLockReadGuard::map(self.calculated.read().await, |hm| hm.get(key).unwrap()); + barrier + .notified() + .instrument(trace_span!("completion_wait")) + .await; + + let (value, node_id) = *RwLockReadGuard::map( + self.calculated + .read() + .instrument(trace_span!("calculated.read")) + .await, + |hm| hm.get(key).unwrap(), + ); deps::add_dep(node_id); @@ -102,6 +133,7 @@ where let notify = Arc::new(Notify::new()); self.waiting .lock() + .instrument(trace_span!("waiting.insert")) .await .insert(key.clone(), notify.clone()); @@ -112,15 +144,22 @@ where deps::next_node_id() }; - let val = deps::with_node_id(dep, self.backend.compute(key.clone())).await; + let val = deps::with_node_id(dep, self.backend.compute(key.clone())) + .instrument(debug_span!("backend.compute")) + .await; let val_ref: &'static V = unsafe { transmute(Blink::new_in(&self.values).put(val)) }; deps::add_dep(dep); self.calculated .write() + .instrument(trace_span!("calculated.insert")) .await .insert(key.clone(), (val_ref, dep)); - self.waiting.lock().await.remove(key); + self.waiting + .lock() + .instrument(trace_span!("waiting.remove")) + .await + .remove(key); notify.notify_waiters(); |