Add some tracing instrumentation

Author: oli-obk

compiler/rustc_mir_build/src/build/expr/as_temp.rs

@@ -23,17 +23,14 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         ensure_sufficient_stack(|| self.as_temp_inner(block, temp_lifetime, expr, mutability))
     }
 
+    #[instrument(skip(self), level = "debug")]
     fn as_temp_inner(
         &mut self,
         mut block: BasicBlock,
         temp_lifetime: Option<region::Scope>,
         expr: &Expr<'tcx>,
         mutability: Mutability,
     ) -> BlockAnd<Local> {
-        debug!(
-            "as_temp(block={:?}, temp_lifetime={:?}, expr={:?}, mutability={:?})",
-            block, temp_lifetime, expr, mutability
-        );
         let this = self;
 
         let expr_span = expr.span;

compiler/rustc_mir_build/src/build/expr/into.rs

@@ -15,14 +15,13 @@ use std::iter;
 impl<'a, 'tcx> Builder<'a, 'tcx> {
     /// Compile `expr`, storing the result into `destination`, which
     /// is assumed to be uninitialized.
+    #[instrument(level = "debug", skip(self))]
     pub(crate) fn expr_into_dest(
         &mut self,
         destination: Place<'tcx>,
         mut block: BasicBlock,
         expr: &Expr<'tcx>,
     ) -> BlockAnd<()> {
-        debug!("expr_into_dest(destination={:?}, block={:?}, expr={:?})", destination, block, expr);
-
         // since we frequently have to reference `self` from within a
         // closure, where `self` would be shadowed, it's easier to
         // just use the name `this` uniformly

compiler/rustc_mir_build/src/build/matches/mod.rs

@@ -654,6 +654,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
     /// scope for the bindings in these patterns, if such a scope had to be
     /// created. NOTE: Declaring the bindings should always be done in their
     /// drop scope.
+    #[instrument(skip(self), level = "debug")]
     pub(crate) fn declare_bindings(
         &mut self,
         mut visibility_scope: Option<SourceScope>,
@@ -662,7 +663,6 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         has_guard: ArmHasGuard,
         opt_match_place: Option<(Option<&Place<'tcx>>, Span)>,
     ) -> Option<SourceScope> {
-        debug!("declare_bindings: pattern={:?}", pattern);
         self.visit_primary_bindings(
             &pattern,
             UserTypeProjections::none(),
@@ -1048,6 +1048,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
     /// if `x.0` matches `false` (for the third arm). In the (impossible at
     /// runtime) case when `x.0` is now `true`, we branch to
     /// `otherwise_block`.
+    #[instrument(skip(self, fake_borrows), level = "debug")]
     fn match_candidates<'pat>(
         &mut self,
         span: Span,
@@ -1057,11 +1058,6 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         candidates: &mut [&mut Candidate<'pat, 'tcx>],
         fake_borrows: &mut Option<FxIndexSet<Place<'tcx>>>,
     ) {
-        debug!(
-            "matched_candidate(span={:?}, candidates={:?}, start_block={:?}, otherwise_block={:?})",
-            span, candidates, start_block, otherwise_block,
-        );
-
         // Start by simplifying candidates. Once this process is complete, all
         // the match pairs which remain require some form of test, whether it
         // be a switch or pattern comparison.
@@ -1380,6 +1376,10 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         )
     }
 
+    #[instrument(
+        skip(self, otherwise, or_span, place, fake_borrows, candidate, pats),
+        level = "debug"
+    )]
     fn test_or_pattern<'pat>(
         &mut self,
         candidate: &mut Candidate<'pat, 'tcx>,
@@ -1389,7 +1389,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         place: PlaceBuilder<'tcx>,
         fake_borrows: &mut Option<FxIndexSet<Place<'tcx>>>,
     ) {
-        debug!("test_or_pattern:\ncandidate={:#?}\npats={:#?}", candidate, pats);
+        debug!("candidate={:#?}\npats={:#?}", candidate, pats);
         let mut or_candidates: Vec<_> = pats
             .iter()
             .map(|pat| Candidate::new(place.clone(), pat, candidate.has_guard))
@@ -1634,9 +1634,14 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
             candidates = rest;
         }
         // at least the first candidate ought to be tested
-        assert!(total_candidate_count > candidates.len());
-        debug!("test_candidates: tested_candidates: {}", total_candidate_count - candidates.len());
-        debug!("test_candidates: untested_candidates: {}", candidates.len());
+        assert!(
+            total_candidate_count > candidates.len(),
+            "{}, {:#?}",
+            total_candidate_count,
+            candidates
+        );
+        debug!("tested_candidates: {}", total_candidate_count - candidates.len());
+        debug!("untested_candidates: {}", candidates.len());
 
         // HACK(matthewjasper) This is a closure so that we can let the test
         // create its blocks before the rest of the match. This currently
@@ -2195,6 +2200,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
     /// first local is a binding for occurrences of `var` in the guard, which
     /// will have type `&T`. The second local is a binding for occurrences of
     /// `var` in the arm body, which will have type `T`.
+    #[instrument(skip(self), level = "debug")]
     fn declare_binding(
         &mut self,
         source_info: SourceInfo,
@@ -2209,19 +2215,12 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         opt_match_place: Option<(Option<Place<'tcx>>, Span)>,
         pat_span: Span,
     ) {
-        debug!(
-            "declare_binding(var_id={:?}, name={:?}, mode={:?}, var_ty={:?}, \
-             visibility_scope={:?}, source_info={:?})",
-            var_id, name, mode, var_ty, visibility_scope, source_info
-        );
-
         let tcx = self.tcx;
         let debug_source_info = SourceInfo { span: source_info.span, scope: visibility_scope };
         let binding_mode = match mode {
             BindingMode::ByValue => ty::BindingMode::BindByValue(mutability),
             BindingMode::ByRef(_) => ty::BindingMode::BindByReference(mutability),
         };
-        debug!("declare_binding: user_ty={:?}", user_ty);
         let local = LocalDecl::<'tcx> {
             mutability,
             ty: var_ty,
@@ -2271,7 +2270,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         } else {
             LocalsForNode::One(for_arm_body)
         };
-        debug!("declare_binding: vars={:?}", locals);
+        debug!(?locals);
         self.var_indices.insert(var_id, locals);
     }
 

compiler/rustc_mir_build/src/build/matches/simplify.rs

@@ -37,12 +37,13 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
     ///
     /// only generates a single switch. If this happens this method returns
     /// `true`.
+    #[instrument(skip(self, candidate), level = "debug")]
     pub(super) fn simplify_candidate<'pat>(
         &mut self,
         candidate: &mut Candidate<'pat, 'tcx>,
     ) -> bool {
         // repeatedly simplify match pairs until fixed point is reached
-        debug!(?candidate, "simplify_candidate");
+        debug!("{:#?}", candidate);
 
         // existing_bindings and new_bindings exists to keep the semantics in order.
         // Reversing the binding order for bindings after `@` changes the binding order in places

compiler/rustc_mir_build/src/build/matches/test.rs

@@ -144,6 +144,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         }
     }
 
