add some instrumentation

3 files changed, 189 insertions, 134 deletions

diff --git a/src/librustc_mir/borrow_check/nll/type_check/input_output.rs b/src/librustc_mir/borrow_check/nll/type_check/input_output.rs
index 2b1878c33e9..92d5a431a61 100644
--- a/src/librustc_mir/borrow_check/nll/type_check/input_output.rs
+++ b/src/librustc_mir/borrow_check/nll/type_check/input_output.rs
@@ -21,17 +21,18 @@ use borrow_check::nll::renumber;
 use borrow_check::nll::universal_regions::UniversalRegions;
 use rustc::hir::def_id::DefId;
 use rustc::infer::InferOk;
-use rustc::ty::Ty;
-use rustc::ty::subst::Subst;
-use rustc::mir::*;
 use rustc::mir::visit::TyContext;
+use rustc::mir::*;
 use rustc::traits::PredicateObligations;
+use rustc::ty::subst::Subst;
+use rustc::ty::Ty;
 
 use rustc_data_structures::indexed_vec::Idx;
 
 use super::{Locations, TypeChecker};
 
 impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
+    #[inline(never)]
     pub(super) fn equate_inputs_and_outputs(
         &mut self,
         mir: &Mir<'tcx>,
@@ -56,8 +57,8 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         }
 
         assert!(
-            mir.yield_ty.is_some() && universal_regions.yield_ty.is_some() ||
-            mir.yield_ty.is_none() && universal_regions.yield_ty.is_none()
+            mir.yield_ty.is_some() && universal_regions.yield_ty.is_some()
+                || mir.yield_ty.is_none() && universal_regions.yield_ty.is_none()
         );
         if let Some(mir_yield_ty) = mir.yield_ty {
             let ur_yield_ty = universal_regions.yield_ty.unwrap();
@@ -76,57 +77,66 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
             output_ty
         );
         let mir_output_ty = mir.local_decls[RETURN_PLACE].ty;
