add debugging, get incremental test working

This commit is contained in:
Niko Matsakis 2018-09-30 07:28:22 -04:00
parent 2d2bdfe7f1
commit 9bfd8ebbfa
7 changed files with 135 additions and 38 deletions

View file

@ -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"
difference = "2.0"
env_logger = "0.5.13"

View file

@ -76,7 +76,7 @@ where
&self,
query: &'q QC,
key: &Q::Key,
descriptor: impl FnOnce() -> QC::QueryDescriptor,
descriptor: &QC::QueryDescriptor,
) -> Result<Q::Value, CycleDetected>;
/// True if the query **may** have changed since the given
@ -125,12 +125,13 @@ where
Q: Query<QC>,
{
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)
})
}

View file

@ -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<QC, Q>
where
Q: Query<QC>,
@ -42,7 +42,6 @@ where
Memoized(Memo<QC, Q>),
}
#[derive(Debug)]
struct Memo<QC, Q>
where
Q: Query<QC>,
@ -76,7 +75,6 @@ where
}
}
#[derive(Debug)]
struct StampedValue<V> {
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<StampedValue<Q::Value>, 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::<Q>(query, descriptor, key);
@ -214,9 +234,16 @@ where
&self,
query: &'q QC,
key: &Q::Key,
descriptor: impl FnOnce() -> QC::QueryDescriptor,
descriptor: &QC::QueryDescriptor,
) -> Result<Q::Value, CycleDetected> {
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,
}

View file

@ -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<Q>(
&self,
query: &QC,
descriptor: QC::QueryDescriptor,
descriptor: &QC::QueryDescriptor,
key: &Q::Key,
) -> (Q::Value, QueryDescriptorSet<QC>)
where
Q: Query<QC>,
{
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<QC: QueryContext> ActiveQuery<QC> {
}
}
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<QC: QueryContext> {

View file

@ -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<Q::Value, CycleDetected> {
// 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::<Q>(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
}
}

View file

@ -10,7 +10,7 @@ impl Log {
self.data.borrow_mut().push(text.into());
}
crate fn read(&self) -> Vec<String> {
self.data.borrow().clone()
crate fn take(&self) -> Vec<String> {
std::mem::replace(&mut *self.data.borrow_mut(), vec![])
}
}

View file

@ -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"]);
}