chore: Add more tracing

src/internal/id.rs

@@ -60,6 +60,12 @@ impl ArenaId for VersionSetId {
 #[cfg_attr(feature = "serde", serde(transparent))]
 pub struct SolvableId(pub u32);
 
+impl SolvableId {
+    pub(crate) const fn as_internal(self) -> InternalSolvableId {
+        InternalSolvableId(self.0 + 1)
+    }
+}
+
 /// Internally used id for solvables that can also represent root and null.
 #[repr(transparent)]
 #[derive(Copy, Clone, Eq, PartialEq, Hash, Debug, Ord, PartialOrd)]

src/solver/cache.rs

@@ -171,14 +171,26 @@ impl<D: DependencyProvider> SolverCache<D> {
         match self.version_set_candidates.get(&version_set_id) {
             Some(candidates) => Ok(candidates),
             None => {
-                let package_name = self.provider.version_set_name(version_set_id);
-                let candidates = self.get_or_cache_candidates(package_name).await?;
+                let package_name_id = self.provider.version_set_name(version_set_id);
+
+                tracing::trace!(
+                    "Getting matching candidates for package: {:?}",
+                    self.provider.display_name(package_name_id).to_string()
+                );
+
+                let candidates = self.get_or_cache_candidates(package_name_id).await?;
+                tracing::trace!("Got {:?} matching candidates", candidates.candidates.len());
 
                 let matching_candidates = self
                     .provider
                     .filter_candidates(&candidates.candidates, version_set_id, false)
                     .await;
 
+                tracing::trace!(
+                    "Filtered {:?} matching candidates",
+                    matching_candidates.len()
+                );
+
                 Ok(self
                     .version_set_candidates
                     .insert(version_set_id, matching_candidates))
@@ -197,17 +209,32 @@ impl<D: DependencyProvider> SolverCache<D> {
         match self.version_set_inverse_candidates.get(&version_set_id) {
             Some(candidates) => Ok(candidates),
             None => {
-                let package_name = self.provider.version_set_name(version_set_id);
-                let candidates = self.get_or_cache_candidates(package_name).await?;
+                let package_name_id = self.provider.version_set_name(version_set_id);
 
-                let matching_candidates = self
+                tracing::trace!(
+                    "Getting NON-matching candidates for package: {:?}",
+                    self.provider.display_name(package_name_id).to_string()
+                );
+
+                let candidates = self.get_or_cache_candidates(package_name_id).await?;
+                tracing::trace!(
+                    "Got {:?} NON-matching candidates",
+                    candidates.candidates.len()
+                );
+
+                let matching_candidates: Vec<SolvableId> = self
                     .provider
                     .filter_candidates(&candidates.candidates, version_set_id, true)
                     .await
                     .into_iter()
                     .map(Into::into)
                     .collect();
 
+                tracing::trace!(
+                    "Filtered {:?} matching candidates",
+                    matching_candidates.len()
+                );
+
                 Ok(self
                     .version_set_inverse_candidates
                     .insert(version_set_id, matching_candidates))
@@ -227,11 +254,16 @@ impl<D: DependencyProvider> SolverCache<D> {
         match self.version_set_to_sorted_candidates.get(&version_set_id) {
             Some(candidates) => Ok(candidates),
             None => {
-                let package_name = self.provider.version_set_name(version_set_id);
+                let package_name_id = self.provider.version_set_name(version_set_id);
+                tracing::trace!(
+                    "Getting sorted matching candidates for package: {:?}",
+                    self.provider.display_name(package_name_id).to_string()
+                );
+
                 let matching_candidates = self
                     .get_or_cache_matching_candidates(version_set_id)
                     .await?;
-                let candidates = self.get_or_cache_candidates(package_name).await?;
+                let candidates = self.get_or_cache_candidates(package_name_id).await?;
 
                 // Sort all the candidates in order in which they should be tried by the solver.
                 let mut sorted_candidates = Vec::new();

src/solver/clause.rs

@@ -611,48 +611,56 @@ pub(crate) struct ClauseDisplay<'i, I: Interner> {
 impl<'i, I: Interner> Display for ClauseDisplay<'i, I> {
     fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
         match self.kind {
-            Clause::InstallRoot => write!(f, "install root"),
+            Clause::InstallRoot => write!(f, "InstallRoot"),
             Clause::Excluded(solvable_id, reason) => {
                 write!(
                     f,
-                    "{} excluded because: {}",
+                    "Excluded({}({:?}), {})",
                     solvable_id.display(self.interner),
+                    solvable_id,
                     self.interner.display_string(reason)
                 )
             }
-            Clause::Learnt(learnt_id) => write!(f, "learnt clause {learnt_id:?}"),
+            Clause::Learnt(learnt_id) => write!(f, "Learnt({learnt_id:?})"),
             Clause::Requires(solvable_id, version_set_id) => {
                 write!(
                     f,
-                    "{} requires {} {}",
+                    "Requires({}({:?}), {})",
                     solvable_id.display(self.interner),
-                    self.interner
-                        .display_name(self.interner.version_set_name(version_set_id)),
+                    solvable_id,
                     self.interner.display_version_set(version_set_id)
                 )
             }
             Clause::Constrains(s1, s2, version_set_id) => {
                 write!(
                     f,
-                    "{} excludes {} by {}",
+                    "Constrains({}({:?}), {}({:?}), {})",
                     s1.display(self.interner),
+                    s1,
                     s2.display(self.interner),
-                    self.interner.display_version_set(version_set_id),
+                    s2,
+                    self.interner.display_version_set(version_set_id)
                 )
             }
-            Clause::Lock(locked, forbidden) => {
+            Clause::ForbidMultipleInstances(s1, s2, name) => {
                 write!(
                     f,
-                    "{} is locked, so {} is forbidden",
-                    locked.display(self.interner),
-                    forbidden.display(self.interner),
+                    "ForbidMultipleInstances({}({:?}), {}({:?}), {})",
+                    s1.display(self.interner),
+                    s1,
+                    s2.display(self.interner),
+                    s2,
+                    self.interner.display_name(name)
                 )
             }
-            Clause::ForbidMultipleInstances(_, _, name_id) => {
+            Clause::Lock(locked, other) => {
                 write!(
                     f,
-                    "only one {} allowed",
-                    self.interner.display_name(name_id)
+                    "Lock({}({:?}), {}({:?}))",
+                    locked.display(self.interner),
+                    locked,
+                    other.display(self.interner),
+                    other,
                 )
             }
         }