+    #[instrument(skip(self, make_target_blocks, place_builder), level = "debug")]
     pub(super) fn perform_test(
         &mut self,
         match_start_span: Span,

compiler/rustc_mir_build/src/build/scope.rs

@@ -553,6 +553,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
 
     /// Convenience wrapper that pushes a scope and then executes `f`
     /// to build its contents, popping the scope afterwards.
+    #[instrument(skip(self, f), level = "debug")]
     pub(crate) fn in_scope<F, R>(
         &mut self,
         region_scope: (region::Scope, SourceInfo),
@@ -562,7 +563,6 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
     where
         F: FnOnce(&mut Builder<'a, 'tcx>) -> BlockAnd<R>,
     {
-        debug!("in_scope(region_scope={:?})", region_scope);
         let source_scope = self.source_scope;
         let tcx = self.tcx;
         if let LintLevel::Explicit(current_hir_id) = lint_level {
@@ -589,7 +589,7 @@ impl<'a, 'tcx> Builder<'a, 'tcx> {
         let rv = unpack!(block = f(self));
         unpack!(block = self.pop_scope(region_scope, block));
         self.source_scope = source_scope;
-        debug!("in_scope: exiting region_scope={:?} block={:?}", region_scope, block);
+        debug!(?block);
         block.and(rv)
     }
 

compiler/rustc_mir_build/src/thir/cx/expr.rs

@@ -48,6 +48,8 @@ impl<'tcx> Cx<'tcx> {
             _ => None,
         };
 
+        trace!(?expr.ty);
+
         // Now apply adjustments, if any.
         for adjustment in self.typeck_results.expr_adjustments(hir_expr) {
             trace!(?expr, ?adjustment);
@@ -56,6 +58,8 @@ impl<'tcx> Cx<'tcx> {
                 self.apply_adjustment(hir_expr, expr, adjustment, adjustment_span.unwrap_or(span));
         }
 
+        trace!(?expr.ty, "after adjustments");
+
         // Next, wrap this up in the expr's scope.
         expr = Expr {
             temp_lifetime,

compiler/rustc_mir_build/src/thir/pattern/mod.rs

@@ -196,6 +196,7 @@ impl<'a, 'tcx> PatCtxt<'a, 'tcx> {
         }
     }
 
+    #[instrument(skip(self), level = "debug")]
     fn lower_pattern_unadjusted(&mut self, pat: &'tcx hir::Pat<'tcx>) -> Pat<'tcx> {
         let mut ty = self.typeck_results.node_type(pat.hir_id);