Implement a query stack Backtrace analog (#827)

components/salsa-macro-rules/src/setup_input_struct.rs

@@ -72,6 +72,10 @@ macro_rules! setup_input_struct {
             type $Configuration = $Struct;
 
             impl $zalsa_struct::Configuration for $Configuration {
+                const LOCATION: $zalsa::Location = $zalsa::Location {
+                    file: file!(),
+                    line: line!(),
+                };
                 const DEBUG_NAME: &'static str = stringify!($Struct);
                 const FIELD_DEBUG_NAMES: &'static [&'static str] = &[$(stringify!($field_id)),*];
                 type Singleton = $zalsa::macro_if! {if $is_singleton {$zalsa::input::Singleton} else {$zalsa::input::NotSingleton}};

components/salsa-macro-rules/src/setup_interned_struct.rs

@@ -121,6 +121,10 @@ macro_rules! setup_interned_struct {
             }
 
             impl salsa::plumbing::interned::Configuration for $StructWithStatic {
+                const LOCATION: $zalsa::Location = $zalsa::Location {
+                    file: file!(),
+                    line: line!(),
+                };
                 const DEBUG_NAME: &'static str = stringify!($Struct);
                 type Fields<'a> = $StructDataIdent<'a>;
                 type Struct<'db> = $Struct< $($db_lt_arg)? >;

components/salsa-macro-rules/src/setup_tracked_fn.rs

@@ -135,6 +135,10 @@ macro_rules! setup_tracked_fn {
                     }
 
                     impl $zalsa::interned::Configuration for $Configuration {
+                        const LOCATION: $zalsa::Location = $zalsa::Location {
+                            file: file!(),
+                            line: line!(),
+                        };
                         const DEBUG_NAME: &'static str = "Configuration";
 
                         type Fields<$db_lt> = ($($input_ty),*);
@@ -177,6 +181,10 @@ macro_rules! setup_tracked_fn {
             }
 
             impl $zalsa::function::Configuration for $Configuration {
+                const LOCATION: $zalsa::Location = $zalsa::Location {
+                    file: file!(),
+                    line: line!(),
+                };
                 const DEBUG_NAME: &'static str = stringify!($fn_name);
 
                 type DbView = dyn $Db;

components/salsa-macro-rules/src/setup_tracked_struct.rs

@@ -107,6 +107,10 @@ macro_rules! setup_tracked_struct {
             type $Configuration = $Struct<'static>;
 
             impl $zalsa_struct::Configuration for $Configuration {
+                const LOCATION: $zalsa::Location = $zalsa::Location {
+                    file: file!(),
+                    line: line!(),
+                };
                 const DEBUG_NAME: &'static str = stringify!($Struct);
 
                 const TRACKED_FIELD_NAMES: &'static [&'static str] = &[

src/accumulator.rs

@@ -9,7 +9,7 @@ use std::sync::Arc;
 use accumulated::{Accumulated, AnyAccumulated};
 
 use crate::function::VerifyResult;
-use crate::ingredient::{fmt_index, Ingredient, Jar};
+use crate::ingredient::{Ingredient, Jar};
 use crate::plumbing::IngredientIndices;
 use crate::table::memo::MemoTableTypes;
 use crate::zalsa::{IngredientIndex, Zalsa};
@@ -92,6 +92,15 @@ impl<A: Accumulator> IngredientImpl<A> {
 }
 
 impl<A: Accumulator> Ingredient for IngredientImpl<A> {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &const {
+            crate::ingredient::Location {
+                file: file!(),
+                line: line!(),
+            }
+        }
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.index
     }
@@ -105,10 +114,6 @@ impl<A: Accumulator> Ingredient for IngredientImpl<A> {
         panic!("nothing should ever depend on an accumulator directly")
     }
 
-    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
-        fmt_index(A::DEBUG_NAME, index, fmt)
-    }
-
     fn debug_name(&self) -> &'static str {
         A::DEBUG_NAME
     }

src/active_query.rs

@@ -1,6 +1,6 @@
 use std::ops::Not;
 use std::sync::atomic::AtomicBool;
-use std::{mem, ops};
+use std::{fmt, mem, ops};
 
 use crate::accumulator::accumulated_map::{
     AccumulatedMap, AtomicInputAccumulatedValues, InputAccumulatedValues,
@@ -347,3 +347,118 @@ impl QueryStack {
         self.stack[self.len].clear()
     }
 }
+
+struct CapturedQuery {
+    database_key_index: DatabaseKeyIndex,
+    durability: Durability,
+    changed_at: Revision,
+    cycle_heads: CycleHeads,
+    iteration_count: u32,
+}
+
+impl fmt::Debug for CapturedQuery {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        let mut debug_struct = f.debug_struct("CapturedQuery");
+        debug_struct
+            .field("database_key_index", &self.database_key_index)
+            .field("durability", &self.durability)
+            .field("changed_at", &self.changed_at);
+        if !self.cycle_heads.is_empty() {
+            debug_struct
+                .field("cycle_heads", &self.cycle_heads)
+                .field("iteration_count", &self.iteration_count);
+        }
+        debug_struct.finish()
+    }
+}
+
+pub struct Backtrace(Box<[CapturedQuery]>);
+
+impl Backtrace {
+    pub fn capture() -> Option<Self> {
+        crate::with_attached_database(|db| {
+            db.zalsa_local().with_query_stack(|stack| {
+                Backtrace(
+                    stack
+                        .iter()
+                        .rev()
+                        .map(|query| CapturedQuery {
+                            database_key_index: query.database_key_index,
+                            durability: query.durability,
+                            changed_at: query.changed_at,
+                            cycle_heads: query.cycle_heads.clone(),
+                            iteration_count: query.iteration_count,
+                        })
+                        .collect(),
+                )
+            })
+        })
+    }
+}
+
+impl fmt::Debug for Backtrace {
+    fn fmt(&self, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
+        write!(fmt, "Backtrace ")?;
+
+        let mut dbg = fmt.debug_list();
+
+        for frame in &self.0 {
+            dbg.entry(&frame);
+        }
+
+        dbg.finish()
+    }
+}
+
+impl fmt::Display for Backtrace {
+    fn fmt(&self, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
+        writeln!(fmt, "query stacktrace:")?;
+        let full = fmt.alternate();
+        let indent = "             ";
+        for (
+            idx,
+            &CapturedQuery {
+                database_key_index,
+                durability,
+                changed_at,
+                ref cycle_heads,
+                iteration_count,
+            },
+        ) in self.0.iter().enumerate()
+        {
+            write!(fmt, "{idx:>4}: {database_key_index:?}")?;
+            if full {
+                write!(fmt, " -> ({changed_at:?}, {durability:#?}")?;
+                if !cycle_heads.is_empty() || iteration_count > 0 {
+                    write!(fmt, ", iteration = {iteration_count:?}")?;
+                }
+                write!(fmt, ")")?;
+            }
+            writeln!(fmt)?;
+            crate::attach::with_attached_database(|db| {
+                let ingredient = db
+                    .zalsa()
+                    .lookup_ingredient(database_key_index.ingredient_index());
+                let loc = ingredient.location();
+                writeln!(fmt, "{indent}at {}:{}", loc.file, loc.line)?;
+                if !cycle_heads.is_empty() {
+                    write!(fmt, "{indent}cycle heads: ")?;
+                    for (idx, head) in cycle_heads.iter().enumerate() {
+                        if idx != 0 {
+                            write!(fmt, ", ")?;
+                        }
+                        write!(
+                            fmt,
+                            "{:?} -> {:?}",
+                            head.database_key_index, head.iteration_count
+                        )?;
+                    }
+                    writeln!(fmt)?;
+                }
+                Ok(())
+            })
+            .transpose()?;
+        }
+        Ok(())
+    }
+}

src/durability.rs

@@ -21,9 +21,17 @@ pub struct Durability(DurabilityVal);
 
 impl std::fmt::Debug for Durability {
     fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
-        f.debug_tuple("Durability")
-            .field(&(self.0 as usize))
-            .finish()
+        if f.alternate() {
+            match self.0 {
+                DurabilityVal::Low => f.write_str("Durability::LOW"),
+                DurabilityVal::Medium => f.write_str("Durability::MEDIUM"),
+                DurabilityVal::High => f.write_str("Durability::HIGH"),
+            }
+        } else {
+            f.debug_tuple("Durability")
+                .field(&(self.0 as usize))
+                .finish()
+        }
     }
 }
 

src/function.rs

@@ -9,7 +9,7 @@ use crate::accumulator::accumulated_map::{AccumulatedMap, InputAccumulatedValues
 use crate::cycle::{CycleHeadKind, CycleRecoveryAction, CycleRecoveryStrategy};
 use crate::function::delete::DeletedEntries;
 use crate::function::sync::{ClaimResult, SyncTable};
-use crate::ingredient::{fmt_index, Ingredient};
+use crate::ingredient::Ingredient;
 use crate::key::DatabaseKeyIndex;
 use crate::plumbing::MemoIngredientMap;
 use crate::salsa_struct::SalsaStructInDb;
@@ -37,6 +37,7 @@ pub type Memo<C> = memo::Memo<<C as Configuration>::Output<'static>>;
 
 pub trait Configuration: Any {
     const DEBUG_NAME: &'static str;
+    const LOCATION: crate::ingredient::Location;
 
     /// The database that this function is associated with.
     type DbView: ?Sized + crate::Database;
@@ -228,6 +229,10 @@ impl<C> Ingredient for IngredientImpl<C>
 where
     C: Configuration,
 {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.index
     }
@@ -313,10 +318,6 @@ where
         self.deleted_entries.clear();
     }
 
-    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
-        fmt_index(C::DEBUG_NAME, index, fmt)
-    }
-
     fn debug_name(&self) -> &'static str {
         C::DEBUG_NAME
     }

src/ingredient.rs

@@ -44,8 +44,14 @@ pub trait Jar: Any {
         Self: Sized;
 }
 
+pub struct Location {
+    pub file: &'static str,
+    pub line: u32,
+}
+
 pub trait Ingredient: Any + std::fmt::Debug + Send + Sync {
     fn debug_name(&self) -> &'static str;
+    fn location(&self) -> &'static Location;
 
     /// Has the value for `input` in this ingredient changed after `revision`?
     ///
@@ -136,7 +142,9 @@ pub trait Ingredient: Any + std::fmt::Debug + Send + Sync {
 
     fn memo_table_types(&self) -> Arc<MemoTableTypes>;
 
-    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result;
+    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
+        fmt_index(self.debug_name(), index, fmt)
+    }
     // Function ingredient methods
 
     /// If this ingredient is a participant in a cycle, what is its cycle recovery strategy?

src/input.rs

@@ -11,7 +11,7 @@ use input_field::FieldIngredientImpl;
 
 use crate::function::VerifyResult;
 use crate::id::{AsId, FromId, FromIdWithDb};
-use crate::ingredient::{fmt_index, Ingredient};
+use crate::ingredient::Ingredient;
 use crate::input::singleton::{Singleton, SingletonChoice};
 use crate::key::DatabaseKeyIndex;
 use crate::plumbing::{Jar, Stamp};
@@ -23,6 +23,7 @@ use crate::{Database, Durability, Id, Revision, Runtime};
 pub trait Configuration: Any {
     const DEBUG_NAME: &'static str;
     const FIELD_DEBUG_NAMES: &'static [&'static str];
+    const LOCATION: crate::ingredient::Location;
 
     /// The singleton state for this input if any.
     type Singleton: SingletonChoice + Send + Sync;
@@ -199,6 +200,10 @@ impl<C: Configuration> IngredientImpl<C> {
 }
 
 impl<C: Configuration> Ingredient for IngredientImpl<C> {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.ingredient_index
     }
@@ -213,9 +218,6 @@ impl<C: Configuration> Ingredient for IngredientImpl<C> {
         // Their *fields* are stored in function ingredients elsewhere.
         VerifyResult::unchanged()
     }
-    fn fmt_index(&self, index: Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
-        fmt_index(C::DEBUG_NAME, index, fmt)
-    }
 
     fn debug_name(&self) -> &'static str {
         C::DEBUG_NAME

src/input/input_field.rs

@@ -41,6 +41,10 @@ impl<C> Ingredient for FieldIngredientImpl<C>
 where
     C: Configuration,
 {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.index
     }

src/interned.rs

@@ -15,7 +15,7 @@ use crate::durability::Durability;
 use crate::function::VerifyResult;
 use crate::hash::FxDashMap;
 use crate::id::{AsId, FromId};
-use crate::ingredient::{fmt_index, Ingredient};
+use crate::ingredient::Ingredient;
 use crate::plumbing::{IngredientIndices, Jar};
 use crate::revision::AtomicRevision;
 use crate::table::memo::{MemoTable, MemoTableTypes};
@@ -24,6 +24,8 @@ use crate::zalsa::{IngredientIndex, Zalsa};
 use crate::{Database, DatabaseKeyIndex, Event, EventKind, Id, Revision};
 
 pub trait Configuration: Sized + 'static {
+    const LOCATION: crate::ingredient::Location;
+
     const DEBUG_NAME: &'static str;
 
     /// The fields of the struct being interned.
@@ -379,6 +381,10 @@ impl<C> Ingredient for IngredientImpl<C>
 where
     C: Configuration,
 {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.ingredient_index
     }
@@ -416,10 +422,6 @@ where
         VerifyResult::unchanged()
     }
 
-    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
-        fmt_index(C::DEBUG_NAME, index, fmt)
-    }
-
     fn debug_name(&self) -> &'static str {
         C::DEBUG_NAME
     }

