Tweak debug outputs to make debugging new solver easier

compiler/rustc_trait_selection/src/solve/assembly.rs

@@ -270,6 +270,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
     /// To deal with this, we first try to normalize the self type and add the candidates for the normalized
     /// self type to the list of candidates in case that succeeds. We also have to consider candidates with the
     /// projection as a self type as well
+    #[instrument(level = "debug", skip_all)]
     fn assemble_candidates_after_normalizing_self_ty<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -315,6 +316,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_impl_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -333,6 +335,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         );
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_builtin_impl_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -390,6 +393,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_param_env_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -405,6 +409,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_alias_bound_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -452,6 +457,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_object_bound_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,
@@ -514,6 +520,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip_all)]
     fn assemble_coherence_unknowable_candidates<G: GoalKind<'tcx>>(
         &mut self,
         goal: Goal<'tcx, G>,

compiler/rustc_trait_selection/src/solve/eval_ctxt.rs

@@ -106,7 +106,7 @@ pub trait InferCtxtEvalExt<'tcx> {
 }
 
 impl<'tcx> InferCtxtEvalExt<'tcx> for InferCtxt<'tcx> {
-    #[instrument(level = "debug", skip(self))]
+    #[instrument(level = "debug", skip(self), ret)]
     fn evaluate_root_goal(
         &self,
         goal: Goal<'tcx, ty::Predicate<'tcx>>,
@@ -552,7 +552,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
     ///
     /// If possible, try using `eq` instead which automatically handles nested
     /// goals correctly.
-    #[instrument(level = "debug", skip(self, param_env), ret)]
+    #[instrument(level = "trace", skip(self, param_env), ret)]
     pub(super) fn eq_and_get_goals<T: ToTrace<'tcx>>(
         &self,
         param_env: ty::ParamEnv<'tcx>,

compiler/rustc_trait_selection/src/solve/mod.rs

@@ -153,13 +153,22 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
     ) -> QueryResult<'tcx> {
         let tcx = self.tcx();
         // We may need to invert the alias relation direction if dealing an alias on the RHS.
+        #[derive(Debug)]
         enum Invert {
             No,
             Yes,
         }
         let evaluate_normalizes_to =
             |ecx: &mut EvalCtxt<'_, 'tcx>, alias, other, direction, invert| {
-                debug!("evaluate_normalizes_to(alias={:?}, other={:?})", alias, other);
+                let span = tracing::span!(
+                    tracing::Level::DEBUG,
+                    "compute_alias_relate_goal(evaluate_normalizes_to)",
+                    ?alias,
+                    ?other,
+                    ?direction,
+                    ?invert
+                );
+                let _enter = span.enter();
                 let result = ecx.probe(|ecx| {
                     let other = match direction {
                         // This is purely an optimization.
@@ -184,7 +193,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
                     ));
                     ecx.evaluate_added_goals_and_make_canonical_response(Certainty::Yes)
                 });
-                debug!("evaluate_normalizes_to({alias}, {other}, {direction:?}) -> {result:?}");
+                debug!(?result);
                 result
             };
 
@@ -210,7 +219,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
             }
 
             (Some(alias_lhs), Some(alias_rhs)) => {
-                debug!("compute_alias_relate_goal: both sides are aliases");
+                debug!("both sides are aliases");
 
                 let candidates = vec![
                     // LHS normalizes-to RHS
@@ -219,9 +228,14 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
                     evaluate_normalizes_to(self, alias_rhs, lhs, direction, Invert::Yes),
                     // Relate via substs
                     self.probe(|ecx| {
-                        debug!(
-                            "compute_alias_relate_goal: alias defids are equal, equating substs"
+                        let span = tracing::span!(
+                            tracing::Level::DEBUG,
+                            "compute_alias_relate_goal(relate_via_substs)",
+                            ?alias_lhs,
+                            ?alias_rhs,
+                            ?direction
                         );
+                        let _enter = span.enter();
 
                         match direction {
                             ty::AliasRelationDirection::Equate => {
@@ -275,6 +289,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         debug!("added_goals={:?}", &self.nested_goals.goals[current_len..]);
     }
 
+    #[instrument(level = "debug", skip(self, responses))]
     fn try_merge_responses(
         &mut self,
         responses: impl Iterator<Item = QueryResult<'tcx>>,
@@ -304,6 +319,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
         });
         // FIXME(-Ztrait-solver=next): We should take the intersection of the constraints on all the
         // responses and use that for the constraints of this ambiguous response.
+        debug!(">1 response, bailing with {certainty:?}");
         let response = self.evaluate_added_goals_and_make_canonical_response(certainty);
         if let Ok(response) = &response {
             assert!(response.has_no_inference_or_external_constraints());

compiler/rustc_trait_selection/src/solve/search_graph/mod.rs

@@ -209,6 +209,7 @@ impl<'tcx> SearchGraph<'tcx> {
     ) -> QueryResult<'tcx> {
         if self.should_use_global_cache() {
             if let Some(result) = tcx.new_solver_evaluation_cache.get(&canonical_goal, tcx) {
+                debug!(?canonical_goal, ?result, "cache hit");
                 return result;
             }
         }