Auto merge of #77792 - matthewjasper:instrument-trait-selection, r=oli-obk

Use tracing spans in rustc_trait_selection

Spans are very helpful when debugging this code. It's also hot enough to make a good benchmark.

r? `@oli-obk`

5 files changed, 166 insertions, 290 deletions

diff --git a/compiler/rustc_trait_selection/src/traits/fulfill.rs b/compiler/rustc_trait_selection/src/traits/fulfill.rs
index 27751eb554d..97dd180b27b 100644
--- a/compiler/rustc_trait_selection/src/traits/fulfill.rs
+++ b/compiler/rustc_trait_selection/src/traits/fulfill.rs
@@ -120,7 +120,8 @@ impl<'a, 'tcx> FulfillmentContext<'tcx> {
         &mut self,
         selcx: &mut SelectionContext<'a, 'tcx>,
     ) -> Result<(), Vec<FulfillmentError<'tcx>>> {
-        debug!("select(obligation-forest-size={})", self.predicates.len());
+        let span = debug_span!("select", obligation_forest_size = ?self.predicates.len());
+        let _enter = span.enter();
 
         let mut errors = Vec::new();
 
@@ -173,7 +174,7 @@ impl<'tcx> TraitEngine<'tcx> for FulfillmentContext<'tcx> {
         projection_ty: ty::ProjectionTy<'tcx>,
         cause: ObligationCause<'tcx>,
     ) -> Ty<'tcx> {
-        debug!("normalize_projection_type(projection_ty={:?})", projection_ty);
+        debug!(?projection_ty, "normalize_projection_type");
 
         debug_assert!(!projection_ty.has_escaping_bound_vars());
 
@@ -191,7 +192,7 @@ impl<'tcx> TraitEngine<'tcx> for FulfillmentContext<'tcx> {
         );
         self.register_predicate_obligations(infcx, obligations);
 
-        debug!("normalize_projection_type: result={:?}", normalized_ty);
+        debug!(?normalized_ty);
 
         normalized_ty
     }
@@ -205,7 +206,7 @@ impl<'tcx> TraitEngine<'tcx> for FulfillmentContext<'tcx> {
         // debug output much nicer to read and so on.
         let obligation = infcx.resolve_vars_if_possible(&obligation);
 
-        debug!("register_predicate_obligation(obligation={:?})", obligation);
+        debug!(?obligation, "register_predicate_obligation");
 
         assert!(!infcx.is_in_snapshot() || self.usable_in_snapshot);
 
@@ -342,7 +343,7 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
                 self.selcx.infcx().resolve_vars_if_possible(&obligation.predicate);
         }
 
-        debug!("process_obligation: obligation = {:?} cause = {:?}", obligation, obligation.cause);
+        debug!(?obligation, ?obligation.cause, "process_obligation");
 
         let infcx = self.selcx.infcx();
 
@@ -509,7 +510,7 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
                 }
 
                 ty::PredicateAtom::ConstEquate(c1, c2) => {
-                    debug!("equating consts: c1={:?} c2={:?}", c1, c2);
+                    debug!(?c1, ?c2, "equating consts");
                     if self.selcx.tcx().features().const_evaluatable_checked {
                         // FIXME: we probably should only try to unify abstract constants
                         // if the constants depend on generic parameters.
@@ -601,6 +602,7 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
         }
     }
 