src/lib.rs

@@ -38,6 +38,7 @@ pub use parallel::{join, par_map};
 pub use salsa_macros::{accumulator, db, input, interned, tracked, Supertype, Update};
 
 pub use self::accumulator::Accumulator;
+pub use self::active_query::Backtrace;
 pub use self::cancelled::Cancelled;
 pub use self::cycle::CycleRecoveryAction;
 pub use self::database::{AsDynDatabase, Database};
@@ -80,7 +81,7 @@ pub mod plumbing {
     pub use crate::cycle::{CycleRecoveryAction, CycleRecoveryStrategy};
     pub use crate::database::{current_revision, Database};
     pub use crate::id::{AsId, FromId, FromIdWithDb, Id};
-    pub use crate::ingredient::{Ingredient, Jar};
+    pub use crate::ingredient::{Ingredient, Jar, Location};
     pub use crate::key::DatabaseKeyIndex;
     pub use crate::memo_ingredient_indices::{
         IngredientIndices, MemoIngredientIndices, MemoIngredientMap, MemoIngredientSingletonIndex,

src/tracked_struct.rs

@@ -12,7 +12,7 @@ use tracked_field::FieldIngredientImpl;
 
 use crate::function::VerifyResult;
 use crate::id::{AsId, FromId};
-use crate::ingredient::{fmt_index, Ingredient, Jar};
+use crate::ingredient::{Ingredient, Jar};
 use crate::key::DatabaseKeyIndex;
 use crate::plumbing::ZalsaLocal;
 use crate::revision::OptionalAtomicRevision;
@@ -30,6 +30,8 @@ pub mod tracked_field;
 /// Implemented by the `#[salsa::tracked]` macro when applied
 /// to a struct.
 pub trait Configuration: Sized + 'static {
+    const LOCATION: crate::ingredient::Location;
+
     /// The debug name of the tracked struct.
     const DEBUG_NAME: &'static str;
 
@@ -732,6 +734,10 @@ impl<C> Ingredient for IngredientImpl<C>
 where
     C: Configuration,
 {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.ingredient_index
     }
@@ -777,10 +783,6 @@ where
         self.delete_entity(db, stale_output_key, provisional);
     }
 
-    fn fmt_index(&self, index: crate::Id, fmt: &mut fmt::Formatter<'_>) -> fmt::Result {
-        fmt_index(C::DEBUG_NAME, index, fmt)
-    }
-
     fn debug_name(&self) -> &'static str {
         C::DEBUG_NAME
     }

