diff --git a/Cargo.toml b/Cargo.toml index a1d116a7..dbee4da3 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -13,6 +13,8 @@ derive-new = "0.5.5" rustc-hash = "1.0" parking_lot = "0.6.4" indexmap = "1.0.1" +log = "0.4.5" [dev-dependencies] -text-diff = "0.4.0" \ No newline at end of file +difference = "2.0" +env_logger = "0.5.13" \ No newline at end of file diff --git a/src/lib.rs b/src/lib.rs index 6f8ea66c..e42e838a 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -76,7 +76,7 @@ where &self, query: &'q QC, key: &Q::Key, - descriptor: impl FnOnce() -> QC::QueryDescriptor, + descriptor: &QC::QueryDescriptor, ) -> Result; /// True if the query **may** have changed since the given @@ -125,12 +125,13 @@ where Q: Query, { pub fn of(&self, key: Q::Key) -> Q::Value { + let descriptor = self.descriptor(&key); self.storage - .try_fetch(self.query, &key, || self.descriptor(&key)) + .try_fetch(self.query, &key, &descriptor) .unwrap_or_else(|CycleDetected| { self.query .salsa_runtime() - .report_unexpected_cycle(self.descriptor(&key)) + .report_unexpected_cycle(descriptor) }) } diff --git a/src/memoized.rs b/src/memoized.rs index 1013f4a7..52b8db4b 100644 --- a/src/memoized.rs +++ b/src/memoized.rs @@ -6,6 +6,7 @@ use crate::QueryContext; use crate::QueryDescriptor; use crate::QueryStorageOps; use crate::QueryTable; +use log::debug; use parking_lot::{RwLock, RwLockUpgradableReadGuard}; use rustc_hash::FxHashMap; use std::any::Any; @@ -28,7 +29,6 @@ where } /// Defines the "current state" of query's memoized results. -#[derive(Debug)] enum QueryState where Q: Query, @@ -42,7 +42,6 @@ where Memoized(Memo), } -#[derive(Debug)] struct Memo where Q: Query, @@ -76,7 +75,6 @@ where } } -#[derive(Debug)] struct StampedValue { value: V, changed_at: Revision, @@ -103,17 +101,38 @@ where &self, query: &'q QC, key: &Q::Key, - descriptor: impl FnOnce() -> QC::QueryDescriptor, + descriptor: &QC::QueryDescriptor, ) -> Result, CycleDetected> { let revision_now = query.salsa_runtime().current_revision(); + debug!( + "{:?}({:?}): invoked at {:?}", + Q::default(), + key, + revision_now, + ); + let mut old_value = { let map_read = self.map.upgradable_read(); if let Some(value) = map_read.get(key) { match value { QueryState::InProgress => return Err(CycleDetected), QueryState::Memoized(m) => { + debug!( + "{:?}({:?}): found memoized value verified_at={:?}", + Q::default(), + key, + m.verified_at, + ); + if m.verified_at == revision_now { + debug!( + "{:?}({:?}): returning memoized value (changed_at={:?})", + Q::default(), + key, + m.changed_at, + ); + return Ok(m.stamped_value()); } } @@ -134,6 +153,8 @@ where .iter() .all(|old_input| !old_input.maybe_changed_since(query, old_memo.verified_at)) { + debug!("{:?}({:?}): inputs still valid", Q::default(), key); + // If none of out inputs have changed since the last time we refreshed // our value, then our value must still be good. We'll just patch // the verified-at date and re-use it. @@ -155,7 +176,6 @@ where // Query was not previously executed or value is potentially // stale. Let's execute! - let descriptor = descriptor(); let (value, inputs) = query .salsa_runtime() .execute_query_implementation::(query, descriptor, key); @@ -214,9 +234,16 @@ where &self, query: &'q QC, key: &Q::Key, - descriptor: impl FnOnce() -> QC::QueryDescriptor, + descriptor: &QC::QueryDescriptor, ) -> Result { - Ok(self.read(query, key, descriptor)?.value) + let StampedValue { + value, + changed_at: _, + } = self.read(query, key, &descriptor)?; + + query.salsa_runtime().report_query_read(descriptor); + + Ok(value) } fn maybe_changed_since( @@ -226,10 +253,19 @@ where key: &Q::Key, descriptor: &QC::QueryDescriptor, ) -> bool { + let revision_now = query.salsa_runtime().current_revision(); + + debug!( + "{:?}({:?})::maybe_changed_since(revision={:?}, revision_now={:?})", + Q::default(), + key, + revision, + revision_now, + ); + // Check for the case where we have no cache entry, or our cache // entry is up to date (common case): { - let revision_now = query.salsa_runtime().current_revision(); let map_read = self.map.read(); match map_read.get(key) { None | Some(QueryState::InProgress) => return true, @@ -242,7 +278,7 @@ where } // Otherwise fall back to the full read to compute the result. - match self.read(query, key, || descriptor.clone()) { + match self.read(query, key, descriptor) { Ok(v) => v.changed_at > revision, Err(CycleDetected) => true, } diff --git a/src/runtime.rs b/src/runtime.rs index 53cc35e0..abdaf65c 100644 --- a/src/runtime.rs +++ b/src/runtime.rs @@ -1,5 +1,6 @@ use crate::Query; use crate::QueryContext; +use log::debug; use rustc_hash::FxHasher; use std::cell::RefCell; use std::fmt::Write; @@ -77,24 +78,32 @@ where /// Increments the current revision counter and returns the new value. crate fn increment_revision(&self) -> Revision { - Revision { + let result = Revision { generation: 1 + self.shared_state.revision.fetch_add(1, Ordering::SeqCst), - } + }; + + debug!("increment_revision: incremented to {:?}", result); + + result } crate fn execute_query_implementation( &self, query: &QC, - descriptor: QC::QueryDescriptor, + descriptor: &QC::QueryDescriptor, key: &Q::Key, ) -> (Q::Value, QueryDescriptorSet) where Q: Query, { + debug!("{:?}({:?}): executing query", Q::default(), key); + // Push the active query onto the stack. let push_len = { let mut local_state = self.local_state.borrow_mut(); - local_state.query_stack.push(ActiveQuery::new(descriptor)); + local_state + .query_stack + .push(ActiveQuery::new(descriptor.clone())); local_state.query_stack.len() }; @@ -122,13 +131,10 @@ where /// - `descriptor`: the query whose result was read /// - `changed_revision`: the last revision in which the result of that /// query had changed - crate fn report_query_read(&self, descriptor: QC::QueryDescriptor, changed_revision: Revision) { - self.local_state - .borrow_mut() - .query_stack - .last_mut() - .unwrap() - .add_read(descriptor, changed_revision); + crate fn report_query_read(&self, descriptor: &QC::QueryDescriptor) { + if let Some(top_query) = self.local_state.borrow_mut().query_stack.last_mut() { + top_query.add_read(descriptor); + } } /// Obviously, this should be user configurable at some point. @@ -178,12 +184,12 @@ impl ActiveQuery { } } - fn add_read(&mut self, subquery: QC::QueryDescriptor, _changed_revision: Revision) { - self.subqueries.insert(subquery); + fn add_read(&mut self, subquery: &QC::QueryDescriptor) { + self.subqueries.insert(subquery.clone()); } } -#[derive(Copy, Clone, Debug, PartialEq, Eq, Hash, PartialOrd, Ord)] +#[derive(Copy, Clone, PartialEq, Eq, Hash, PartialOrd, Ord)] pub struct Revision { generation: u64, } @@ -194,6 +200,12 @@ impl Revision { } } +impl std::fmt::Debug for Revision { + fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(fmt, "R({})", self.generation) + } +} + /// An insertion-order-preserving set of queries. Used to track the /// inputs accessed during query execution. crate struct QueryDescriptorSet { diff --git a/src/volatile.rs b/src/volatile.rs index 19427f87..911da65a 100644 --- a/src/volatile.rs +++ b/src/volatile.rs @@ -4,6 +4,7 @@ use crate::Query; use crate::QueryContext; use crate::QueryStorageOps; use crate::QueryTable; +use log::debug; use parking_lot::{RwLock, RwLockUpgradableReadGuard}; use rustc_hash::FxHashMap; use std::any::Any; @@ -28,25 +29,34 @@ where &self, query: &'q QC, key: &Q::Key, - descriptor: impl FnOnce() -> QC::QueryDescriptor, + descriptor: &QC::QueryDescriptor, ) -> Result { // FIXME: Should we even call `execute_query_implementation` // here? Or should we just call `Q::execute`, and maybe // separate out the `push`/`pop` operations. - let descriptor = descriptor(); let (value, _inputs) = query .salsa_runtime() .execute_query_implementation::(query, descriptor, key); + + query.salsa_runtime().report_query_read(descriptor); + Ok(value) } fn maybe_changed_since( &self, _query: &'q QC, - _revision: Revision, - _key: &Q::Key, + revision: Revision, + key: &Q::Key, _descriptor: &QC::QueryDescriptor, ) -> bool { + debug!( + "{:?}({:?})::maybe_changed_since(revision={:?}) ==> true (volatile)", + Q::default(), + key, + revision, + ); + true } } diff --git a/tests/incremental/log.rs b/tests/incremental/log.rs index 55eceb97..469bd124 100644 --- a/tests/incremental/log.rs +++ b/tests/incremental/log.rs @@ -10,7 +10,7 @@ impl Log { self.data.borrow_mut().push(text.into()); } - crate fn read(&self) -> Vec { - self.data.borrow().clone() + crate fn take(&self) -> Vec { + std::mem::replace(&mut *self.data.borrow_mut(), vec![]) } } diff --git a/tests/incremental/tests.rs b/tests/incremental/tests.rs index 7648790c..ac516ad5 100644 --- a/tests/incremental/tests.rs +++ b/tests/incremental/tests.rs @@ -2,18 +2,36 @@ use crate::implementation::QueryContextImpl; use crate::queries::CounterContext; -use crate::queries::QueryContext; +use crate::queries::QueryContext as _; +use salsa::QueryContext as _; impl QueryContextImpl { fn assert_log(&self, expected_log: &[&str]) { - let expected_text = format!("{:#?}", expected_log); - let actual_text = format!("{:#?}", self.log().read()); - text_diff::assert_diff(&expected_text, &actual_text, "", 0); + use difference::{Changeset, Difference}; + + let expected_text = &format!("{:#?}", expected_log); + let actual_text = &format!("{:#?}", self.log().take()); + + if expected_text == actual_text { + return; + } + + let Changeset { diffs, .. } = Changeset::new(expected_text, actual_text, "\n"); + + for i in 0..diffs.len() { + match &diffs[i] { + Difference::Same(x) => println!(" {}", x), + Difference::Add(x) => println!("+{}", x), + Difference::Rem(x) => println!("-{}", x), + } + } + + panic!("incorrect log results"); } } #[test] -fn foo() { +fn volatile_x2() { let query = QueryContextImpl::default(); // Invoking volatile twice will simply execute twice. @@ -21,3 +39,21 @@ fn foo() { query.volatile().of(()); query.assert_log(&["Volatile invoked", "Volatile invoked"]); } + +#[test] +fn foo() { + env_logger::init(); + + let query = QueryContextImpl::default(); + + query.memoized2().of(()); + query.assert_log(&["Memoized2 invoked", "Memoized1 invoked", "Volatile invoked"]); + + query.memoized2().of(()); + query.assert_log(&[]); + + query.salsa_runtime().next_revision(); + + query.memoized2().of(()); + query.assert_log(&["Memoized1 invoked", "Volatile invoked"]); +}