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`

Author: bors

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,26 +615,20 @@ 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![]);
             }
         }
 
         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))
             }