src/tracked_struct/tracked_field.rs

@@ -45,6 +45,10 @@ impl<C> Ingredient for FieldIngredientImpl<C>
 where
     C: Configuration,
 {
+    fn location(&self) -> &'static crate::ingredient::Location {
+        &C::LOCATION
+    }
+
     fn ingredient_index(&self) -> IngredientIndex {
         self.ingredient_index
     }

tests/backtrace.rs

@@ -0,0 +1,127 @@
+use expect_test::expect;
+use salsa::{Backtrace, Database, DatabaseImpl};
+use test_log::test;
+
+#[salsa::input(debug)]
+struct Thing {
+    detailed: bool,
+}
+
+#[salsa::tracked]
+fn query_a(db: &dyn Database, thing: Thing) -> String {
+    query_b(db, thing)
+}
+
+#[salsa::tracked]
+fn query_b(db: &dyn Database, thing: Thing) -> String {
+    query_c(db, thing)
+}
+
+#[salsa::tracked]
+fn query_c(db: &dyn Database, thing: Thing) -> String {
+    query_d(db, thing)
+}
+
+#[salsa::tracked]
+fn query_d(db: &dyn Database, thing: Thing) -> String {
+    query_e(db, thing)
+}
+
+#[salsa::tracked]
+fn query_e(db: &dyn Database, thing: Thing) -> String {
+    if thing.detailed(db) {
+        format!("{:#}", Backtrace::capture().unwrap())
+    } else {
+        format!("{}", Backtrace::capture().unwrap())
+    }
+}
+#[salsa::tracked]
+fn query_f(db: &dyn Database, thing: Thing) -> String {
+    query_cycle(db, thing)
+}
+
+#[salsa::tracked(cycle_fn=cycle_fn, cycle_initial=cycle_initial)]
+fn query_cycle(db: &dyn Database, thing: Thing) -> String {
+    let backtrace = query_cycle(db, thing);
+    if backtrace.is_empty() {
+        query_e(db, thing)
+    } else {
+        backtrace
+    }
+}
+
+fn cycle_initial(_db: &dyn salsa::Database, _thing: Thing) -> String {
+    String::new()
+}
+
+fn cycle_fn(
+    _db: &dyn salsa::Database,
+    _value: &str,
+    _count: u32,
+    _thing: Thing,
+) -> salsa::CycleRecoveryAction<String> {
+    salsa::CycleRecoveryAction::Iterate
+}
+
+#[test]
+fn backtrace_works() {
+    let db = DatabaseImpl::default();
+
+    let backtrace = query_a(&db, Thing::new(&db, false)).replace("\\", "/");
+    expect![[r#"
+        query stacktrace:
+           0: query_e(Id(0))
+                     at tests/backtrace.rs:30
+           1: query_d(Id(0))
+                     at tests/backtrace.rs:25
+           2: query_c(Id(0))
+                     at tests/backtrace.rs:20
+           3: query_b(Id(0))
+                     at tests/backtrace.rs:15
+           4: query_a(Id(0))
+                     at tests/backtrace.rs:10
+    "#]]
+    .assert_eq(&backtrace);
+
+    let backtrace = query_a(&db, Thing::new(&db, true)).replace("\\", "/");
+    expect![[r#"
+        query stacktrace:
+           0: query_e(Id(1)) -> (R1, Durability::LOW)
+                     at tests/backtrace.rs:30
+           1: query_d(Id(1)) -> (R1, Durability::HIGH)
+                     at tests/backtrace.rs:25
+           2: query_c(Id(1)) -> (R1, Durability::HIGH)
+                     at tests/backtrace.rs:20
+           3: query_b(Id(1)) -> (R1, Durability::HIGH)
+                     at tests/backtrace.rs:15
+           4: query_a(Id(1)) -> (R1, Durability::HIGH)
+                     at tests/backtrace.rs:10
+    "#]]
+    .assert_eq(&backtrace);
+
+    let backtrace = query_f(&db, Thing::new(&db, false)).replace("\\", "/");
+    expect![[r#"
+        query stacktrace:
+           0: query_e(Id(2))
+                     at tests/backtrace.rs:30
+           1: query_cycle(Id(2))
+                     at tests/backtrace.rs:43
+                     cycle heads: query_cycle(Id(2)) -> 0
+           2: query_f(Id(2))
+                     at tests/backtrace.rs:38
+    "#]]
+    .assert_eq(&backtrace);
+
+    let backtrace = query_f(&db, Thing::new(&db, true)).replace("\\", "/");
+    expect![[r#"
+        query stacktrace:
+           0: query_e(Id(3)) -> (R1, Durability::LOW)
+                     at tests/backtrace.rs:30
+           1: query_cycle(Id(3)) -> (R1, Durability::HIGH, iteration = 0)
+                     at tests/backtrace.rs:43
+                     cycle heads: query_cycle(Id(3)) -> 0
+           2: query_f(Id(3)) -> (R1, Durability::HIGH)
+                     at tests/backtrace.rs:38
+    "#]]
+    .assert_eq(&backtrace);
+}

tests/interned-structs_self_ref.rs

@@ -69,6 +69,10 @@ const _: () = {
         }
     }
     impl zalsa_struct_::Configuration for Configuration_ {
+        const LOCATION: zalsa_::Location = zalsa_::Location {
+            file: file!(),
+            line: line!(),
+        };
         const DEBUG_NAME: &'static str = "InternedString";
         type Fields<'a> = StructData<'a>;
         type Struct<'a> = InternedString<'a>;