+    #[instrument(level = "debug", skip(self, obligation, stalled_on))]
     fn process_trait_obligation(
         &mut self,
         obligation: &PredicateObligation<'tcx>,
@@ -613,8 +615,8 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
             // FIXME: consider caching errors too.
             if infcx.predicate_must_hold_considering_regions(obligation) {
                 debug!(
-                    "selecting trait `{:?}` at depth {} evaluated to holds",
-                    obligation.predicate, obligation.recursion_depth
+                    "selecting trait at depth {} evaluated to holds",
+                    obligation.recursion_depth
                 );
                 return ProcessResult::Changed(vec![]);
             }
@@ -622,17 +624,11 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
 
         match self.selcx.select(&trait_obligation) {
             Ok(Some(impl_source)) => {
-                debug!(
-                    "selecting trait `{:?}` at depth {} yielded Ok(Some)",
-                    trait_obligation.predicate, obligation.recursion_depth
-                );
+                debug!("selecting trait at depth {} yielded Ok(Some)", obligation.recursion_depth);
                 ProcessResult::Changed(mk_pending(impl_source.nested_obligations()))
             }
             Ok(None) => {
-                debug!(
-                    "selecting trait `{:?}` at depth {} yielded Ok(None)",
-                    trait_obligation.predicate, obligation.recursion_depth
-                );
+                debug!("selecting trait at depth {} yielded Ok(None)", obligation.recursion_depth);
 
                 // This is a bit subtle: for the most part, the
                 // only reason we can fail to make progress on
@@ -652,10 +648,7 @@ impl<'a, 'b, 'tcx> FulfillProcessor<'a, 'b, 'tcx> {
                 ProcessResult::Unchanged
             }
             Err(selection_err) => {
-                info!(
-                    "selecting trait `{:?}` at depth {} yielded Err",
-                    trait_obligation.predicate, obligation.recursion_depth
-                );
+                info!("selecting trait at depth {} yielded Err", obligation.recursion_depth);
 
                 ProcessResult::Error(CodeSelectionError(selection_err))
             }
diff --git a/compiler/rustc_trait_selection/src/traits/project.rs b/compiler/rustc_trait_selection/src/traits/project.rs
index de42aa0e6b7..8dbf7ec51c6 100644
--- a/compiler/rustc_trait_selection/src/traits/project.rs
+++ b/compiler/rustc_trait_selection/src/traits/project.rs
@@ -157,6 +157,7 @@ impl<'tcx> ProjectionTyCandidateSet<'tcx> {
 ///    the given obligations. If the projection cannot be normalized because
 ///    the required trait bound doesn't hold this returned with `obligations`
 ///    being a predicate that cannot be proven.
+#[instrument(level = "debug", skip(selcx))]
 pub(super) fn poly_project_and_unify_type<'cx, 'tcx>(
     selcx: &mut SelectionContext<'cx, 'tcx>,
     obligation: &PolyProjectionObligation<'tcx>,
@@ -164,8 +165,6 @@ pub(super) fn poly_project_and_unify_type<'cx, 'tcx>(
     Result<Option<Vec<PredicateObligation<'tcx>>>, InProgress>,
     MismatchedProjectionTypes<'tcx>,
 > {
-    debug!("poly_project_and_unify_type(obligation={:?})", obligation);
-
     let infcx = selcx.infcx();
     infcx.commit_if_ok(|_snapshot| {
         let placeholder_predicate =
@@ -191,7 +190,7 @@ fn project_and_unify_type<'cx, 'tcx>(
     Result<Option<Vec<PredicateObligation<'tcx>>>, InProgress>,
     MismatchedProjectionTypes<'tcx>,
 > {
-    debug!("project_and_unify_type(obligation={:?})", obligation);
+    debug!(?obligation, "project_and_unify_type");
 
     let mut obligations = vec![];
     let normalized_ty = match opt_normalize_projection_type(
@@ -207,10 +206,7 @@ fn project_and_unify_type<'cx, 'tcx>(
         Err(InProgress) => return Ok(Err(InProgress)),
     };
 
-    debug!(
-        "project_and_unify_type: normalized_ty={:?} obligations={:?}",
-        normalized_ty, obligations
-    );
+    debug!(?normalized_ty, ?obligations, "project_and_unify_type result");
 
     let infcx = selcx.infcx();
     match infcx
@@ -275,6 +271,7 @@ where
     Normalized { value, obligations }
 }
 
+#[instrument(level = "debug", skip(selcx, param_env, cause, obligations))]
 pub fn normalize_with_depth_to<'a, 'b, 'tcx, T>(
     selcx: &'a mut SelectionContext<'b, 'tcx>,
     param_env: ty::ParamEnv<'tcx>,
@@ -286,16 +283,10 @@ pub fn normalize_with_depth_to<'a, 'b, 'tcx, T>(
 where
     T: TypeFoldable<'tcx>,
 {
-    debug!("normalize_with_depth(depth={}, value={:?})", depth, value);
     let mut normalizer = AssocTypeNormalizer::new(selcx, param_env, cause, depth, obligations);
     let result = ensure_sufficient_stack(|| normalizer.fold(value));
-    debug!(
-        "normalize_with_depth: depth={} result={:?} with {} obligations",
-        depth,
-        result,
-        normalizer.obligations.len()
-    );
-    debug!("normalize_with_depth: depth={} obligations={:?}", depth, normalizer.obligations);
+    debug!(?result, obligations.len = normalizer.obligations.len());
+    debug!(?normalizer.obligations,);
     result
 }
 
@@ -396,12 +387,11 @@ impl<'a, 'b, 'tcx> TypeFolder<'tcx> for AssocTypeNormalizer<'a, 'b, 'tcx> {
                     &mut self.obligations,
                 );
                 debug!(
-                    "AssocTypeNormalizer: depth={} normalized {:?} to {:?}, \
-                     now with {} obligations",
-                    self.depth,
-                    ty,
-                    normalized_ty,
-                    self.obligations.len()
+                    ?self.depth,
+                    ?ty,
+                    ?normalized_ty,
+                    obligations.len = ?self.obligations.len(),
+                    "AssocTypeNormalizer: normalized type"
                 );
                 normalized_ty
             }
@@ -473,6 +463,7 @@ pub fn normalize_projection_type<'a, 'b, 'tcx>(
 /// often immediately appended to another obligations vector. So now this
 /// function takes an obligations vector and appends to it directly, which is
 /// slightly uglier but avoids the need for an extra short-lived allocation.
+#[instrument(level = "debug", skip(selcx, param_env, cause, obligations))]
 fn opt_normalize_projection_type<'a, 'b, 'tcx>(
     selcx: &'a mut SelectionContext<'b, 'tcx>,
     param_env: ty::ParamEnv<'tcx>,
@@ -486,13 +477,6 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
     let projection_ty = infcx.resolve_vars_if_possible(&projection_ty);
     let cache_key = ProjectionCacheKey::new(projection_ty);
 
-    debug!(
-        "opt_normalize_projection_type(\
-         projection_ty={:?}, \
-         depth={})",
-        projection_ty, depth
-    );
-
     // FIXME(#20304) For now, I am caching here, which is good, but it
     // means we don't capture the type variables that are created in
     // the case of ambiguity. Which means we may create a large stream
@@ -508,10 +492,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             // If we found ambiguity the last time, that means we will continue
             // to do so until some type in the key changes (and we know it
             // hasn't, because we just fully resolved it).
-            debug!(
-                "opt_normalize_projection_type: \
-                 found cache entry: ambiguous"
-            );
+            debug!("found cache entry: ambiguous");
             return Ok(None);
         }
         Err(ProjectionCacheEntry::InProgress) => {
@@ -529,10 +510,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             // with `A::B`, which can trigger a recursive
             // normalization.
 
-            debug!(
-                "opt_normalize_projection_type: \
-                 found cache entry: in-progress"
-            );
+            debug!("found cache entry: in-progress");
 
             return Err(InProgress);
         }
@@ -548,11 +526,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             // discarded as duplicated). But when doing trait
             // evaluation this is not the case, and dropping the trait
             // evaluations can causes ICEs (e.g., #43132).
-            debug!(
-                "opt_normalize_projection_type: \
-                 found normalized ty `{:?}`",
-                ty
-            );
+            debug!(?ty, "found normalized ty");
 
             // Once we have inferred everything we need to know, we
             // can ignore the `obligations` from that point on.
@@ -565,10 +539,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             return Ok(Some(ty.value));
         }
         Err(ProjectionCacheEntry::Error) => {
-            debug!(
-                "opt_normalize_projection_type: \
-                 found error"
-            );
+            debug!("opt_normalize_projection_type: found error");
             let result = normalize_to_error(selcx, param_env, projection_ty, cause, depth);
             obligations.extend(result.obligations);
             return Ok(Some(result.value));
@@ -586,13 +557,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             // an impl, where-clause etc) and hence we must
             // re-normalize it
 
-            debug!(
-                "opt_normalize_projection_type: \
-                 projected_ty={:?} \
-                 depth={} \
-                 projected_obligations={:?}",
-                projected_ty, depth, projected_obligations
-            );
+            debug!(?projected_ty, ?depth, ?projected_obligations);
 
             let result = if projected_ty.has_projections() {
                 let mut normalizer = AssocTypeNormalizer::new(
@@ -604,11 +569,7 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
                 );
                 let normalized_ty = normalizer.fold(&projected_ty);
 
-                debug!(
-                    "opt_normalize_projection_type: \
-                     normalized_ty={:?} depth={}",
-                    normalized_ty, depth
-                );
+                debug!(?normalized_ty, ?depth);
 
                 Normalized { value: normalized_ty, obligations: projected_obligations }
             } else {
@@ -621,21 +582,14 @@ fn opt_normalize_projection_type<'a, 'b, 'tcx>(
             Ok(Some(result.value))
         }
         Ok(ProjectedTy::NoProgress(projected_ty)) => {
-            debug!(
-                "opt_normalize_projection_type: \
-                 projected_ty={:?} no progress",
-                projected_ty
-            );
+            debug!(?projected_ty, "opt_normalize_projection_type: no progress");
             let result = Normalized { value: projected_ty, obligations: vec![] };
             infcx.inner.borrow_mut().projection_cache().insert_ty(cache_key, result.clone());
             // No need to extend `obligations`.
             Ok(Some(result.value))
         }
         Err(ProjectionTyError::TooManyCandidates) => {
-            debug!(
-                "opt_normalize_projection_type: \
-                 too many candidates"
-            );
+            debug!("opt_normalize_projection_type: too many candidates");
             infcx.inner.borrow_mut().projection_cache().ambiguous(cache_key);
             Ok(None)
         }
@@ -755,15 +709,12 @@ impl<'tcx> Progress<'tcx> {
 
     fn with_addl_obligations(mut self, mut obligations: Vec<PredicateObligation<'tcx>>) -> Self {
         debug!(
-            "with_addl_obligations: self.obligations.len={} obligations.len={}",
-            self.obligations.len(),
-            obligations.len()
+            self.obligations.len = ?self.obligations.len(),
+            obligations.len = obligations.len(),
+            "with_addl_obligations"
         );
 
-        debug!(
-            "with_addl_obligations: self.obligations={:?} obligations={:?}",
-            self.obligations, obligations
-        );
+        debug!(?self.obligations, ?obligations, "with_addl_obligations");
 
         self.obligations.append(&mut obligations);
         self
@@ -778,7 +729,7 @@ fn project_type<'cx, 'tcx>(
     selcx: &mut SelectionContext<'cx, 'tcx>,
     obligation: &ProjectionTyObligation<'tcx>,
 ) -> Result<ProjectedTy<'tcx>, ProjectionTyError<'tcx>> {
-    debug!("project(obligation={:?})", obligation);
+    debug!(?obligation, "project_type");
 
     if !selcx.tcx().sess.recursion_limit().value_within_limit(obligation.recursion_depth) {
         debug!("project: overflow!");
@@ -787,7 +738,7 @@ fn project_type<'cx, 'tcx>(
 
     let obligation_trait_ref = &obligation.predicate.trait_ref(selcx.tcx());
 
-    debug!("project: obligation_trait_ref={:?}", obligation_trait_ref);
+    debug!(?obligation_trait_ref);
 
     if obligation_trait_ref.references_error() {
         return Ok(ProjectedTy::Progress(Progress::error(selcx.tcx())));
@@ -951,10 +902,11 @@ fn assemble_candidates_from_predicates<'cx, 'tcx>(
     env_predicates: impl Iterator<Item = ty::Predicate<'tcx>>,
     potentially_unnormalized_candidates: bool,
 ) {
-    debug!("assemble_candidates_from_predicates(obligation={:?})", obligation);
+    debug!(?obligation, "assemble_candidates_from_predicates");
+
     let infcx = selcx.infcx();
     for predicate in env_predicates {
-        debug!("assemble_candidates_from_predicates: predicate={:?}", predicate);
+        debug!(?predicate);
         if let ty::PredicateAtom::Projection(data) = predicate.skip_binders() {
             let data = ty::Binder::bind(data);
             let same_def_id = data.projection_def_id() == obligation.predicate.item_def_id;
@@ -969,11 +921,7 @@ fn assemble_candidates_from_predicates<'cx, 'tcx>(
                     )
                 });
 
-            debug!(
-                "assemble_candidates_from_predicates: candidate={:?} \
-                 is_match={} same_def_id={}",
-                data, is_match, same_def_id
-            );
+            debug!(?data, ?is_match, ?same_def_id);
 
             if is_match {
                 candidate_set.push_candidate(ctor(data));
@@ -997,6 +945,8 @@ fn assemble_candidates_from_impls<'cx, 'tcx>(
     obligation_trait_ref: &ty::TraitRef<'tcx>,
     candidate_set: &mut ProjectionTyCandidateSet<'tcx>,
 ) {
+    debug!("assemble_candidates_from_impls");
+
     // If we are resolving `<T as TraitRef<...>>::Item == Type`,
     // start out by selecting the predicate `T as TraitRef<...>`:
     let poly_trait_ref = obligation_trait_ref.to_poly_trait_ref();
@@ -1009,7 +959,7 @@ fn assemble_candidates_from_impls<'cx, 'tcx>(
                 return Err(());
             }
             Err(e) => {
-                debug!("assemble_candidates_from_impls: selection error {:?}", e);
+                debug!(error = ?e, "selection error");
                 candidate_set.mark_error(e);
                 return Err(());
             }
@@ -1020,7 +970,7 @@ fn assemble_candidates_from_impls<'cx, 'tcx>(
             | super::ImplSource::Generator(_)
             | super::ImplSource::FnPointer(_)
             | super::ImplSource::TraitAlias(_) => {
-                debug!("assemble_candidates_from_impls: impl_source={:?}", impl_source);
+                debug!(?impl_source);
                 true
             }
             super::ImplSource::UserDefined(impl_data) => {
@@ -1066,10 +1016,9 @@ fn assemble_candidates_from_impls<'cx, 'tcx>(
                         !poly_trait_ref.still_further_specializable()
                     } else {
                         debug!(
-                            "assemble_candidates_from_impls: not eligible due to default: \
-                             assoc_ty={} predicate={}",
-                            selcx.tcx().def_path_str(node_item.item.def_id),
-                            obligation.predicate,
+                            assoc_ty = ?selcx.tcx().def_path_str(node_item.item.def_id),
+                            ?obligation.predicate,
+                            "assemble_candidates_from_impls: not eligible due to default",
                         );
                         false
                     }
@@ -1176,8 +1125,7 @@ fn confirm_candidate<'cx, 'tcx>(
     obligation: &ProjectionTyObligation<'tcx>,
     candidate: ProjectionTyCandidate<'tcx>,
 ) -> Progress<'tcx> {
-    debug!("confirm_candidate(candidate={:?}, obligation={:?})", candidate, obligation);
-
+    debug!(?obligation, ?candidate, "confirm_candidate");
     let mut progress = match candidate {
         ProjectionTyCandidate::ParamEnv(poly_projection)
         | ProjectionTyCandidate::Object(poly_projection) => {
@@ -1220,9 +1168,8 @@ fn confirm_select_candidate<'cx, 'tcx>(
         | super::ImplSource::AutoImpl(..)
         | super::ImplSource::Param(..)
         | super::ImplSource::Builtin(..)
-        | super::ImplSource::TraitAlias(..) =>
-        // we don't create Select candidates with this kind of resolution
-        {
+        | super::ImplSource::TraitAlias(..) => {
+            // we don't create Select candidates with this kind of resolution
             span_bug!(
                 obligation.cause.span,
                 "Cannot project an associated type from `{:?}`",
@@ -1246,10 +1193,7 @@ fn confirm_generator_candidate<'cx, 'tcx>(
         &gen_sig,
     );
 
-    debug!(
-        "confirm_generator_candidate: obligation={:?},gen_sig={:?},obligations={:?}",
-        obligation, gen_sig, obligations
-    );
+    debug!(?obligation, ?gen_sig, ?obligations, "confirm_generator_candidate");
 
     let tcx = selcx.tcx();
 
@@ -1339,10 +1283,7 @@ fn confirm_closure_candidate<'cx, 'tcx>(
         &closure_sig,
     );
 
-    debug!(
-        "confirm_closure_candidate: obligation={:?},closure_sig={:?},obligations={:?}",
-        obligation, closure_sig, obligations
-    );
+    debug!(?obligation, ?closure_sig, ?obligations, "confirm_closure_candidate");
 
     confirm_callable_candidate(selcx, obligation, closure_sig, util::TupleArgumentsFlag::No)
         .with_addl_obligations(impl_source.nested)
@@ -1357,7 +1298,7 @@ fn confirm_callable_candidate<'cx, 'tcx>(
 ) -> Progress<'tcx> {
     let tcx = selcx.tcx();
 
-    debug!("confirm_callable_candidate({:?},{:?})", obligation, fn_sig);
+    debug!(?obligation, ?fn_sig, "confirm_callable_candidate");
 
     let fn_once_def_id = tcx.require_lang_item(LangItem::FnOnce, None);
     let fn_once_output_def_id = tcx.require_lang_item(LangItem::FnOnceOutput, None);
diff --git a/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs b/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs
index 038ba431c47..fdf1641c986 100644
--- a/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs
+++ b/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs
@@ -22,6 +22,7 @@ use super::SelectionCandidate::{self, *};
 use super::{EvaluatedCandidate, SelectionCandidateSet, SelectionContext, TraitObligationStack};
 
 impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
+    #[instrument(level = "debug", skip(self))]
     pub(super) fn candidate_from_obligation<'o>(
         &mut self,
         stack: &TraitObligationStack<'o, 'tcx>,
@@ -35,16 +36,13 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         // this is because we want the unbound variables to be
         // replaced with fresh types starting from index 0.
         let cache_fresh_trait_pred = self.infcx.freshen(stack.obligation.predicate);
-        debug!(
-            "candidate_from_obligation(cache_fresh_trait_pred={:?}, obligation={:?})",
-            cache_fresh_trait_pred, stack
-        );
+        debug!(?cache_fresh_trait_pred);
         debug_assert!(!stack.obligation.predicate.has_escaping_bound_vars());
 
         if let Some(c) =
             self.check_candidate_cache(stack.obligation.param_env, cache_fresh_trait_pred)
         {
-            debug!("CACHE HIT: SELECT({:?})={:?}", cache_fresh_trait_pred, c);
+            debug!(candidate = ?c, "CACHE HIT");
             return c;
         }
 
@@ -57,7 +55,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let (candidate, dep_node) =
             self.in_task(|this| this.candidate_from_obligation_no_cache(stack));
 
-        debug!("CACHE MISS: SELECT({:?})={:?}", cache_fresh_trait_pred, candidate);
+        debug!(?candidate, "CACHE MISS");
         self.insert_candidate_cache(
             stack.obligation.param_env,
             cache_fresh_trait_pred,
@@ -103,7 +101,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                         } else {
                             IntercrateAmbiguityCause::DownstreamCrate { trait_desc, self_desc }
                         };
-                        debug!("evaluate_stack: pushing cause = {:?}", cause);
+                        debug!(?cause, "evaluate_stack: pushing cause");
                         self.intercrate_ambiguity_causes.as_mut().unwrap().push(cause);
                     }
                 }
@@ -120,7 +118,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
 
         let mut candidates = candidate_set.vec;
 
-        debug!("assembled {} candidates for {:?}: {:?}", candidates.len(), stack, candidates);
+        debug!(?stack, ?candidates, "assembled {} candidates", candidates.len());
 
         // At this point, we know that each of the entries in the
         // candidate set is *individually* applicable. Now we have to
@@ -163,7 +161,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             .flat_map(Result::transpose)
             .collect::<Result<Vec<_>, _>>()?;
 
-        debug!("winnowed to {} candidates for {:?}: {:?}", candidates.len(), stack, candidates);
+        debug!(?stack, ?candidates, "winnowed to {} candidates", candidates.len());
 
         let needs_infer = stack.obligation.predicate.has_infer_types_or_consts();
 
@@ -181,10 +179,10 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                     )
                 });
                 if is_dup {
-                    debug!("Dropping candidate #{}/{}: {:?}", i, candidates.len(), candidates[i]);
+                    debug!(candidate = ?candidates[i], "Dropping candidate #{}/{}", i, candidates.len());
                     candidates.swap_remove(i);
                 } else {
-                    debug!("Retaining candidate #{}/{}: {:?}", i, candidates.len(), candidates[i]);
+                    debug!(candidate = ?candidates[i], "Retaining candidate #{}/{}", i, candidates.len());
                     i += 1;
 
                     // If there are *STILL* multiple candidates, give up
@@ -257,7 +255,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let lang_items = self.tcx().lang_items();
 
         if lang_items.copy_trait() == Some(def_id) {
-            debug!("obligation self ty is {:?}", obligation.predicate.skip_binder().self_ty());
+            debug!(obligation_self_ty = ?obligation.predicate.skip_binder().self_ty());
 
             // User-defined copy impls are permitted, but only for
             // structs and enums.
@@ -308,7 +306,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         candidates: &mut SelectionCandidateSet<'tcx>,
     ) {
-        debug!("assemble_candidates_for_projected_tys({:?})", obligation);
+        debug!(?obligation, "assemble_candidates_from_projected_tys");
 
         // Before we go into the whole placeholder thing, just
         // quickly check if the self-type is a projection at all.
@@ -341,7 +339,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         stack: &TraitObligationStack<'o, 'tcx>,
         candidates: &mut SelectionCandidateSet<'tcx>,
     ) -> Result<(), SelectionError<'tcx>> {
-        debug!("assemble_candidates_from_caller_bounds({:?})", stack.obligation);
+        debug!(?stack.obligation, "assemble_candidates_from_caller_bounds");
 
         let all_bounds = stack
             .obligation
@@ -383,10 +381,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let self_ty = obligation.self_ty().skip_binder();
         match self_ty.kind() {
             ty::Generator(..) => {
-                debug!(
-                    "assemble_generator_candidates: self_ty={:?} obligation={:?}",
-                    self_ty, obligation
-                );
+                debug!(?self_ty, ?obligation, "assemble_generator_candidates",);
 
                 candidates.vec.push(GeneratorCandidate);
             }
@@ -423,10 +418,10 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         // type/region parameters
         match *obligation.self_ty().skip_binder().kind() {
             ty::Closure(_, closure_substs) => {
-                debug!("assemble_unboxed_candidates: kind={:?} obligation={:?}", kind, obligation);
+                debug!(?kind, ?obligation, "assemble_unboxed_candidates");
                 match self.infcx.closure_kind(closure_substs) {
                     Some(closure_kind) => {
-                        debug!("assemble_unboxed_candidates: closure_kind = {:?}", closure_kind);
+                        debug!(?closure_kind, "assemble_unboxed_candidates");
                         if closure_kind.extends(kind) {
                             candidates.vec.push(ClosureCandidate);
                         }
@@ -503,7 +498,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         candidates: &mut SelectionCandidateSet<'tcx>,
     ) -> Result<(), SelectionError<'tcx>> {
-        debug!("assemble_candidates_from_impls(obligation={:?})", obligation);
+        debug!(?obligation, "assemble_candidates_from_impls");
 
         // Essentially any user-written impl will match with an error type,
         // so creating `ImplCandidates` isn't useful. However, we might
@@ -537,7 +532,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
     ) -> Result<(), SelectionError<'tcx>> {
         // Okay to skip binder here because the tests we do below do not involve bound regions.
         let self_ty = obligation.self_ty().skip_binder();
-        debug!("assemble_candidates_from_auto_impls(self_ty={:?})", self_ty);
+        debug!(?self_ty, "assemble_candidates_from_auto_impls");
 
         let def_id = obligation.predicate.def_id();
 
@@ -604,8 +599,8 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         candidates: &mut SelectionCandidateSet<'tcx>,
     ) {
         debug!(
-            "assemble_candidates_from_object_ty(self_ty={:?})",
-            obligation.self_ty().skip_binder()
+            self_ty = ?obligation.self_ty().skip_binder(),
+            "assemble_candidates_from_object_ty",
         );
 
         self.infcx.probe(|_snapshot| {
@@ -645,7 +640,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 _ => return,
             };
 
-            debug!("assemble_candidates_from_object_ty: poly_trait_ref={:?}", poly_trait_ref);
+            debug!(?poly_trait_ref, "assemble_candidates_from_object_ty");
 
             // Count only those upcast versions that match the trait-ref
             // we are looking for. Specifically, do not only check for the
@@ -697,7 +692,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         };
         let target = obligation.predicate.skip_binder().trait_ref.substs.type_at(1);
 
-        debug!("assemble_candidates_for_unsizing(source={:?}, target={:?})", source, target);
+        debug!(?source, ?target, "assemble_candidates_for_unsizing");
 
         let may_apply = match (source.kind(), target.kind()) {
             // Trait+Kx+'a -> Trait+Ky+'b (upcasts).
@@ -758,7 +753,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
     ) -> Result<(), SelectionError<'tcx>> {
         // Okay to skip binder here because the tests we do below do not involve bound regions.
         let self_ty = obligation.self_ty().skip_binder();
-        debug!("assemble_candidates_for_trait_alias(self_ty={:?})", self_ty);
+        debug!(?self_ty, "assemble_candidates_for_trait_alias");
 
         let def_id = obligation.predicate.def_id();
 
@@ -778,7 +773,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
     ) -> Result<(), SelectionError<'tcx>> {
         match conditions {
             BuiltinImplConditions::Where(nested) => {
-                debug!("builtin_bound: nested={:?}", nested);
+                debug!(?nested, "builtin_bound");
                 candidates
                     .vec
                     .push(BuiltinCandidate { has_nested: !nested.skip_binder().is_empty() });
diff --git a/compiler/rustc_trait_selection/src/traits/select/confirmation.rs b/compiler/rustc_trait_selection/src/traits/select/confirmation.rs
index 96f0bedf6f1..37d619d5942 100644
--- a/compiler/rustc_trait_selection/src/traits/select/confirmation.rs
+++ b/compiler/rustc_trait_selection/src/traits/select/confirmation.rs
@@ -42,13 +42,12 @@ use super::SelectionContext;
 use std::iter;
 
 impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
+    #[instrument(level = "debug", skip(self))]
     pub(super) fn confirm_candidate(
         &mut self,
         obligation: &TraitObligation<'tcx>,
         candidate: SelectionCandidate<'tcx>,
     ) -> Result<Selection<'tcx>, SelectionError<'tcx>> {
-        debug!("confirm_candidate({:?}, {:?})", obligation, candidate);
-
         match candidate {
             BuiltinCandidate { has_nested } => {
                 let data = self.confirm_builtin_candidate(obligation, has_nested);
@@ -191,7 +190,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         param: ty::PolyTraitRef<'tcx>,
     ) -> Vec<PredicateObligation<'tcx>> {
-        debug!("confirm_param_candidate({:?},{:?})", obligation, param);
+        debug!(?obligation, ?param, "confirm_param_candidate");
 
         // During evaluation, we already checked that this
         // where-clause trait-ref could be unified with the obligation
@@ -214,7 +213,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         has_nested: bool,
     ) -> ImplSourceBuiltinData<PredicateObligation<'tcx>> {
-        debug!("confirm_builtin_candidate({:?}, {:?})", obligation, has_nested);
+        debug!(?obligation, ?has_nested, "confirm_builtin_candidate");
 
         let lang_items = self.tcx().lang_items();
         let obligations = if has_nested {
@@ -247,7 +246,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             vec![]
         };
 
-        debug!("confirm_builtin_candidate: obligations={:?}", obligations);
+        debug!(?obligations);
 
         ImplSourceBuiltinData { nested: obligations }
     }
@@ -262,7 +261,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         trait_def_id: DefId,
     ) -> ImplSourceAutoImplData<PredicateObligation<'tcx>> {
-        debug!("confirm_auto_impl_candidate({:?}, {:?})", obligation, trait_def_id);
+        debug!(?obligation, ?trait_def_id, "confirm_auto_impl_candidate");
 
         let types = obligation.predicate.map_bound(|inner| {
             let self_ty = self.infcx.shallow_resolve(inner.self_ty());
@@ -278,7 +277,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         trait_def_id: DefId,
         nested: ty::Binder<Vec<Ty<'tcx>>>,
     ) -> ImplSourceAutoImplData<PredicateObligation<'tcx>> {
-        debug!("vtable_auto_impl: nested={:?}", nested);
+        debug!(?nested, "vtable_auto_impl");
         ensure_sufficient_stack(|| {
             let cause = obligation.derived_cause(BuiltinDerivedObligation);
             let mut obligations = self.collect_predicates_for_types(
@@ -308,7 +307,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             // predicate as usual.  It won't have any effect since auto traits are coinductive.
             obligations.extend(trait_obligations);
 
-            debug!("vtable_auto_impl: obligations={:?}", obligations);
+            debug!(?obligations, "vtable_auto_impl");
 
             ImplSourceAutoImplData { trait_def_id, nested: obligations }
         })
@@ -319,13 +318,13 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         impl_def_id: DefId,
     ) -> ImplSourceUserDefinedData<'tcx, PredicateObligation<'tcx>> {
-        debug!("confirm_impl_candidate({:?},{:?})", obligation, impl_def_id);
+        debug!(?obligation, ?impl_def_id, "confirm_impl_candidate");
 
         // First, create the substitutions by matching the impl again,
         // this time not in a probe.
         self.infcx.commit_unconditionally(|_| {
             let substs = self.rematch_impl(impl_def_id, obligation);
-            debug!("confirm_impl_candidate: substs={:?}", substs);
+            debug!(?substs, "impl substs");
             let cause = obligation.derived_cause(ImplDerivedObligation);
             ensure_sufficient_stack(|| {
                 self.vtable_impl(
@@ -347,10 +346,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         recursion_depth: usize,
         param_env: ty::ParamEnv<'tcx>,
     ) -> ImplSourceUserDefinedData<'tcx, PredicateObligation<'tcx>> {
-        debug!(
-            "vtable_impl(impl_def_id={:?}, substs={:?}, recursion_depth={})",
-            impl_def_id, substs, recursion_depth,
-        );
+        debug!(?impl_def_id, ?substs, ?recursion_depth, "vtable_impl");
 
         let mut impl_obligations = self.impl_or_trait_obligations(
             cause,
@@ -360,10 +356,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             &substs.value,
         );
 
-        debug!(
-            "vtable_impl: impl_def_id={:?} impl_obligations={:?}",
-            impl_def_id, impl_obligations
-        );
+        debug!(?impl_obligations, "vtable_impl");
 
         // Because of RFC447, the impl-trait-ref and obligations
         // are sufficient to determine the impl substs, without
@@ -379,8 +372,8 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         &mut self,
         obligation: &TraitObligation<'tcx>,
     ) -> ImplSourceObjectData<'tcx, PredicateObligation<'tcx>> {
+        debug!(?obligation, "confirm_object_candidate");
         let tcx = self.tcx();
-        debug!("confirm_object_candidate({:?})", obligation);
 
         let trait_predicate =
             self.infcx.replace_bound_vars_with_placeholders(&obligation.predicate);
@@ -507,7 +500,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             }
         }
 
-        debug!("confirm_object_candidate: nested: {:?}", nested);
+        debug!(?nested, "object nested obligations");
         ImplSourceObjectData { upcast_trait_ref, vtable_base, nested }
     }
 
@@ -516,7 +509,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
     ) -> Result<ImplSourceFnPointerData<'tcx, PredicateObligation<'tcx>>, SelectionError<'tcx>>
     {
-        debug!("confirm_fn_pointer_candidate({:?})", obligation);
+        debug!(?obligation, "confirm_fn_pointer_candidate");
 
         // Okay to skip binder; it is reintroduced below.
         let self_ty = self.infcx.shallow_resolve(obligation.self_ty().skip_binder());
@@ -554,7 +547,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         alias_def_id: DefId,
     ) -> ImplSourceTraitAliasData<'tcx, PredicateObligation<'tcx>> {
-        debug!("confirm_trait_alias_candidate({:?}, {:?})", obligation, alias_def_id);
+        debug!(?obligation, ?alias_def_id, "confirm_trait_alias_candidate");
 
         self.infcx.commit_unconditionally(|_| {
             let predicate =
@@ -571,10 +564,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 &substs,
             );
 
-            debug!(
-                "confirm_trait_alias_candidate: trait_def_id={:?} trait_obligations={:?}",
-                trait_def_id, trait_obligations
-            );
+            debug!(?trait_def_id, ?trait_obligations, "trait alias obligations");
 
             ImplSourceTraitAliasData { alias_def_id, substs, nested: trait_obligations }
         })
@@ -594,7 +584,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             _ => bug!("closure candidate for non-closure {:?}", obligation),
         };
 
-        debug!("confirm_generator_candidate({:?},{:?},{:?})", obligation, generator_def_id, substs);
+        debug!(?obligation, ?generator_def_id, ?substs, "confirm_generator_candidate");
 
         let trait_ref = self.generator_trait_ref_unnormalized(obligation, substs);
         let Normalized { value: trait_ref, mut obligations } = ensure_sufficient_stack(|| {
@@ -607,11 +597,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             )
         });
 
-        debug!(
-            "confirm_generator_candidate(generator_def_id={:?}, \
-             trait_ref={:?}, obligations={:?})",
-            generator_def_id, trait_ref, obligations
-        );
+        debug!(?trait_ref, ?obligations, "generator candidate obligations");
 
         obligations.extend(self.confirm_poly_trait_refs(
             obligation.cause.clone(),
@@ -627,7 +613,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         &mut self,
         obligation: &TraitObligation<'tcx>,
     ) -> Result<ImplSourceClosureData<'tcx, PredicateObligation<'tcx>>, SelectionError<'tcx>> {
-        debug!("confirm_closure_candidate({:?})", obligation);
+        debug!(?obligation, "confirm_closure_candidate");
 
         let kind = self
             .tcx()
@@ -654,10 +640,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             )
         });
 
-        debug!(
-            "confirm_closure_candidate(closure_def_id={:?}, trait_ref={:?}, obligations={:?})",
-            closure_def_id, trait_ref, obligations
-        );
+        debug!(?closure_def_id, ?trait_ref, ?obligations, "confirm closure candidate obligations");
 
         obligations.extend(self.confirm_poly_trait_refs(
             obligation.cause.clone(),
@@ -731,7 +714,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let target = obligation.predicate.skip_binder().trait_ref.substs.type_at(1);
         let target = self.infcx.shallow_resolve(target);
 
-        debug!("confirm_builtin_unsize_candidate(source={:?}, target={:?})", source, target);
+        debug!(?source, ?target, "confirm_builtin_unsize_candidate");
 
         let mut nested = vec![];
         match (source.kind(), target.kind()) {
diff --git a/compiler/rustc_trait_selection/src/traits/select/mod.rs b/compiler/rustc_trait_selection/src/traits/select/mod.rs
index a142ba58a69..57b680b0e53 100644
--- a/compiler/rustc_trait_selection/src/traits/select/mod.rs
+++ b/compiler/rustc_trait_selection/src/traits/select/mod.rs
@@ -236,7 +236,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         infcx: &'cx InferCtxt<'cx, 'tcx>,
         allow_negative_impls: bool,
     ) -> SelectionContext<'cx, 'tcx> {
-        debug!("with_negative({:?})", allow_negative_impls);
+        debug!(?allow_negative_impls, "with_negative");
         SelectionContext {
             infcx,
             freshener: infcx.freshener(),
@@ -251,7 +251,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         infcx: &'cx InferCtxt<'cx, 'tcx>,
         query_mode: TraitQueryMode,
     ) -> SelectionContext<'cx, 'tcx> {
-        debug!("with_query_mode({:?})", query_mode);
+        debug!(?query_mode, "with_query_mode");
         SelectionContext {
             infcx,
             freshener: infcx.freshener(),
@@ -311,11 +311,11 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
 
     /// Attempts to satisfy the obligation. If successful, this will affect the surrounding
     /// type environment by performing unification.
+    #[instrument(level = "debug", skip(self))]
     pub fn select(
         &mut self,
         obligation: &TraitObligation<'tcx>,
     ) -> SelectionResult<'tcx, Selection<'tcx>> {
-        debug!("select({:?})", obligation);
         debug_assert!(!obligation.predicate.has_escaping_bound_vars());
 
         let pec = &ProvisionalEvaluationCache::default();
@@ -344,7 +344,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             }
             Err(e) => Err(e),
             Ok(candidate) => {
-                debug!("select: candidate = {:?}", candidate);
+                debug!(?candidate);
                 Ok(Some(candidate))
             }
         }
@@ -362,7 +362,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
 
     /// Evaluates whether the obligation `obligation` can be satisfied (by any means).
     pub fn predicate_may_hold_fatal(&mut self, obligation: &PredicateObligation<'tcx>) -> bool {
-        debug!("predicate_may_hold_fatal({:?})", obligation);
+        debug!(?obligation, "predicate_may_hold_fatal");
 
         // This fatal query is a stopgap that should only be used in standard mode,
         // where we do not expect overflow to be propagated.
@@ -419,10 +419,9 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         I: IntoIterator<Item = PredicateObligation<'tcx>> + std::fmt::Debug,
     {
         let mut result = EvaluatedToOk;
-        debug!("evaluate_predicates_recursively({:?})", predicates);
+        debug!(?predicates, "evaluate_predicates_recursively");
         for obligation in predicates {
             let eval = self.evaluate_predicate_recursively(stack, obligation.clone())?;
-            debug!("evaluate_predicate_recursively({:?}) = {:?}", obligation, eval);
             if let EvaluatedToErr = eval {
                 // fast-path - EvaluatedToErr is the top of the lattice,
                 // so we don't need to look on the other predicates.
@@ -434,17 +433,16 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         Ok(result)
     }
 
+    #[instrument(
+        level = "debug",
+        skip(self, previous_stack),
+        fields(previous_stack = ?previous_stack.head())
+    )]
     fn evaluate_predicate_recursively<'o>(
         &mut self,
         previous_stack: TraitObligationStackList<'o, 'tcx>,
         obligation: PredicateObligation<'tcx>,
     ) -> Result<EvaluationResult, OverflowError> {
-        debug!(
-            "evaluate_predicate_recursively(obligation={:?}, previous_stack={:?})",
-            obligation,
-            previous_stack.head()
-        );
-
         // `previous_stack` stores a `TraitObligation`, while `obligation` is
         // a `PredicateObligation`. These are distinct types, so we can't
         // use any `Option` combinator method that would force them to be
@@ -454,7 +452,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             None => self.check_recursion_limit(&obligation, &obligation)?,
         }
 
-        ensure_sufficient_stack(|| {
+        let result = ensure_sufficient_stack(|| {
             match obligation.predicate.skip_binders() {
                 ty::PredicateAtom::Trait(t, _) => {
                     let t = ty::Binder::bind(t);
@@ -561,10 +559,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 }
 
                 ty::PredicateAtom::ConstEquate(c1, c2) => {
-                    debug!(
-                        "evaluate_predicate_recursively: equating consts c1={:?} c2={:?}",
-                        c1, c2
-                    );
+                    debug!(?c1, ?c2, "evaluate_predicate_recursively: equating consts");
 
                     let evaluate = |c: &'tcx ty::Const<'tcx>| {
                         if let ty::ConstKind::Unevaluated(def, substs, promoted) = c.val {
@@ -610,7 +605,11 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                     bug!("TypeWellFormedFromEnv is only used for chalk")
                 }
             }
-        })
+        });
+
+        debug!(?result);
+
+        result
     }
 
     fn evaluate_trait_predicate_recursively<'o>(
@@ -618,7 +617,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         previous_stack: TraitObligationStackList<'o, 'tcx>,
         mut obligation: TraitObligation<'tcx>,
     ) -> Result<EvaluationResult, OverflowError> {
-        debug!("evaluate_trait_predicate_recursively({:?})", obligation);
+        debug!(?obligation, "evaluate_trait_predicate_recursively");
 
         if !self.intercrate
             && obligation.is_global()
@@ -627,19 +626,22 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             // If a param env has no global bounds, global obligations do not
             // depend on its particular value in order to work, so we can clear
             // out the param env and get better caching.
-            debug!("evaluate_trait_predicate_recursively({:?}) - in global", obligation);
+            debug!("evaluate_trait_predicate_recursively - in global");
             obligation.param_env = obligation.param_env.without_caller_bounds();
         }
 
         let stack = self.push_stack(previous_stack, &obligation);
         let fresh_trait_ref = stack.fresh_trait_ref;
+
+        debug!(?fresh_trait_ref);
+
         if let Some(result) = self.check_evaluation_cache(obligation.param_env, fresh_trait_ref) {
-            debug!("CACHE HIT: EVAL({:?})={:?}", fresh_trait_ref, result);
+            debug!(?result, "CACHE HIT");
             return Ok(result);
         }
 
         if let Some(result) = stack.cache().get_provisional(fresh_trait_ref) {
-            debug!("PROVISIONAL CACHE HIT: EVAL({:?})={:?}", fresh_trait_ref, result);
+            debug!(?result, "PROVISIONAL CACHE HIT");
             stack.update_reached_depth(stack.cache().current_reached_depth());
             return Ok(result);
         }
@@ -662,7 +664,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
 
         let reached_depth = stack.reached_depth.get();
         if reached_depth >= stack.depth {
-            debug!("CACHE MISS: EVAL({:?})={:?}", fresh_trait_ref, result);
+            debug!(?result, "CACHE MISS");
             self.insert_evaluation_cache(obligation.param_env, fresh_trait_ref, dep_node, result);
 
             stack.cache().on_completion(stack.depth, |fresh_trait_ref, provisional_result| {
@@ -674,7 +676,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 );
             });
         } else {
-            debug!("PROVISIONAL: {:?}={:?}", fresh_trait_ref, result);
+            debug!(?result, "PROVISIONAL");
             debug!(
                 "evaluate_trait_predicate_recursively: caching provisionally because {:?} \
                  is a cycle participant (at depth {}, reached depth {})",
@@ -719,10 +721,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             })
             .map(|stack| stack.depth)
         {
-            debug!(
-                "evaluate_stack({:?}) --> recursive at depth {}",
-                stack.fresh_trait_ref, cycle_depth,
-            );
+            debug!("evaluate_stack --> recursive at depth {}", cycle_depth);
 
             // If we have a stack like `A B C D E A`, where the top of
             // the stack is the final `A`, then this will iterate over
@@ -742,10 +741,10 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             let cycle =
                 cycle.map(|stack| stack.obligation.predicate.without_const().to_predicate(tcx));
             if self.coinductive_match(cycle) {
-                debug!("evaluate_stack({:?}) --> recursive, coinductive", stack.fresh_trait_ref);
+                debug!("evaluate_stack --> recursive, coinductive");
                 Some(EvaluatedToOk)
             } else {
-                debug!("evaluate_stack({:?}) --> recursive, inductive", stack.fresh_trait_ref);
+                debug!("evaluate_stack --> recursive, inductive");
                 Some(EvaluatedToRecur)
             }
         } else {
@@ -786,10 +785,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         // This check was an imperfect workaround for a bug in the old
         // intercrate mode; it should be removed when that goes away.
         if unbound_input_types && self.intercrate {
-            debug!(
-                "evaluate_stack({:?}) --> unbound argument, intercrate -->  ambiguous",
-                stack.fresh_trait_ref
-            );
+            debug!("evaluate_stack --> unbound argument, intercrate -->  ambiguous",);
             // Heuristics: show the diagnostics when there are no candidates in crate.
             if self.intercrate_ambiguity_causes.is_some() {
                 debug!("evaluate_stack: intercrate_ambiguity_causes is some");
@@ -807,7 +803,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                                 },
                             });
 
-                        debug!("evaluate_stack: pushing cause = {:?}", cause);
+                        debug!(?cause, "evaluate_stack: pushing cause");
                         self.intercrate_ambiguity_causes.as_mut().unwrap().push(cause);
                     }
                 }
@@ -824,10 +820,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                     )
             })
         {
-            debug!(
-                "evaluate_stack({:?}) --> unbound argument, recursive --> giving up",
-                stack.fresh_trait_ref
-            );
+            debug!("evaluate_stack --> unbound argument, recursive --> giving up",);
             return Ok(EvaluatedToUnknown);
         }
 
@@ -860,27 +853,28 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             ty::PredicateAtom::Trait(ref data, _) => self.tcx().trait_is_auto(data.def_id()),
             _ => false,
         };
-        debug!("coinductive_predicate({:?}) = {:?}", predicate, result);
+        debug!(?predicate, ?result, "coinductive_predicate");
         result
     }
 
     /// Further evaluates `candidate` to decide whether all type parameters match and whether nested
     /// obligations are met. Returns whether `candidate` remains viable after this further
     /// scrutiny.
+    #[instrument(
+        level = "debug",
+        skip(self, stack),
+        fields(depth = stack.obligation.recursion_depth)
+    )]
     fn evaluate_candidate<'o>(
         &mut self,
         stack: &TraitObligationStack<'o, 'tcx>,
         candidate: &SelectionCandidate<'tcx>,
     ) -> Result<EvaluationResult, OverflowError> {
-        debug!(
-            "evaluate_candidate: depth={} candidate={:?}",
-            stack.obligation.recursion_depth, candidate
-        );
         let result = self.evaluation_probe(|this| {
             let candidate = (*candidate).clone();
             match this.confirm_candidate(stack.obligation, candidate) {
                 Ok(selection) => {
-                    debug!("evaluate_candidate: selection = {:?}", selection);
+                    debug!(?selection);
                     this.evaluate_predicates_recursively(
                         stack.list(),
                         selection.nested_obligations().into_iter(),
@@ -889,10 +883,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 Err(..) => Ok(EvaluatedToErr),
             }
         })?;
-        debug!(
-            "evaluate_candidate: depth={} result={:?}",
-            stack.obligation.recursion_depth, result
-        );
+        debug!(?result);
         Ok(result)
     }
 
@@ -925,10 +916,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
 
         if self.can_use_global_caches(param_env) {
             if !trait_ref.needs_infer() {
-                debug!(
-                    "insert_evaluation_cache(trait_ref={:?}, candidate={:?}) global",
-                    trait_ref, result,
-                );
+                debug!(?trait_ref, ?result, "insert_evaluation_cache global");
                 // This may overwrite the cache with the same value
                 // FIXME: Due to #50507 this overwrites the different values
                 // This should be changed to use HashMapExt::insert_same
@@ -938,7 +926,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             }
         }
 
-        debug!("insert_evaluation_cache(trait_ref={:?}, candidate={:?})", trait_ref, result,);
+        debug!(?trait_ref, ?result, "insert_evaluation_cache");
         self.infcx.evaluation_cache.insert(param_env.and(trait_ref), dep_node, result);
     }
 
@@ -1127,11 +1115,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let trait_ref = cache_fresh_trait_pred.skip_binder().trait_ref;
 
         if !self.can_cache_candidate(&candidate) {
-            debug!(
-                "insert_candidate_cache(trait_ref={:?}, candidate={:?} -\
-                 candidate is not cacheable",
-                trait_ref, candidate
-            );
+            debug!(?trait_ref, ?candidate, "insert_candidate_cache - candidate is not cacheable");
             return;
         }
 
@@ -1140,10 +1124,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 // Don't cache overflow globally; we only produce this in certain modes.
             } else if !trait_ref.needs_infer() {
                 if !candidate.needs_infer() {
-                    debug!(
-                        "insert_candidate_cache(trait_ref={:?}, candidate={:?}) global",
-                        trait_ref, candidate,
-                    );
+                    debug!(?trait_ref, ?candidate, "insert_candidate_cache global");
                     // This may overwrite the cache with the same value.
                     tcx.selection_cache.insert(param_env.and(trait_ref), dep_node, candidate);
                     return;
@@ -1151,10 +1132,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             }
         }
 
-        debug!(
-            "insert_candidate_cache(trait_ref={:?}, candidate={:?}) local",
-            trait_ref, candidate,
-        );
+        debug!(?trait_ref, ?candidate, "insert_candidate_cache local");
         self.infcx.selection_cache.insert(param_env.and(trait_ref), dep_node, candidate);
     }
 
@@ -1172,9 +1150,8 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         let placeholder_trait_predicate =
             self.infcx().replace_bound_vars_with_placeholders(&poly_trait_predicate);
         debug!(
-            "match_projection_obligation_against_definition_bounds: \
-             placeholder_trait_predicate={:?}",
-            placeholder_trait_predicate,
+            ?placeholder_trait_predicate,
+            "match_projection_obligation_against_definition_bounds"
         );
 
         let tcx = self.infcx.tcx;
@@ -1225,11 +1202,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             })
             .collect();
 
-        debug!(
-            "match_projection_obligation_against_definition_bounds: \
-             matching_bounds={:?}",
-            matching_bounds
-        );
+        debug!(?matching_bounds, "match_projection_obligation_against_definition_bounds");
         matching_bounds
     }
 
@@ -1816,6 +1789,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         impl_def_id: DefId,
         obligation: &TraitObligation<'tcx>,
     ) -> Result<Normalized<'tcx, SubstsRef<'tcx>>, ()> {
+        debug!(?impl_def_id, ?obligation, "match_impl");
         let impl_trait_ref = self.tcx().impl_trait_ref(impl_def_id).unwrap();
 
         // Before we create the substitutions and everything, first
@@ -1844,11 +1818,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
                 )
             });
 
-        debug!(
-            "match_impl(impl_def_id={:?}, obligation={:?}, \
-             impl_trait_ref={:?}, placeholder_obligation_trait_ref={:?})",
-            impl_def_id, obligation, impl_trait_ref, placeholder_obligation_trait_ref
-        );
+        debug!(?impl_trait_ref, ?placeholder_obligation_trait_ref);
 
         let InferOk { obligations, .. } = self
             .infcx
@@ -1864,7 +1834,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
             return Err(());
         }
 
-        debug!("match_impl: success impl_substs={:?}", impl_substs);
+        debug!(?impl_substs, "match_impl: success");
         Ok(Normalized { value: impl_substs, obligations: nested_obligations })
     }
 
@@ -1926,10 +1896,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         poly_trait_ref: ty::PolyTraitRef<'tcx>,
     ) -> Result<Vec<PredicateObligation<'tcx>>, ()> {
-        debug!(
-            "match_poly_trait_ref: obligation={:?} poly_trait_ref={:?}",
-            obligation, poly_trait_ref
-        );
+        debug!(?obligation, ?poly_trait_ref, "match_poly_trait_ref");
 
         self.infcx
             .at(&obligation.cause, obligation.param_env)
@@ -1976,10 +1943,10 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         obligation: &TraitObligation<'tcx>,
         substs: SubstsRef<'tcx>,
     ) -> ty::PolyTraitRef<'tcx> {
-        debug!("closure_trait_ref_unnormalized(obligation={:?}, substs={:?})", obligation, substs);
+        debug!(?obligation, ?substs, "closure_trait_ref_unnormalized");
         let closure_sig = substs.as_closure().sig();
 
-        debug!("closure_trait_ref_unnormalized: closure_sig = {:?}", closure_sig);
+        debug!(?closure_sig);
 
         // (1) Feels icky to skip the binder here, but OTOH we know
         // that the self-type is an unboxed closure type and hence is
@@ -2030,7 +1997,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> {
         def_id: DefId,           // of impl or trait
         substs: SubstsRef<'tcx>, // for impl or trait
     ) -> Vec<PredicateObligation<'tcx>> {
-        debug!("impl_or_trait_obligations(def_id={:?})", def_id);
+        debug!(?def_id, "impl_or_trait_obligations");
         let tcx = self.tcx();
 
         // To allow for one-pass evaluation of the nested obligation,
@@ -2152,10 +2119,10 @@ impl<'o, 'tcx> TraitObligationStack<'o, 'tcx> {
             self.depth,
             reached_depth,
         );
-        debug!("update_reached_depth(reached_depth={})", reached_depth);
+        debug!(reached_depth, "update_reached_depth");
         let mut p = self;
         while reached_depth < p.depth {
-            debug!("update_reached_depth: marking {:?} as cycle participant", p.fresh_trait_ref);
+            debug!(?p.fresh_trait_ref, "update_reached_depth: marking as cycle participant");
             p.reached_depth.set(p.reached_depth.get().min(reached_depth));
             p = p.previous.head.unwrap();
         }
@@ -2282,10 +2249,10 @@ impl<'tcx> ProvisionalEvaluationCache<'tcx> {
     /// `self.current_reached_depth()` and above.
     fn get_provisional(&self, fresh_trait_ref: ty::PolyTraitRef<'tcx>) -> Option<EvaluationResult> {
         debug!(
-            "get_provisional(fresh_trait_ref={:?}) = {:#?} with reached-depth {}",
-            fresh_trait_ref,
+            ?fresh_trait_ref,
+            reached_depth = ?self.reached_depth.get(),
+            "get_provisional = {:#?}",
             self.map.borrow().get(&fresh_trait_ref),
-            self.reached_depth.get(),
         );
         Some(self.map.borrow().get(&fresh_trait_ref)?.result)
     }
@@ -2308,14 +2275,11 @@ impl<'tcx> ProvisionalEvaluationCache<'tcx> {
         fresh_trait_ref: ty::PolyTraitRef<'tcx>,
         result: EvaluationResult,
     ) {
-        debug!(
-            "insert_provisional(from_dfn={}, reached_depth={}, fresh_trait_ref={:?}, result={:?})",
-            from_dfn, reached_depth, fresh_trait_ref, result,
-        );
+        debug!(?from_dfn, ?reached_depth, ?fresh_trait_ref, ?result, "insert_provisional");
         let r_d = self.reached_depth.get();
         self.reached_depth.set(r_d.min(reached_depth));
 
-        debug!("insert_provisional: reached_depth={:?}", self.reached_depth.get());
+        debug!(reached_depth = self.reached_depth.get());
 
         self.map.borrow_mut().insert(fresh_trait_ref, ProvisionalEvaluation { from_dfn, result });
     }
@@ -2329,7 +2293,7 @@ impl<'tcx> ProvisionalEvaluationCache<'tcx> {
     /// these provisional entries must either depend on it or some
     /// ancestor of it.
     fn on_failure(&self, dfn: usize) {
-        debug!("on_failure(dfn={:?})", dfn,);
+        debug!(?dfn, "on_failure");
         self.map.borrow_mut().retain(|key, eval| {
             if !eval.from_dfn >= dfn {
                 debug!("on_failure: removing {:?}", key);
@@ -2350,7 +2314,7 @@ impl<'tcx> ProvisionalEvaluationCache<'tcx> {
         depth: usize,
         mut op: impl FnMut(ty::PolyTraitRef<'tcx>, EvaluationResult),
     ) {
-        debug!("on_completion(depth={}, reached_depth={})", depth, self.reached_depth.get(),);
+        debug!(?depth, reached_depth = ?self.reached_depth.get(), "on_completion");
 
         if self.reached_depth.get() < depth {
             debug!("on_completion: did not yet reach depth to complete");
@@ -2358,7 +2322,7 @@ impl<'tcx> ProvisionalEvaluationCache<'tcx> {
         }
 
         for (fresh_trait_ref, eval) in self.map.borrow_mut().drain() {
-            debug!("on_completion: fresh_trait_ref={:?} eval={:?}", fresh_trait_ref, eval,);
+            debug!(?fresh_trait_ref, ?eval, "on_completion");
 
             op(fresh_trait_ref, eval.result);
         }