-        let anon_type_map = self.fully_perform_op(Locations::All, |cx| {
-            let mut obligations = ObligationAccumulator::default();
-
-            let (output_ty, anon_type_map) = obligations.add(infcx.instantiate_anon_types(
-                mir_def_id,
-                cx.body_id,
-                cx.param_env,
-                &output_ty,
-            ));
-            debug!(
-                "equate_inputs_and_outputs: instantiated output_ty={:?}",
-                output_ty
-            );
-            debug!(
-                "equate_inputs_and_outputs: anon_type_map={:#?}",
-                anon_type_map
-            );
-
-            debug!(
-                "equate_inputs_and_outputs: mir_output_ty={:?}",
-                mir_output_ty
-            );
-            obligations.add(infcx
-                .at(&cx.misc(cx.last_span), cx.param_env)
-                .eq(output_ty, mir_output_ty)?);
-
-            for (&anon_def_id, anon_decl) in &anon_type_map {
-                let anon_defn_ty = tcx.type_of(anon_def_id);
-                let anon_defn_ty = anon_defn_ty.subst(tcx, anon_decl.substs);
-                let anon_defn_ty = renumber::renumber_regions(
-                    cx.infcx,
-                    TyContext::Location(Location::START),
-                    &anon_defn_ty,
-                );
-                debug!(
-                    "equate_inputs_and_outputs: concrete_ty={:?}",
-                    anon_decl.concrete_ty
-                );
-                debug!("equate_inputs_and_outputs: anon_defn_ty={:?}", anon_defn_ty);
-                obligations.add(infcx
-                    .at(&cx.misc(cx.last_span), cx.param_env)
-                    .eq(anon_decl.concrete_ty, anon_defn_ty)?);
-            }
-
-            debug!("equate_inputs_and_outputs: equated");
-
-            Ok(InferOk {
-                value: Some(anon_type_map),
-                obligations: obligations.into_vec(),
-            })
-        }).unwrap_or_else(|terr| {
+        let anon_type_map =
+            self.fully_perform_op(
+                Locations::All,
+                || format!("input_output"),
+                |cx| {
+                    let mut obligations = ObligationAccumulator::default();
+
+                    let (output_ty, anon_type_map) = obligations.add(infcx.instantiate_anon_types(
+                        mir_def_id,
+                        cx.body_id,
+                        cx.param_env,
+                        &output_ty,
+                    ));
+                    debug!(
+                        "equate_inputs_and_outputs: instantiated output_ty={:?}",
+                        output_ty
+                    );
+                    debug!(
+                        "equate_inputs_and_outputs: anon_type_map={:#?}",
+                        anon_type_map
+                    );
+
+                    debug!(
+                        "equate_inputs_and_outputs: mir_output_ty={:?}",
+                        mir_output_ty
+                    );
+                    obligations.add(
+                        infcx
+                            .at(&cx.misc(cx.last_span), cx.param_env)
+                            .eq(output_ty, mir_output_ty)?,
+                    );
+
+                    for (&anon_def_id, anon_decl) in &anon_type_map {
+                        let anon_defn_ty = tcx.type_of(anon_def_id);
+                        let anon_defn_ty = anon_defn_ty.subst(tcx, anon_decl.substs);
+                        let anon_defn_ty = renumber::renumber_regions(
+                            cx.infcx,
+                            TyContext::Location(Location::START),
+                            &anon_defn_ty,
+                        );
+                        debug!(
+                            "equate_inputs_and_outputs: concrete_ty={:?}",
+                            anon_decl.concrete_ty
+                        );
+                        debug!("equate_inputs_and_outputs: anon_defn_ty={:?}", anon_defn_ty);
+                        obligations.add(
+                            infcx
+                                .at(&cx.misc(cx.last_span), cx.param_env)
+                                .eq(anon_decl.concrete_ty, anon_defn_ty)?,
+                        );
+                    }
+
+                    debug!("equate_inputs_and_outputs: equated");
+
+                    Ok(InferOk {
+                        value: Some(anon_type_map),
+                        obligations: obligations.into_vec(),
+                    })
+                },
+            ).unwrap_or_else(|terr| {
                 span_mirbug!(
                     self,
                     Location::START,
@@ -143,13 +153,17 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         // prove that `T: Iterator` where `T` is the type we
         // instantiated it with).
         if let Some(anon_type_map) = anon_type_map {
-            self.fully_perform_op(Locations::All, |_cx| {
-                infcx.constrain_anon_types(&anon_type_map, universal_regions);
-                Ok(InferOk {
-                    value: (),
-                    obligations: vec![],
-                })
-            }).unwrap();
+            self.fully_perform_op(
+                Locations::All,
+                || format!("anon_type_map"),
+                |_cx| {
+                    infcx.constrain_anon_types(&anon_type_map, universal_regions);
+                    Ok(InferOk {
+                        value: (),
+                        obligations: vec![],
+                    })
+                },
+            ).unwrap();
         }
     }
 
diff --git a/src/librustc_mir/borrow_check/nll/type_check/liveness.rs b/src/librustc_mir/borrow_check/nll/type_check/liveness.rs
index 76320c6a2ea..e69eb38350e 100644
--- a/src/librustc_mir/borrow_check/nll/type_check/liveness.rs
+++ b/src/librustc_mir/borrow_check/nll/type_check/liveness.rs
@@ -8,15 +8,15 @@
 // option. This file may not be copied, modified, or distributed
 // except according to those terms.
 
-use dataflow::{FlowAtLocation, FlowsAtLocation};
 use borrow_check::nll::region_infer::Cause;
-use dataflow::MaybeInitializedPlaces;
+use borrow_check::nll::type_check::AtLocation;
 use dataflow::move_paths::{HasMoveData, MoveData};
-use rustc::mir::{BasicBlock, Location, Mir};
+use dataflow::MaybeInitializedPlaces;
+use dataflow::{FlowAtLocation, FlowsAtLocation};
+use rustc::infer::InferOk;
 use rustc::mir::Local;
+use rustc::mir::{BasicBlock, Location, Mir};
 use rustc::ty::{Ty, TyCtxt, TypeFoldable};
-use rustc::infer::InferOk;
-use borrow_check::nll::type_check::AtLocation;
 use util::liveness::LivenessResults;
 
 use super::TypeChecker;
@@ -170,6 +170,7 @@ impl<'gen, 'typeck, 'flow, 'gcx, 'tcx> TypeLivenessGenerator<'gen, 'typeck, 'flo
     /// the regions in its type must be live at `location`. The
     /// precise set will depend on the dropck constraints, and in
     /// particular this takes `#[may_dangle]` into account.
+    #[inline(never)]
     fn add_drop_live_constraint(
         &mut self,
         dropped_local: Local,
@@ -191,33 +192,39 @@ impl<'gen, 'typeck, 'flow, 'gcx, 'tcx> TypeLivenessGenerator<'gen, 'typeck, 'flo
         //
         // For this reason, we avoid calling TypeChecker.normalize, instead doing all normalization
         // ourselves in one large 'fully_perform_op' callback.
-        let kind_constraints = self.cx
-            .fully_perform_op(location.at_self(), |cx| {
-                let span = cx.last_span;
-
-                let mut final_obligations = Vec::new();
-                let mut kind_constraints = Vec::new();
-
-                let InferOk {
-                    value: kinds,
-                    obligations,
-                } = cx.infcx
-                    .at(&cx.misc(span), cx.param_env)
-                    .dropck_outlives(dropped_ty);
-                for kind in kinds {
-                    // All things in the `outlives` array may be touched by
-                    // the destructor and must be live at this point.
-                    let cause = Cause::DropVar(dropped_local, location);
-                    kind_constraints.push((kind, location, cause));
-                }
-
-                final_obligations.extend(obligations);
-
-                Ok(InferOk {
-                    value: kind_constraints,
-                    obligations: final_obligations,
-                })
-            })
+        let kind_constraints = self
+            .cx
+            .fully_perform_op(
+                location.at_self(),
+                || format!("add_drop_live_constraint(dropped_ty={:?})", dropped_ty),
+                |cx| {
+                    let span = cx.last_span;
+
+                    let mut final_obligations = Vec::new();
+                    let mut kind_constraints = Vec::new();
+
+                    let InferOk {
+                        value: kinds,
+                        obligations,
+                    } = cx
+                        .infcx
+                        .at(&cx.misc(span), cx.param_env)
+                        .dropck_outlives(dropped_ty);
+                    for kind in kinds {
+                        // All things in the `outlives` array may be touched by
+                        // the destructor and must be live at this point.
+                        let cause = Cause::DropVar(dropped_local, location);
+                        kind_constraints.push((kind, location, cause));
+                    }
+
+                    final_obligations.extend(obligations);
+
+                    Ok(InferOk {
+                        value: kind_constraints,
+                        obligations: final_obligations,
+                    })
+                },
+            )
             .unwrap();
 
         for (kind, location, cause) in kind_constraints {
diff --git a/src/librustc_mir/borrow_check/nll/type_check/mod.rs b/src/librustc_mir/borrow_check/nll/type_check/mod.rs
index 04f5024b769..060313399cb 100644
--- a/src/librustc_mir/borrow_check/nll/type_check/mod.rs
+++ b/src/librustc_mir/borrow_check/nll/type_check/mod.rs
@@ -710,14 +710,20 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         traits::ObligationCause::misc(span, self.body_id)
     }
 
+    #[inline(never)]
     fn fully_perform_op<OP, R>(
         &mut self,
         locations: Locations,
+        describe_op: impl Fn() -> String,
         op: OP,
     ) -> Result<R, TypeError<'tcx>>
     where
         OP: FnOnce(&mut Self) -> InferResult<'tcx, R>,
     {
+        if cfg!(debug_assertions) {
+            info!("fully_perform_op(describe_op={}) at {:?}", describe_op(), locations);
+        }
+
         let mut fulfill_cx = TraitEngine::new(self.infcx.tcx);
         let InferOk { value, obligations } = self.infcx.commit_if_ok(|_| op(self))?;
         fulfill_cx.register_predicate_obligations(self.infcx, obligations);
@@ -746,25 +752,35 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         Ok(value)
     }
 
+    #[inline(never)]
     fn sub_types(
         &mut self,
         sub: Ty<'tcx>,
         sup: Ty<'tcx>,
         locations: Locations,
     ) -> UnitResult<'tcx> {
-        self.fully_perform_op(locations, |this| {
-            this.infcx
-                .at(&this.misc(this.last_span), this.param_env)
-                .sup(sup, sub)
-        })
+        self.fully_perform_op(
+            locations,
+            || format!("sub_types({:?} <: {:?})", sub, sup),
+            |this| {
+                this.infcx
+                    .at(&this.misc(this.last_span), this.param_env)
+                    .sup(sup, sub)
+            },
+        )
     }
 
+    #[inline(never)]
     fn eq_types(&mut self, a: Ty<'tcx>, b: Ty<'tcx>, locations: Locations) -> UnitResult<'tcx> {
-        self.fully_perform_op(locations, |this| {
-            this.infcx
-                .at(&this.misc(this.last_span), this.param_env)
-                .eq(b, a)
-        })
+        self.fully_perform_op(
+            locations,
+            || format!("eq_types({:?} = {:?})", a, b),
+            |this| {
+                this.infcx
+                    .at(&this.misc(this.last_span), this.param_env)
+                    .eq(b, a)
+            },
+        )
     }
 
     fn tcx(&self) -> TyCtxt<'a, 'gcx, 'tcx> {
@@ -1520,29 +1536,42 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         );
     }
 
+    #[inline(never)]
     fn prove_predicates<T>(&mut self, predicates: T, location: Location)
     where
-        T: IntoIterator<Item = ty::Predicate<'tcx>>,
-        T::IntoIter: Clone,
+        T: IntoIterator<Item = ty::Predicate<'tcx>> + Clone,
     {
-        let predicates = predicates.into_iter();
+        // This intermediate vector is mildly unfortunate, in that we
+        // sometimes create it even when logging is disabled, but only
+        // if debug-info is enabled, and I doubt it is actually
+        // expensive. -nmatsakis
+        let predicates_vec: Vec<_> = if cfg!(debug_assertions) {
+            predicates.clone().into_iter().collect()
+        } else {
+            Vec::new()
+        };
 
         debug!(
             "prove_predicates(predicates={:?}, location={:?})",
-            predicates.clone().collect::<Vec<_>>(),
+            predicates_vec,
             location,
         );
-        self.fully_perform_op(location.at_self(), |this| {
-            let cause = this.misc(this.last_span);
-            let obligations = predicates
-                .into_iter()
-                .map(|p| traits::Obligation::new(cause.clone(), this.param_env, p))
-                .collect();
-            Ok(InferOk {
-                value: (),
-                obligations,
-            })
-        }).unwrap()
+
+        self.fully_perform_op(
+            location.at_self(),
+            || format!("prove_predicates({:?})", predicates_vec),
+            |this| {
+                let cause = this.misc(this.last_span);
+                let obligations = predicates
+                    .into_iter()
+                    .map(|p| traits::Obligation::new(cause.clone(), this.param_env, p))
+                    .collect();
+                Ok(InferOk {
+                    value: (),
+                    obligations,
+                })
+            },
+        ).unwrap()
     }
 
     fn typeck_mir(&mut self, mir: &Mir<'tcx>) {
@@ -1571,25 +1600,30 @@ impl<'a, 'gcx, 'tcx> TypeChecker<'a, 'gcx, 'tcx> {
         }
     }
 
+    #[inline(never)]
     fn normalize<T>(&mut self, value: &T, location: impl ToLocations) -> T
     where
         T: fmt::Debug + TypeFoldable<'tcx>,
     {
         debug!("normalize(value={:?}, location={:?})", value, location);
-        self.fully_perform_op(location.to_locations(), |this| {
-            let Normalized { value, obligations } = this.infcx
-                .at(&this.misc(this.last_span), this.param_env)
-                .normalize(value)
-                .unwrap_or_else(|NoSolution| {
-                    span_bug!(
-                        this.last_span,
-                        "normalization of `{:?}` failed at {:?}",
-                        value,
-                        location,
-                    );
-                });
-            Ok(InferOk { value, obligations })
-        }).unwrap()
+        self.fully_perform_op(
+            location.to_locations(),
+            || format!("normalize(value={:?})", value),
+            |this| {
+                let Normalized { value, obligations } = this.infcx
+                    .at(&this.misc(this.last_span), this.param_env)
+                    .normalize(value)
+                    .unwrap_or_else(|NoSolution| {
+                        span_bug!(
+                            this.last_span,
+                            "normalization of `{:?}` failed at {:?}",
+                            value,
+                            location,
+                        );
+                    });
+                Ok(InferOk { value, obligations })
+            },
+        ).unwrap()
     }
 }