From 9b5aa063d8e9808eacd27a0bf75a85495ff01bd4 Mon Sep 17 00:00:00 2001 From: Oli Scherer Date: Fri, 20 Aug 2021 13:36:04 +0000 Subject: [PATCH] More tracing instrumentation --- .../src/diagnostics/bound_region_errors.rs | 5 +- compiler/rustc_borrowck/src/lib.rs | 3 +- compiler/rustc_borrowck/src/nll.rs | 3 +- .../rustc_borrowck/src/region_infer/mod.rs | 71 +++++++------------ compiler/rustc_borrowck/src/renumber.rs | 22 +++--- .../src/type_check/canonical.rs | 6 +- .../src/type_check/constraint_conversion.rs | 3 +- .../src/type_check/input_output.rs | 9 +-- compiler/rustc_borrowck/src/type_check/mod.rs | 52 +++++++------- .../src/type_check/relate_tys.rs | 2 +- .../src/graph/scc/mod.rs | 20 ++---- compiler/rustc_infer/src/infer/at.rs | 8 +-- .../src/infer/canonical/query_response.rs | 11 +-- compiler/rustc_infer/src/infer/fudge.rs | 3 +- .../src/infer/higher_ranked/mod.rs | 3 +- compiler/rustc_infer/src/infer/mod.rs | 16 ++--- .../rustc_infer/src/infer/nll_relate/mod.rs | 28 ++++---- .../src/infer/region_constraints/mod.rs | 6 +- compiler/rustc_middle/src/ty/fold.rs | 36 +++++----- compiler/rustc_middle/src/ty/print/mod.rs | 4 +- compiler/rustc_middle/src/ty/print/pretty.rs | 8 +-- compiler/rustc_middle/src/ty/util.rs | 2 + compiler/rustc_mir_dataflow/src/impls/mod.rs | 18 ++--- compiler/rustc_resolve/src/late/lifetimes.rs | 3 + compiler/rustc_resolve/src/lib.rs | 3 + .../rustc_trait_selection/src/opaque_types.rs | 7 +- .../src/traits/error_reporting/mod.rs | 8 +-- .../src/traits/select/candidate_assembly.rs | 1 + .../src/traits/select/confirmation.rs | 4 +- .../src/traits/select/mod.rs | 14 ++-- compiler/rustc_typeck/src/astconv/generics.rs | 21 +++--- compiler/rustc_typeck/src/check/check.rs | 3 +- compiler/rustc_typeck/src/check/closure.rs | 38 +++++----- compiler/rustc_typeck/src/check/coercion.rs | 5 +- compiler/rustc_typeck/src/check/demand.rs | 1 + compiler/rustc_typeck/src/check/expr.rs | 5 +- .../rustc_typeck/src/check/fn_ctxt/_impl.rs | 66 ++++++----------- compiler/rustc_typeck/src/check/upvar.rs | 43 ++++------- compiler/rustc_typeck/src/check/writeback.rs | 14 ++-- 39 files changed, 252 insertions(+), 323 deletions(-) diff --git a/compiler/rustc_borrowck/src/diagnostics/bound_region_errors.rs b/compiler/rustc_borrowck/src/diagnostics/bound_region_errors.rs index 366ade1a713..15309ccd8df 100644 --- a/compiler/rustc_borrowck/src/diagnostics/bound_region_errors.rs +++ b/compiler/rustc_borrowck/src/diagnostics/bound_region_errors.rs @@ -327,6 +327,7 @@ impl TypeOpInfo<'tcx> for AscribeUserTypeQuery<'tcx> { } } +#[instrument(skip(fulfill_cx, infcx), level = "debug")] fn try_extract_error_from_fulfill_cx<'tcx>( mut fulfill_cx: Box + 'tcx>, infcx: &InferCtxt<'_, 'tcx>, @@ -341,7 +342,7 @@ fn try_extract_error_from_fulfill_cx<'tcx>( let _errors = fulfill_cx.select_all_or_error(infcx).err().unwrap_or_else(Vec::new); let (sub_region, cause) = infcx.with_region_constraints(|region_constraints| { - debug!(?region_constraints); + debug!("{:#?}", region_constraints); region_constraints.constraints.iter().find_map(|(constraint, cause)| { match *constraint { Constraint::RegSubReg(sub, sup) if sup == placeholder_region && sup != sub => { @@ -356,7 +357,7 @@ fn try_extract_error_from_fulfill_cx<'tcx>( }) })?; - debug!(?sub_region, ?cause); + debug!(?sub_region, "cause = {:#?}", cause); let nice_error = match (error_region, sub_region) { (Some(error_region), &ty::ReVar(vid)) => NiceRegionError::new( infcx, diff --git a/compiler/rustc_borrowck/src/lib.rs b/compiler/rustc_borrowck/src/lib.rs index 72f4907a09f..6ffa0095e4b 100644 --- a/compiler/rustc_borrowck/src/lib.rs +++ b/compiler/rustc_borrowck/src/lib.rs @@ -144,6 +144,7 @@ fn mir_borrowck<'tcx>( /// If `return_body_with_facts` is true, then return the body with non-erased /// region ids on which the borrow checking was performed together with Polonius /// facts. +#[instrument(skip(infcx, input_body, input_promoted), level = "debug")] fn do_mir_borrowck<'a, 'tcx>( infcx: &InferCtxt<'a, 'tcx>, input_body: &Body<'tcx>, @@ -152,7 +153,7 @@ fn do_mir_borrowck<'a, 'tcx>( ) -> (BorrowCheckResult<'tcx>, Option>>) { let def = input_body.source.with_opt_param().as_local().unwrap(); - debug!("do_mir_borrowck(def = {:?})", def); + debug!(?def); let tcx = infcx.tcx; let param_env = tcx.param_env(def.did); diff --git a/compiler/rustc_borrowck/src/nll.rs b/compiler/rustc_borrowck/src/nll.rs index 477b049b075..e5924f9d084 100644 --- a/compiler/rustc_borrowck/src/nll.rs +++ b/compiler/rustc_borrowck/src/nll.rs @@ -54,6 +54,7 @@ crate struct NllOutput<'tcx> { /// Rewrites the regions in the MIR to use NLL variables, also scraping out the set of universal /// regions (e.g., region parameters) declared on the function. That set will need to be given to /// `compute_regions`. +#[instrument(skip(infcx, param_env, body, promoted), level = "debug")] pub(crate) fn replace_regions_in_mir<'cx, 'tcx>( infcx: &InferCtxt<'cx, 'tcx>, param_env: ty::ParamEnv<'tcx>, @@ -62,7 +63,7 @@ pub(crate) fn replace_regions_in_mir<'cx, 'tcx>( ) -> UniversalRegions<'tcx> { let def = body.source.with_opt_param().as_local().unwrap(); - debug!("replace_regions_in_mir(def={:?})", def); + debug!(?def); // Compute named region information. This also renumbers the inputs/outputs. let universal_regions = UniversalRegions::new(infcx, def, param_env); diff --git a/compiler/rustc_borrowck/src/region_infer/mod.rs b/compiler/rustc_borrowck/src/region_infer/mod.rs index 917d69a5c86..65d6e3a4ae5 100644 --- a/compiler/rustc_borrowck/src/region_infer/mod.rs +++ b/compiler/rustc_borrowck/src/region_infer/mod.rs @@ -552,6 +552,7 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// Performs region inference and report errors if we see any /// unsatisfiable constraints. If this is a closure, returns the /// region requirements to propagate to our creator, if any. + #[instrument(skip(self, infcx, body, polonius_output), level = "debug")] pub(super) fn solve( &mut self, infcx: &InferCtxt<'_, 'tcx>, @@ -607,10 +608,9 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// for each region variable until all the constraints are /// satisfied. Note that some values may grow **too** large to be /// feasible, but we check this later. + #[instrument(skip(self, _body), level = "debug")] fn propagate_constraints(&mut self, _body: &Body<'tcx>) { - debug!("propagate_constraints()"); - - debug!("propagate_constraints: constraints={:#?}", { + debug!("constraints={:#?}", { let mut constraints: Vec<_> = self.constraints.outlives().iter().collect(); constraints.sort(); constraints @@ -637,12 +637,13 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// computed, by unioning the values of its successors. /// Assumes that all successors have been computed already /// (which is assured by iterating over SCCs in dependency order). + #[instrument(skip(self), level = "debug")] fn compute_value_for_scc(&mut self, scc_a: ConstraintSccIndex) { let constraint_sccs = self.constraint_sccs.clone(); // Walk each SCC `B` such that `A: B`... for &scc_b in constraint_sccs.successors(scc_a) { - debug!("propagate_constraint_sccs: scc_a = {:?} scc_b = {:?}", scc_a, scc_b); + debug!(?scc_b); // ...and add elements from `B` into `A`. One complication // arises because of universes: If `B` contains something @@ -663,11 +664,7 @@ impl<'tcx> RegionInferenceContext<'tcx> { self.apply_member_constraint(scc_a, m_c_i, member_constraints.choice_regions(m_c_i)); } - debug!( - "propagate_constraint_sccs: scc_a = {:?} has value {:?}", - scc_a, - self.scc_values.region_value_str(scc_a), - ); + debug!(value = ?self.scc_values.region_value_str(scc_a)); } /// Invoked for each `R0 member of [R1..Rn]` constraint. @@ -681,14 +678,13 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// is considered a *lower bound*. If possible, we will modify /// the constraint to set it equal to one of the option regions. /// If we make any changes, returns true, else false. + #[instrument(skip(self, member_constraint_index), level = "debug")] fn apply_member_constraint( &mut self, scc: ConstraintSccIndex, member_constraint_index: NllMemberConstraintIndex, choice_regions: &[ty::RegionVid], ) -> bool { - debug!("apply_member_constraint(scc={:?}, choice_regions={:#?})", scc, choice_regions,); - // Create a mutable vector of the options. We'll try to winnow // them down. let mut choice_regions: Vec = choice_regions.to_vec(); @@ -714,7 +710,7 @@ impl<'tcx> RegionInferenceContext<'tcx> { .universal_regions_outlived_by(scc) .all(|lb| self.universal_region_relations.outlives(o_r, lb)) }); - debug!("apply_member_constraint: after lb, choice_regions={:?}", choice_regions); + debug!(?choice_regions, "after lb"); // Now find all the *upper bounds* -- that is, each UB is a // free region that must outlive the member region `R0` (`UB: @@ -723,10 +719,10 @@ impl<'tcx> RegionInferenceContext<'tcx> { let rev_scc_graph = self.reverse_scc_graph(); let universal_region_relations = &self.universal_region_relations; for ub in rev_scc_graph.upper_bounds(scc) { - debug!("apply_member_constraint: ub={:?}", ub); + debug!(?ub); choice_regions.retain(|&o_r| universal_region_relations.outlives(ub, o_r)); } - debug!("apply_member_constraint: after ub, choice_regions={:?}", choice_regions); + debug!(?choice_regions, "after ub"); // If we ruled everything out, we're done. if choice_regions.is_empty() { @@ -735,7 +731,7 @@ impl<'tcx> RegionInferenceContext<'tcx> { // Otherwise, we need to find the minimum remaining choice, if // any, and take that. - debug!("apply_member_constraint: choice_regions remaining are {:#?}", choice_regions); + debug!("choice_regions remaining are {:#?}", choice_regions); let min = |r1: ty::RegionVid, r2: ty::RegionVid| -> Option { let r1_outlives_r2 = self.universal_region_relations.outlives(r1, r2); let r2_outlives_r1 = self.universal_region_relations.outlives(r2, r1); @@ -748,27 +744,18 @@ impl<'tcx> RegionInferenceContext<'tcx> { }; let mut min_choice = choice_regions[0]; for &other_option in &choice_regions[1..] { - debug!( - "apply_member_constraint: min_choice={:?} other_option={:?}", - min_choice, other_option, - ); + debug!(?min_choice, ?other_option,); match min(min_choice, other_option) { Some(m) => min_choice = m, None => { - debug!( - "apply_member_constraint: {:?} and {:?} are incomparable; no min choice", - min_choice, other_option, - ); + debug!(?min_choice, ?other_option, "incomparable; no min choice",); return false; } } } let min_choice_scc = self.constraint_sccs.scc(min_choice); - debug!( - "apply_member_constraint: min_choice={:?} best_choice_scc={:?}", - min_choice, min_choice_scc, - ); + debug!(?min_choice, ?min_choice_scc); if self.scc_values.add_region(scc, min_choice_scc) { self.member_constraints_applied.push(AppliedMemberConstraint { member_region_scc: scc, @@ -1091,8 +1078,9 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// include the CFG anyhow. /// - For each `end('x)` element in `'r`, compute the mutual LUB, yielding /// a result `'y`. + #[instrument(skip(self), level = "debug")] pub(crate) fn universal_upper_bound(&self, r: RegionVid) -> RegionVid { - debug!("universal_upper_bound(r={:?}={})", r, self.region_value_str(r)); + debug!(r = %self.region_value_str(r)); // Find the smallest universal region that contains all other // universal regions within `region`. @@ -1102,7 +1090,7 @@ impl<'tcx> RegionInferenceContext<'tcx> { lub = self.universal_region_relations.postdom_upper_bound(lub, ur); } - debug!("universal_upper_bound: r={:?} lub={:?}", r, lub); + debug!(?lub); lub } @@ -1262,9 +1250,8 @@ impl<'tcx> RegionInferenceContext<'tcx> { } // Evaluate whether `sup_region: sub_region`. + #[instrument(skip(self), level = "debug")] fn eval_outlives(&self, sup_region: RegionVid, sub_region: RegionVid) -> bool { - debug!("eval_outlives({:?}: {:?})", sup_region, sub_region); - debug!( "eval_outlives: sup_region's value = {:?} universal={:?}", self.region_value_str(sup_region), @@ -1467,6 +1454,10 @@ impl<'tcx> RegionInferenceContext<'tcx> { /// /// Things that are to be propagated are accumulated into the /// `outlives_requirements` vector. + #[instrument( + skip(self, body, propagated_outlives_requirements, errors_buffer), + level = "debug" + )] fn check_universal_region( &self, body: &Body<'tcx>, @@ -1474,8 +1465,6 @@ impl<'tcx> RegionInferenceContext<'tcx> { propagated_outlives_requirements: &mut Option<&mut Vec>>, errors_buffer: &mut RegionErrors<'tcx>, ) { - debug!("check_universal_region(fr={:?})", longer_fr); - let longer_fr_scc = self.constraint_sccs.scc(longer_fr); // Because this free region must be in the ROOT universe, we @@ -1880,21 +1869,13 @@ impl<'tcx> RegionInferenceContext<'tcx> { } /// Finds some region R such that `fr1: R` and `R` is live at `elem`. + #[instrument(skip(self), level = "trace")] crate fn find_sub_region_live_at(&self, fr1: RegionVid, elem: Location) -> RegionVid { - debug!("find_sub_region_live_at(fr1={:?}, elem={:?})", fr1, elem); - debug!("find_sub_region_live_at: {:?} is in scc {:?}", fr1, self.constraint_sccs.scc(fr1)); - debug!( - "find_sub_region_live_at: {:?} is in universe {:?}", - fr1, - self.scc_universes[self.constraint_sccs.scc(fr1)] - ); + trace!(scc = ?self.constraint_sccs.scc(fr1)); + trace!(universe = ?self.scc_universes[self.constraint_sccs.scc(fr1)]); self.find_constraint_paths_between_regions(fr1, |r| { // First look for some `r` such that `fr1: r` and `r` is live at `elem` - debug!( - "find_sub_region_live_at: liveness_constraints for {:?} are {:?}", - r, - self.liveness_constraints.region_value_str(r), - ); + trace!(?r, liveness_constraints=?self.liveness_constraints.region_value_str(r)); self.liveness_constraints.contains(r, elem) }) .or_else(|| { diff --git a/compiler/rustc_borrowck/src/renumber.rs b/compiler/rustc_borrowck/src/renumber.rs index 9377473befe..20567610f65 100644 --- a/compiler/rustc_borrowck/src/renumber.rs +++ b/compiler/rustc_borrowck/src/renumber.rs @@ -7,13 +7,13 @@ use rustc_middle::ty::{self, Ty, TyCtxt, TypeFoldable}; /// Replaces all free regions appearing in the MIR with fresh /// inference variables, returning the number of variables created. +#[instrument(skip(infcx, body, promoted), level = "debug")] pub fn renumber_mir<'tcx>( infcx: &InferCtxt<'_, 'tcx>, body: &mut Body<'tcx>, promoted: &mut IndexVec>, ) { - debug!("renumber_mir()"); - debug!("renumber_mir: body.arg_count={:?}", body.arg_count); + debug!(?body.arg_count); let mut visitor = NllVisitor { infcx }; @@ -26,12 +26,11 @@ pub fn renumber_mir<'tcx>( /// Replaces all regions appearing in `value` with fresh inference /// variables. +#[instrument(skip(infcx), level = "debug")] pub fn renumber_regions<'tcx, T>(infcx: &InferCtxt<'_, 'tcx>, value: T) -> T where T: TypeFoldable<'tcx>, { - debug!("renumber_regions(value={:?})", value); - infcx.tcx.fold_regions(value, &mut false, |_region, _depth| { let origin = NllRegionVariableOrigin::Existential { from_forall: false }; infcx.next_nll_region_var(origin) @@ -56,12 +55,11 @@ impl<'a, 'tcx> MutVisitor<'tcx> for NllVisitor<'a, 'tcx> { self.infcx.tcx } + #[instrument(skip(self), level = "debug")] fn visit_ty(&mut self, ty: &mut Ty<'tcx>, ty_context: TyContext) { - debug!("visit_ty(ty={:?}, ty_context={:?})", ty, ty_context); - *ty = self.renumber_regions(ty); - debug!("visit_ty: ty={:?}", ty); + debug!(?ty); } fn process_projection_elem( @@ -80,21 +78,19 @@ impl<'a, 'tcx> MutVisitor<'tcx> for NllVisitor<'a, 'tcx> { None } + #[instrument(skip(self), level = "debug")] fn visit_substs(&mut self, substs: &mut SubstsRef<'tcx>, location: Location) { - debug!("visit_substs(substs={:?}, location={:?})", substs, location); - *substs = self.renumber_regions(*substs); - debug!("visit_substs: substs={:?}", substs); + debug!(?substs); } + #[instrument(skip(self), level = "debug")] fn visit_region(&mut self, region: &mut ty::Region<'tcx>, location: Location) { - debug!("visit_region(region={:?}, location={:?})", region, location); - let old_region = *region; *region = self.renumber_regions(&old_region); - debug!("visit_region: region={:?}", region); + debug!(?region); } fn visit_const(&mut self, constant: &mut &'tcx ty::Const<'tcx>, _location: Location) { diff --git a/compiler/rustc_borrowck/src/type_check/canonical.rs b/compiler/rustc_borrowck/src/type_check/canonical.rs index df28fb6e28e..7d4df59902a 100644 --- a/compiler/rustc_borrowck/src/type_check/canonical.rs +++ b/compiler/rustc_borrowck/src/type_check/canonical.rs @@ -24,6 +24,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { /// **Any `rustc_infer::infer` operations that might generate region /// constraints should occur within this method so that those /// constraints can be properly localized!** + #[instrument(skip(self, category, op), level = "trace")] pub(super) fn fully_perform_op( &mut self, locations: Locations, @@ -131,14 +132,13 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] pub(super) fn prove_predicate( &mut self, predicate: ty::Predicate<'tcx>, locations: Locations, category: ConstraintCategory, ) { - debug!("prove_predicate(predicate={:?}, location={:?})", predicate, locations,); - let param_env = self.param_env; self.fully_perform_op( locations, @@ -150,11 +150,11 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { }) } + #[instrument(skip(self), level = "debug")] pub(super) fn normalize(&mut self, value: T, location: impl NormalizeLocation) -> T where T: type_op::normalize::Normalizable<'tcx> + fmt::Display + Copy + 'tcx, { - debug!("normalize(value={:?}, location={:?})", value, location); let param_env = self.param_env; self.fully_perform_op( location.to_locations(), diff --git a/compiler/rustc_borrowck/src/type_check/constraint_conversion.rs b/compiler/rustc_borrowck/src/type_check/constraint_conversion.rs index b0207468485..ab1a7461b4b 100644 --- a/compiler/rustc_borrowck/src/type_check/constraint_conversion.rs +++ b/compiler/rustc_borrowck/src/type_check/constraint_conversion.rs @@ -53,9 +53,8 @@ impl<'a, 'tcx> ConstraintConversion<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] pub(super) fn convert_all(&mut self, query_constraints: &QueryRegionConstraints<'tcx>) { - debug!("convert_all(query_constraints={:#?})", query_constraints); - let QueryRegionConstraints { outlives, member_constraints } = query_constraints; // Annoying: to invoke `self.to_region_vid`, we need access to diff --git a/compiler/rustc_borrowck/src/type_check/input_output.rs b/compiler/rustc_borrowck/src/type_check/input_output.rs index 46d30a188ed..24332690bec 100644 --- a/compiler/rustc_borrowck/src/type_check/input_output.rs +++ b/compiler/rustc_borrowck/src/type_check/input_output.rs @@ -20,6 +20,7 @@ use crate::universal_regions::UniversalRegions; use super::{Locations, TypeChecker}; impl<'a, 'tcx> TypeChecker<'a, 'tcx> { + #[instrument(skip(self, body, universal_regions), level = "debug")] pub(super) fn equate_inputs_and_outputs( &mut self, body: &Body<'tcx>, @@ -64,10 +65,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { ); } - debug!( - "equate_inputs_and_outputs: normalized_input_tys = {:?}, local_decls = {:?}", - normalized_input_tys, body.local_decls - ); + debug!(?normalized_input_tys, ?body.local_decls); // Equate expected input tys with those in the MIR. for (argument_index, &normalized_input_ty) in normalized_input_tys.iter().enumerate() { @@ -160,9 +158,8 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { } } + #[instrument(skip(self, span), level = "debug")] fn equate_normalized_input_or_output(&mut self, a: Ty<'tcx>, b: Ty<'tcx>, span: Span) { - debug!("equate_normalized_input_or_output(a={:?}, b={:?})", a, b); - if let Err(_) = self.eq_types(a, b, Locations::All(span), ConstraintCategory::BoringNoLocation) { diff --git a/compiler/rustc_borrowck/src/type_check/mod.rs b/compiler/rustc_borrowck/src/type_check/mod.rs index 4bbeed39e45..55790bd2daa 100644 --- a/compiler/rustc_borrowck/src/type_check/mod.rs +++ b/compiler/rustc_borrowck/src/type_check/mod.rs @@ -197,6 +197,11 @@ pub(crate) fn type_check<'mir, 'tcx>( .into_iter() .filter_map(|(opaque_type_key, mut decl)| { decl.concrete_ty = infcx.resolve_vars_if_possible(decl.concrete_ty); + trace!( + "finalized opaque type {:?} to {:#?}", + opaque_type_key, + decl.concrete_ty.kind() + ); if decl.concrete_ty.has_infer_types_or_consts() { infcx.tcx.sess.delay_span_bug( body.span, @@ -247,6 +252,18 @@ pub(crate) fn type_check<'mir, 'tcx>( MirTypeckResults { constraints, universal_region_relations, opaque_type_values } } +#[instrument( + skip( + infcx, + body, + promoted, + region_bound_pairs, + borrowck_context, + universal_region_relations, + extra + ), + level = "debug" +)] fn type_check_internal<'a, 'tcx, R>( infcx: &'a InferCtxt<'a, 'tcx>, param_env: ty::ParamEnv<'tcx>, @@ -1114,13 +1131,14 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { } } + #[instrument(skip(self, data), level = "debug")] fn push_region_constraints( &mut self, locations: Locations, category: ConstraintCategory, data: &QueryRegionConstraints<'tcx>, ) { - debug!("push_region_constraints: constraints generated at {:?} are {:#?}", locations, data); + debug!("constraints generated: {:#?}", data); constraint_conversion::ConstraintConversion::new( self.infcx, @@ -1180,6 +1198,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { self.relate_types(expected, ty::Variance::Invariant, found, locations, category) } + #[instrument(skip(self), level = "debug")] fn relate_type_and_user_type( &mut self, a: Ty<'tcx>, @@ -1188,11 +1207,6 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { locations: Locations, category: ConstraintCategory, ) -> Fallible<()> { - debug!( - "relate_type_and_user_type(a={:?}, v={:?}, user_ty={:?}, locations={:?})", - a, v, user_ty, locations, - ); - let annotated_type = self.user_type_annotations[user_ty.base].inferred_ty; let mut curr_projected_ty = PlaceTy::from_ty(annotated_type); @@ -1250,6 +1264,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { /// generics of `foo`). Note that `anon_ty` is not just the opaque type, /// but the entire return type (which may contain opaque types within it). /// * `revealed_ty` would be `Box<(T, u32)>` + #[instrument(skip(self), level = "debug")] fn eq_opaque_type_and_type( &mut self, revealed_ty: Ty<'tcx>, @@ -1257,13 +1272,6 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { locations: Locations, category: ConstraintCategory, ) -> Fallible<()> { - debug!( - "eq_opaque_type_and_type( \ - revealed_ty={:?}, \ - anon_ty={:?})", - revealed_ty, anon_ty - ); - // Fast path for the common case. if !anon_ty.has_opaque_types() { if let Err(terr) = self.eq_types(anon_ty, revealed_ty, locations, category) { @@ -1283,7 +1291,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { let body = self.body; let mir_def_id = body.source.def_id().expect_local(); - debug!("eq_opaque_type_and_type: mir_def_id={:?}", mir_def_id); + debug!(?mir_def_id); self.fully_perform_op( locations, category, @@ -1305,12 +1313,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { anon_ty, locations.span(body), )); - debug!( - "eq_opaque_type_and_type: \ - instantiated output_ty={:?} \ - revealed_ty={:?}", - output_ty, revealed_ty - ); + debug!(?output_ty, ?revealed_ty); // Make sure that the inferred types are well-formed. I'm // not entirely sure this is needed (the HIR type check @@ -1328,7 +1331,7 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { .eq(output_ty, revealed_ty)?, ); - debug!("eq_opaque_type_and_type: equated"); + debug!("equated"); Ok(InferOk { value: (), obligations: obligations.into_vec() }) }, @@ -1368,8 +1371,8 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { self.infcx.tcx } + #[instrument(skip(self, body, location), level = "debug")] fn check_stmt(&mut self, body: &Body<'tcx>, stmt: &Statement<'tcx>, location: Location) { - debug!("check_stmt: {:?}", stmt); let tcx = self.tcx(); match stmt.kind { StatementKind::Assign(box (ref place, ref rv)) => { @@ -1522,13 +1525,13 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { } } + #[instrument(skip(self, body, term_location), level = "debug")] fn check_terminator( &mut self, body: &Body<'tcx>, term: &Terminator<'tcx>, term_location: Location, ) { - debug!("check_terminator: {:?}", term); let tcx = self.tcx(); match term.kind { TerminatorKind::Goto { .. } @@ -2685,9 +2688,10 @@ impl<'a, 'tcx> TypeChecker<'a, 'tcx> { tcx.predicates_of(def_id).instantiate(tcx, substs) } + #[instrument(skip(self, body), level = "debug")] fn typeck_mir(&mut self, body: &Body<'tcx>) { self.last_span = body.span; - debug!("run_on_mir: {:?}", body.span); + debug!(?body.span); for (local, local_decl) in body.local_decls.iter_enumerated() { self.check_local(&body, local, local_decl); diff --git a/compiler/rustc_borrowck/src/type_check/relate_tys.rs b/compiler/rustc_borrowck/src/type_check/relate_tys.rs index de86d39cc37..b788529dc1c 100644 --- a/compiler/rustc_borrowck/src/type_check/relate_tys.rs +++ b/compiler/rustc_borrowck/src/type_check/relate_tys.rs @@ -17,6 +17,7 @@ use crate::type_check::{BorrowCheckContext, Locations}; /// /// N.B., the type `a` is permitted to have unresolved inference /// variables, but not the type `b`. +#[instrument(skip(infcx, param_env, borrowck_context), level = "debug")] pub(super) fn relate_types<'tcx>( infcx: &InferCtxt<'_, 'tcx>, param_env: ty::ParamEnv<'tcx>, @@ -27,7 +28,6 @@ pub(super) fn relate_types<'tcx>( category: ConstraintCategory, borrowck_context: &mut BorrowCheckContext<'_, 'tcx>, ) -> Fallible<()> { - debug!("relate_types(a={:?}, v={:?}, b={:?}, locations={:?})", a, v, b, locations); TypeRelating::new( infcx, NllTypeRelatingDelegate::new( diff --git a/compiler/rustc_data_structures/src/graph/scc/mod.rs b/compiler/rustc_data_structures/src/graph/scc/mod.rs index d8ac815a158..b84f28b6a9e 100644 --- a/compiler/rustc_data_structures/src/graph/scc/mod.rs +++ b/compiler/rustc_data_structures/src/graph/scc/mod.rs @@ -405,6 +405,7 @@ where /// Call this method when `inspect_node` has returned `None`. Having the /// caller decide avoids mutual recursion between the two methods and allows /// us to maintain an allocated stack for nodes on the path between calls. + #[instrument(skip(self, initial), level = "debug")] fn walk_unvisited_node(&mut self, initial: G::Node) -> WalkReturn { struct VisitingNodeFrame { node: G::Node, @@ -451,7 +452,7 @@ where Some(iter) => iter, None => { // This None marks that we still have the initialize this node's frame. - debug!("walk_unvisited_node(depth = {:?}, node = {:?})", depth, node); + debug!(?depth, ?node); debug_assert!(matches!(self.node_states[node], NodeState::NotVisited)); @@ -478,10 +479,7 @@ where return_value.take().into_iter().map(|walk| (*successor_node, Some(walk))); let successor_walk = successors.by_ref().map(|successor_node| { - debug!( - "walk_unvisited_node: node = {:?} successor_ode = {:?}", - node, successor_node - ); + debug!(?node, ?successor_node); (successor_node, self.inspect_node(successor_node)) }); @@ -491,10 +489,7 @@ where // Track the minimum depth we can reach. assert!(successor_min_depth <= depth); if successor_min_depth < *min_depth { - debug!( - "walk_unvisited_node: node = {:?} successor_min_depth = {:?}", - node, successor_min_depth - ); + debug!(?node, ?successor_min_depth); *min_depth = successor_min_depth; *min_cycle_root = successor_node; } @@ -503,16 +498,13 @@ where Some(WalkReturn::Complete { scc_index: successor_scc_index }) => { // Push the completed SCC indices onto // the `successors_stack` for later. - debug!( - "walk_unvisited_node: node = {:?} successor_scc_index = {:?}", - node, successor_scc_index - ); + debug!(?node, ?successor_scc_index); successors_stack.push(successor_scc_index); } None => { let depth = depth + 1; - debug!("walk_node(depth = {:?}, node = {:?})", depth, successor_node); + debug!(?depth, ?successor_node); // Remember which node the return value will come from. frame.successor_node = successor_node; // Start a new stack frame the step into it. diff --git a/compiler/rustc_infer/src/infer/at.rs b/compiler/rustc_infer/src/infer/at.rs index 11ee8fb17ad..cff848eeb6a 100644 --- a/compiler/rustc_infer/src/infer/at.rs +++ b/compiler/rustc_infer/src/infer/at.rs @@ -187,11 +187,11 @@ impl<'a, 'tcx> At<'a, 'tcx> { impl<'a, 'tcx> Trace<'a, 'tcx> { /// Makes `a <: b` where `a` may or may not be expected (if /// `a_is_expected` is true, then `a` is expected). + #[instrument(skip(self), level = "debug")] pub fn sub(self, a: T, b: T) -> InferResult<'tcx, ()> where T: Relate<'tcx>, { - debug!("sub({:?} <: {:?})", a, b); let Trace { at, trace, a_is_expected } = self; at.infcx.commit_if_ok(|_| { let mut fields = at.infcx.combine_fields(trace, at.param_env); @@ -204,11 +204,11 @@ impl<'a, 'tcx> Trace<'a, 'tcx> { /// Makes `a == b`; the expectation is set by the call to /// `trace()`. + #[instrument(skip(self), level = "debug")] pub fn eq(self, a: T, b: T) -> InferResult<'tcx, ()> where T: Relate<'tcx>, { - debug!("eq({:?} == {:?})", a, b); let Trace { at, trace, a_is_expected } = self; at.infcx.commit_if_ok(|_| { let mut fields = at.infcx.combine_fields(trace, at.param_env); @@ -219,11 +219,11 @@ impl<'a, 'tcx> Trace<'a, 'tcx> { }) } + #[instrument(skip(self), level = "debug")] pub fn lub(self, a: T, b: T) -> InferResult<'tcx, T> where T: Relate<'tcx>, { - debug!("lub({:?} \\/ {:?})", a, b); let Trace { at, trace, a_is_expected } = self; at.infcx.commit_if_ok(|_| { let mut fields = at.infcx.combine_fields(trace, at.param_env); @@ -234,11 +234,11 @@ impl<'a, 'tcx> Trace<'a, 'tcx> { }) } + #[instrument(skip(self), level = "debug")] pub fn glb(self, a: T, b: T) -> InferResult<'tcx, T> where T: Relate<'tcx>, { - debug!("glb({:?} /\\ {:?})", a, b); let Trace { at, trace, a_is_expected } = self; at.infcx.commit_if_ok(|_| { let mut fields = at.infcx.combine_fields(trace, at.param_env); diff --git a/compiler/rustc_infer/src/infer/canonical/query_response.rs b/compiler/rustc_infer/src/infer/canonical/query_response.rs index b5c03072557..2296cc6129a 100644 --- a/compiler/rustc_infer/src/infer/canonical/query_response.rs +++ b/compiler/rustc_infer/src/infer/canonical/query_response.rs @@ -49,6 +49,7 @@ impl<'cx, 'tcx> InferCtxt<'cx, 'tcx> { /// the same thing happens, but the resulting query is marked as ambiguous. /// - Finally, if any of the obligations result in a hard error, /// then `Err(NoSolution)` is returned. + #[instrument(skip(self, inference_vars, answer, fulfill_cx), level = "trace")] pub fn make_canonicalized_query_response( &self, inference_vars: CanonicalVarValues<'tcx>, @@ -62,7 +63,7 @@ impl<'cx, 'tcx> InferCtxt<'cx, 'tcx> { let query_response = self.make_query_response(inference_vars, answer, fulfill_cx)?; let canonical_result = self.canonicalize_response(query_response); - debug!("make_canonicalized_query_response: canonical_result = {:#?}", canonical_result); + debug!("canonical_result = {:#?}", canonical_result); Ok(self.tcx.arena.alloc(canonical_result)) } @@ -94,6 +95,7 @@ impl<'cx, 'tcx> InferCtxt<'cx, 'tcx> { /// Helper for `make_canonicalized_query_response` that does /// everything up until the final canonicalization. + #[instrument(skip(self, fulfill_cx), level = "debug")] fn make_query_response( &self, inference_vars: CanonicalVarValues<'tcx>, @@ -105,13 +107,6 @@ impl<'cx, 'tcx> InferCtxt<'cx, 'tcx> { { let tcx = self.tcx; - debug!( - "make_query_response(\ - inference_vars={:?}, \ - answer={:?})", - inference_vars, answer, - ); - // Select everything, returning errors. let true_errors = fulfill_cx.select_where_possible(self).err().unwrap_or_else(Vec::new); debug!("true_errors = {:#?}", true_errors); diff --git a/compiler/rustc_infer/src/infer/fudge.rs b/compiler/rustc_infer/src/infer/fudge.rs index 35ebe92c592..773753a0363 100644 --- a/compiler/rustc_infer/src/infer/fudge.rs +++ b/compiler/rustc_infer/src/infer/fudge.rs @@ -94,13 +94,12 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { /// the actual types (`?T`, `Option`) -- and remember that /// after the snapshot is popped, the variable `?T` is no longer /// unified. + #[instrument(skip(self, f), level = "debug")] pub fn fudge_inference_if_ok(&self, f: F) -> Result where F: FnOnce() -> Result, T: TypeFoldable<'tcx>, { - debug!("fudge_inference_if_ok()"); - let variable_lengths = self.variable_lengths(); let (mut fudger, value) = self.probe(|_| { match f() { diff --git a/compiler/rustc_infer/src/infer/higher_ranked/mod.rs b/compiler/rustc_infer/src/infer/higher_ranked/mod.rs index d460222df8a..ae85e55da6a 100644 --- a/compiler/rustc_infer/src/infer/higher_ranked/mod.rs +++ b/compiler/rustc_infer/src/infer/higher_ranked/mod.rs @@ -9,6 +9,7 @@ use rustc_middle::ty::relate::{Relate, RelateResult, TypeRelation}; use rustc_middle::ty::{self, Binder, TypeFoldable}; impl<'a, 'tcx> CombineFields<'a, 'tcx> { + #[instrument(skip(self), level = "debug")] pub fn higher_ranked_sub( &mut self, a: Binder<'tcx, T>, @@ -18,8 +19,6 @@ impl<'a, 'tcx> CombineFields<'a, 'tcx> { where T: Relate<'tcx>, { - debug!("higher_ranked_sub(a={:?}, b={:?})", a, b); - // Rather than checking the subtype relationship between `a` and `b` // as-is, we need to do some extra work here in order to make sure // that function subtyping works correctly with respect to regions diff --git a/compiler/rustc_infer/src/infer/mod.rs b/compiler/rustc_infer/src/infer/mod.rs index 632e792bbd1..18836d5a68e 100644 --- a/compiler/rustc_infer/src/infer/mod.rs +++ b/compiler/rustc_infer/src/infer/mod.rs @@ -807,8 +807,8 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { } } + #[instrument(skip(self, snapshot), level = "debug")] fn rollback_to(&self, cause: &str, snapshot: CombinedSnapshot<'a, 'tcx>) { - debug!("rollback_to(cause={})", cause); let CombinedSnapshot { undo_snapshot, region_constraints_snapshot, @@ -825,8 +825,8 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { inner.unwrap_region_constraints().rollback_to(region_constraints_snapshot); } + #[instrument(skip(self, snapshot), level = "debug")] fn commit_from(&self, snapshot: CombinedSnapshot<'a, 'tcx>) { - debug!("commit_from()"); let CombinedSnapshot { undo_snapshot, region_constraints_snapshot: _, @@ -841,11 +841,11 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { } /// Executes `f` and commit the bindings. + #[instrument(skip(self, f), level = "debug")] pub fn commit_unconditionally(&self, f: F) -> R where F: FnOnce(&CombinedSnapshot<'a, 'tcx>) -> R, { - debug!("commit_unconditionally()"); let snapshot = self.start_snapshot(); let r = f(&snapshot); self.commit_from(snapshot); @@ -853,11 +853,11 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { } /// Execute `f` and commit the bindings if closure `f` returns `Ok(_)`. + #[instrument(skip(self, f), level = "debug")] pub fn commit_if_ok(&self, f: F) -> Result where F: FnOnce(&CombinedSnapshot<'a, 'tcx>) -> Result, { - debug!("commit_if_ok()"); let snapshot = self.start_snapshot(); let r = f(&snapshot); debug!("commit_if_ok() -- r.is_ok() = {}", r.is_ok()); @@ -873,11 +873,11 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { } /// Execute `f` then unroll any bindings it creates. + #[instrument(skip(self, f), level = "debug")] pub fn probe(&self, f: F) -> R where F: FnOnce(&CombinedSnapshot<'a, 'tcx>) -> R, { - debug!("probe()"); let snapshot = self.start_snapshot(); let r = f(&snapshot); self.rollback_to("probe", snapshot); @@ -885,11 +885,11 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { } /// If `should_skip` is true, then execute `f` then unroll any bindings it creates. + #[instrument(skip(self, f), level = "debug")] pub fn probe_maybe_skip_leak_check(&self, should_skip: bool, f: F) -> R where F: FnOnce(&CombinedSnapshot<'a, 'tcx>) -> R, { - debug!("probe()"); let snapshot = self.start_snapshot(); let was_skip_leak_check = self.skip_leak_check.get(); if should_skip { @@ -946,18 +946,19 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { }) } + #[instrument(skip(self), level = "debug")] pub fn sub_regions( &self, origin: SubregionOrigin<'tcx>, a: ty::Region<'tcx>, b: ty::Region<'tcx>, ) { - debug!("sub_regions({:?} <: {:?})", a, b); self.inner.borrow_mut().unwrap_region_constraints().make_subregion(origin, a, b); } /// Require that the region `r` be equal to one of the regions in /// the set `regions`. + #[instrument(skip(self), level = "debug")] pub fn member_constraint( &self, opaque_type_def_id: DefId, @@ -966,7 +967,6 @@ impl<'a, 'tcx> InferCtxt<'a, 'tcx> { region: ty::Region<'tcx>, in_regions: &Lrc>>, ) { - debug!("member_constraint({:?} <: {:?})", region, in_regions); self.inner.borrow_mut().unwrap_region_constraints().member_constraint( opaque_type_def_id, definition_span, diff --git a/compiler/rustc_infer/src/infer/nll_relate/mod.rs b/compiler/rustc_infer/src/infer/nll_relate/mod.rs index 73d74584a5e..29a9cbc7a99 100644 --- a/compiler/rustc_infer/src/infer/nll_relate/mod.rs +++ b/compiler/rustc_infer/src/infer/nll_relate/mod.rs @@ -507,6 +507,7 @@ where true } + #[instrument(skip(self, info), level = "trace")] fn relate_with_variance>( &mut self, variance: ty::Variance, @@ -514,23 +515,22 @@ where a: T, b: T, ) -> RelateResult<'tcx, T> { - debug!("relate_with_variance(variance={:?}, a={:?}, b={:?})", variance, a, b); - let old_ambient_variance = self.ambient_variance; self.ambient_variance = self.ambient_variance.xform(variance); self.ambient_variance_info = self.ambient_variance_info.xform(info); - debug!("relate_with_variance: ambient_variance = {:?}", self.ambient_variance); + debug!(?self.ambient_variance); let r = self.relate(a, b)?; self.ambient_variance = old_ambient_variance; - debug!("relate_with_variance: r={:?}", r); + debug!(?r); Ok(r) } + #[instrument(skip(self), level = "debug")] fn tys(&mut self, a: Ty<'tcx>, mut b: Ty<'tcx>) -> RelateResult<'tcx, Ty<'tcx>> { let a = self.infcx.shallow_resolve(a); @@ -573,7 +573,7 @@ where } _ => { - debug!("tys(a={:?}, b={:?}, variance={:?})", a, b, self.ambient_variance); + debug!(?a, ?b, ?self.ambient_variance); // Will also handle unification of `IntVar` and `FloatVar`. self.infcx.super_combine_tys(self, a, b) @@ -581,18 +581,19 @@ where } } + #[instrument(skip(self), level = "trace")] fn regions( &mut self, a: ty::Region<'tcx>, b: ty::Region<'tcx>, ) -> RelateResult<'tcx, ty::Region<'tcx>> { - debug!("regions(a={:?}, b={:?}, variance={:?})", a, b, self.ambient_variance); + debug!(?self.ambient_variance); let v_a = self.replace_bound_region(a, ty::INNERMOST, &self.a_scopes); let v_b = self.replace_bound_region(b, ty::INNERMOST, &self.b_scopes); - debug!("regions: v_a = {:?}", v_a); - debug!("regions: v_b = {:?}", v_b); + debug!(?v_a); + debug!(?v_b); if self.ambient_covariance() { // Covariance: a <= b. Hence, `b: a`. @@ -628,6 +629,7 @@ where } } + #[instrument(skip(self), level = "trace")] fn binders( &mut self, a: ty::Binder<'tcx, T>, @@ -655,7 +657,7 @@ where // - Instantiate binders on `b` universally, yielding a universe U1. // - Instantiate binders on `a` existentially in U1. - debug!("binders({:?}: {:?}, ambient_variance={:?})", a, b, self.ambient_variance); + debug!(?self.ambient_variance); if let (Some(a), Some(b)) = (a.no_bound_vars(), b.no_bound_vars()) { // Fast path for the common case. @@ -673,8 +675,8 @@ where let b_scope = self.create_scope(b, UniversallyQuantified(true)); let a_scope = self.create_scope(a, UniversallyQuantified(false)); - debug!("binders: a_scope = {:?} (existential)", a_scope); - debug!("binders: b_scope = {:?} (universal)", b_scope); + debug!(?a_scope, "(existential)"); + debug!(?b_scope, "(universal)"); self.b_scopes.push(b_scope); self.a_scopes.push(a_scope); @@ -717,8 +719,8 @@ where let a_scope = self.create_scope(a, UniversallyQuantified(true)); let b_scope = self.create_scope(b, UniversallyQuantified(false)); - debug!("binders: a_scope = {:?} (universal)", a_scope); - debug!("binders: b_scope = {:?} (existential)", b_scope); + debug!(?a_scope, "(universal)"); + debug!(?b_scope, "(existential)"); self.a_scopes.push(a_scope); self.b_scopes.push(b_scope); diff --git a/compiler/rustc_infer/src/infer/region_constraints/mod.rs b/compiler/rustc_infer/src/infer/region_constraints/mod.rs index af31ab0923d..df4fdb3a982 100644 --- a/compiler/rustc_infer/src/infer/region_constraints/mod.rs +++ b/compiler/rustc_infer/src/infer/region_constraints/mod.rs @@ -540,6 +540,7 @@ impl<'tcx> RegionConstraintCollector<'_, 'tcx> { }); } + #[instrument(skip(self, origin), level = "debug")] pub fn make_subregion( &mut self, origin: SubregionOrigin<'tcx>, @@ -547,10 +548,7 @@ impl<'tcx> RegionConstraintCollector<'_, 'tcx> { sup: Region<'tcx>, ) { // cannot add constraints once regions are resolved - debug!( - "RegionConstraintCollector: make_subregion({:?}, {:?}) due to {:?}", - sub, sup, origin - ); + debug!("origin = {:#?}", origin); match (sub, sup) { (&ReLateBound(..), _) | (_, &ReLateBound(..)) => { diff --git a/compiler/rustc_middle/src/ty/fold.rs b/compiler/rustc_middle/src/ty/fold.rs index a04b0a7ef61..e16491dcc90 100644 --- a/compiler/rustc_middle/src/ty/fold.rs +++ b/compiler/rustc_middle/src/ty/fold.rs @@ -79,6 +79,7 @@ pub trait TypeFoldable<'tcx>: fmt::Debug + Clone { == Some(FoundFlags) } + #[instrument(level = "trace")] fn has_type_flags(&self, flags: TypeFlags) -> bool { self.visit_with(&mut HasTypeFlagsVisitor { tcx: None, flags }).break_value() == Some(FoundFlags) @@ -476,21 +477,16 @@ impl<'a, 'tcx> TypeFolder<'tcx> for RegionFolder<'a, 'tcx> { t } + #[instrument(skip(self), level = "debug")] fn fold_region(&mut self, r: ty::Region<'tcx>) -> ty::Region<'tcx> { match *r { ty::ReLateBound(debruijn, _) if debruijn < self.current_index => { - debug!( - "RegionFolder.fold_region({:?}) skipped bound region (current index={:?})", - r, self.current_index - ); + debug!(?self.current_index, "skipped bound region"); *self.skipped_regions = true; r } _ => { - debug!( - "RegionFolder.fold_region({:?}) folding free region (current_index={:?})", - r, self.current_index - ); + debug!(?self.current_index, "folding free region"); (self.fold_region_fn)(r, self.current_index) } } @@ -1125,6 +1121,12 @@ struct HasTypeFlagsVisitor<'tcx> { flags: ty::TypeFlags, } +impl std::fmt::Debug for HasTypeFlagsVisitor<'tcx> { + fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + self.flags.fmt(fmt) + } +} + impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { type BreakTy = FoundFlags; fn tcx_for_anon_const_substs(&self) -> Option> { @@ -1132,9 +1134,10 @@ impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { } #[inline] + #[instrument(level = "trace")] fn visit_ty(&mut self, t: Ty<'tcx>) -> ControlFlow { let flags = t.flags(); - debug!("HasTypeFlagsVisitor: t={:?} flags={:?} self.flags={:?}", t, flags, self.flags); + trace!(t.flags=?t.flags()); if flags.intersects(self.flags) { ControlFlow::Break(FoundFlags) } else { @@ -1146,9 +1149,10 @@ impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { } #[inline] + #[instrument(skip(self), level = "trace")] fn visit_region(&mut self, r: ty::Region<'tcx>) -> ControlFlow { let flags = r.type_flags(); - debug!("HasTypeFlagsVisitor: r={:?} r.flags={:?} self.flags={:?}", r, flags, self.flags); + trace!(r.flags=?flags); if flags.intersects(self.flags) { ControlFlow::Break(FoundFlags) } else { @@ -1157,9 +1161,10 @@ impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { } #[inline] + #[instrument(level = "trace")] fn visit_const(&mut self, c: &'tcx ty::Const<'tcx>) -> ControlFlow { let flags = FlagComputation::for_const(c); - debug!("HasTypeFlagsVisitor: c={:?} c.flags={:?} self.flags={:?}", c, flags, self.flags); + trace!(r.flags=?flags); if flags.intersects(self.flags) { ControlFlow::Break(FoundFlags) } else { @@ -1171,9 +1176,10 @@ impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { } #[inline] + #[instrument(level = "trace")] fn visit_unevaluated_const(&mut self, uv: ty::Unevaluated<'tcx>) -> ControlFlow { let flags = FlagComputation::for_unevaluated_const(uv); - debug!("HasTypeFlagsVisitor: uv={:?} uv.flags={:?} self.flags={:?}", uv, flags, self.flags); + trace!(r.flags=?flags); if flags.intersects(self.flags) { ControlFlow::Break(FoundFlags) } else { @@ -1185,12 +1191,10 @@ impl<'tcx> TypeVisitor<'tcx> for HasTypeFlagsVisitor<'tcx> { } #[inline] + #[instrument(level = "trace")] fn visit_predicate(&mut self, predicate: ty::Predicate<'tcx>) -> ControlFlow { let flags = predicate.inner.flags; - debug!( - "HasTypeFlagsVisitor: predicate={:?} flags={:?} self.flags={:?}", - predicate, flags, self.flags - ); + trace!(predicate.flags=?flags); if flags.intersects(self.flags) { ControlFlow::Break(FoundFlags) } else { diff --git a/compiler/rustc_middle/src/ty/print/mod.rs b/compiler/rustc_middle/src/ty/print/mod.rs index 13e2122a619..308b4d2fefc 100644 --- a/compiler/rustc_middle/src/ty/print/mod.rs +++ b/compiler/rustc_middle/src/ty/print/mod.rs @@ -98,14 +98,14 @@ pub trait Printer<'tcx>: Sized { // Defaults (should not be overridden): + #[instrument(skip(self), level = "debug")] fn default_print_def_path( self, def_id: DefId, substs: &'tcx [GenericArg<'tcx>], ) -> Result { - debug!("default_print_def_path: def_id={:?}, substs={:?}", def_id, substs); let key = self.tcx().def_key(def_id); - debug!("default_print_def_path: key={:?}", key); + debug!(?key); match key.disambiguated_data.data { DefPathData::CrateRoot => { diff --git a/compiler/rustc_middle/src/ty/print/pretty.rs b/compiler/rustc_middle/src/ty/print/pretty.rs index d99534c200a..b8bca6363db 100644 --- a/compiler/rustc_middle/src/ty/print/pretty.rs +++ b/compiler/rustc_middle/src/ty/print/pretty.rs @@ -2033,12 +2033,11 @@ impl FmtPrinter<'_, 'tcx, F> { Ok(inner) } + #[instrument(skip(self), level = "debug")] fn prepare_late_bound_region_info(&mut self, value: &ty::Binder<'tcx, T>) where T: TypeFoldable<'tcx>, { - debug!("prepare_late_bound_region_info(value: {:?})", value); - struct LateBoundRegionNameCollector<'a, 'tcx> { tcx: TyCtxt<'tcx>, used_region_names: &'a mut FxHashSet, @@ -2052,8 +2051,9 @@ impl FmtPrinter<'_, 'tcx, F> { Some(self.tcx) } + #[instrument(skip(self), level = "trace")] fn visit_region(&mut self, r: ty::Region<'tcx>) -> ControlFlow { - debug!("LateBoundRegionNameCollector::visit_region(r: {:?}, address: {:p})", r, &r); + trace!("address: {:p}", r); if let ty::ReLateBound(_, ty::BoundRegion { kind: ty::BrNamed(_, name), .. }) = *r { self.used_region_names.insert(name); } else if let ty::RePlaceholder(ty::PlaceholderRegion { @@ -2068,8 +2068,8 @@ impl FmtPrinter<'_, 'tcx, F> { // We collect types in order to prevent really large types from compiling for // a really long time. See issue #83150 for why this is necessary. + #[instrument(skip(self), level = "trace")] fn visit_ty(&mut self, ty: Ty<'tcx>) -> ControlFlow { - debug!("LateBoundRegionNameCollector::visit_ty(ty: {:?}", ty); let not_previously_inserted = self.type_collector.insert(ty); if not_previously_inserted { ty.super_visit_with(self) diff --git a/compiler/rustc_middle/src/ty/util.rs b/compiler/rustc_middle/src/ty/util.rs index 2ec06d472fe..d4032cdf696 100644 --- a/compiler/rustc_middle/src/ty/util.rs +++ b/compiler/rustc_middle/src/ty/util.rs @@ -516,6 +516,7 @@ impl<'tcx> TyCtxt<'tcx> { } /// Expands the given impl trait type, stopping if the type is recursive. + #[instrument(skip(self), level = "debug")] pub fn try_expand_impl_trait_type( self, def_id: DefId, @@ -532,6 +533,7 @@ impl<'tcx> TyCtxt<'tcx> { }; let expanded_type = visitor.expand_opaque_ty(def_id, substs).unwrap(); + trace!(?expanded_type); if visitor.found_recursion { Err(expanded_type) } else { Ok(expanded_type) } } } diff --git a/compiler/rustc_mir_dataflow/src/impls/mod.rs b/compiler/rustc_mir_dataflow/src/impls/mod.rs index 771ad90af28..474f4f2a79b 100644 --- a/compiler/rustc_mir_dataflow/src/impls/mod.rs +++ b/compiler/rustc_mir_dataflow/src/impls/mod.rs @@ -602,6 +602,7 @@ impl<'tcx> AnalysisDomain<'tcx> for EverInitializedPlaces<'_, 'tcx> { impl<'tcx> GenKillAnalysis<'tcx> for EverInitializedPlaces<'_, 'tcx> { type Idx = InitIndex; + #[instrument(skip(self, trans), level = "debug")] fn statement_effect( &self, trans: &mut impl GenKill, @@ -613,24 +614,19 @@ impl<'tcx> GenKillAnalysis<'tcx> for EverInitializedPlaces<'_, 'tcx> { let init_loc_map = &move_data.init_loc_map; let rev_lookup = &move_data.rev_lookup; - debug!( - "statement {:?} at loc {:?} initializes move_indexes {:?}", - stmt, location, &init_loc_map[location] - ); + debug!("initializes move_indexes {:?}", &init_loc_map[location]); trans.gen_all(init_loc_map[location].iter().copied()); if let mir::StatementKind::StorageDead(local) = stmt.kind { // End inits for StorageDead, so that an immutable variable can // be reinitialized on the next iteration of the loop. let move_path_index = rev_lookup.find_local(local); - debug!( - "stmt {:?} at loc {:?} clears the ever initialized status of {:?}", - stmt, location, &init_path_map[move_path_index] - ); + debug!("clears the ever initialized status of {:?}", init_path_map[move_path_index]); trans.kill_all(init_path_map[move_path_index].iter().copied()); } } + #[instrument(skip(self, trans, _terminator), level = "debug")] fn terminator_effect( &self, trans: &mut impl GenKill, @@ -640,10 +636,8 @@ impl<'tcx> GenKillAnalysis<'tcx> for EverInitializedPlaces<'_, 'tcx> { let (body, move_data) = (self.body, self.move_data()); let term = body[location.block].terminator(); let init_loc_map = &move_data.init_loc_map; - debug!( - "terminator {:?} at loc {:?} initializes move_indexes {:?}", - term, location, &init_loc_map[location] - ); + debug!(?term); + debug!("initializes move_indexes {:?}", init_loc_map[location]); trans.gen_all( init_loc_map[location] .iter() diff --git a/compiler/rustc_resolve/src/late/lifetimes.rs b/compiler/rustc_resolve/src/late/lifetimes.rs index 84e7c68713f..eb6f302a11d 100644 --- a/compiler/rustc_resolve/src/late/lifetimes.rs +++ b/compiler/rustc_resolve/src/late/lifetimes.rs @@ -2740,6 +2740,7 @@ impl<'a, 'tcx> LifetimeContext<'a, 'tcx> { for input in inputs { gather.visit_ty(input); } + trace!(?gather.anon_count); let late_bound_vars = self.map.late_bound_vars.entry(hir_id).or_default(); let named_late_bound_vars = late_bound_vars.len() as u32; late_bound_vars.extend( @@ -3028,6 +3029,7 @@ impl<'a, 'tcx> LifetimeContext<'a, 'tcx> { NestedVisitorMap::None } + #[instrument(skip(self), level = "trace")] fn visit_ty(&mut self, ty: &hir::Ty<'_>) { // If we enter a `BareFn`, then we enter a *new* binding scope if let hir::TyKind::BareFn(_) = ty.kind { @@ -3048,6 +3050,7 @@ impl<'a, 'tcx> LifetimeContext<'a, 'tcx> { intravisit::walk_generic_args(self, path_span, generic_args) } + #[instrument(skip(self), level = "trace")] fn visit_lifetime(&mut self, lifetime_ref: &hir::Lifetime) { if lifetime_ref.is_elided() { self.anon_count += 1; diff --git a/compiler/rustc_resolve/src/lib.rs b/compiler/rustc_resolve/src/lib.rs index 1cbe8f41d92..10eef7d31e6 100644 --- a/compiler/rustc_resolve/src/lib.rs +++ b/compiler/rustc_resolve/src/lib.rs @@ -20,6 +20,9 @@ #![recursion_limit = "256"] #![allow(rustdoc::private_intra_doc_links)] +#[macro_use] +extern crate tracing; + pub use rustc_hir::def::{Namespace, PerNS}; use Determinacy::*; diff --git a/compiler/rustc_trait_selection/src/opaque_types.rs b/compiler/rustc_trait_selection/src/opaque_types.rs index 028f6e89f18..c2205462680 100644 --- a/compiler/rustc_trait_selection/src/opaque_types.rs +++ b/compiler/rustc_trait_selection/src/opaque_types.rs @@ -517,6 +517,7 @@ impl<'a, 'tcx> InferCtxtExt<'tcx> for InferCtxt<'a, 'tcx> { debug!(?id_substs); let map: FxHashMap, GenericArg<'tcx>> = substs.iter().enumerate().map(|(index, subst)| (subst, id_substs[index])).collect(); + debug!("map = {:#?}", map); // Convert the type from the function into a type valid outside // the function, by replacing invalid regions with 'static, @@ -672,6 +673,7 @@ impl TypeFolder<'tcx> for ReverseMapper<'tcx> { self.tcx } + #[instrument(skip(self), level = "debug")] fn fold_region(&mut self, r: ty::Region<'tcx>) -> ty::Region<'tcx> { match r { // Ignore bound regions and `'static` regions that appear in the @@ -1098,18 +1100,17 @@ fn may_define_opaque_type(tcx: TyCtxt<'_>, def_id: LocalDefId, opaque_hir_id: hi /// /// Requires that trait definitions have been processed so that we can /// elaborate predicates and walk supertraits. +#[instrument(skip(tcx, predicates), level = "debug")] crate fn required_region_bounds( tcx: TyCtxt<'tcx>, erased_self_ty: Ty<'tcx>, predicates: impl Iterator>, ) -> Vec> { - debug!("required_region_bounds(erased_self_ty={:?})", erased_self_ty); - assert!(!erased_self_ty.has_escaping_bound_vars()); traits::elaborate_predicates(tcx, predicates) .filter_map(|obligation| { - debug!("required_region_bounds(obligation={:?})", obligation); + debug!(?obligation); match obligation.predicate.kind().skip_binder() { ty::PredicateKind::Projection(..) | ty::PredicateKind::Trait(..) diff --git a/compiler/rustc_trait_selection/src/traits/error_reporting/mod.rs b/compiler/rustc_trait_selection/src/traits/error_reporting/mod.rs index e435154d931..b751918463b 100644 --- a/compiler/rustc_trait_selection/src/traits/error_reporting/mod.rs +++ b/compiler/rustc_trait_selection/src/traits/error_reporting/mod.rs @@ -1195,13 +1195,13 @@ impl<'a, 'tcx> InferCtxtPrivExt<'tcx> for InferCtxt<'a, 'tcx> { false } + #[instrument(skip(self), level = "debug")] fn report_fulfillment_error( &self, error: &FulfillmentError<'tcx>, body_id: Option, fallback_has_occurred: bool, ) { - debug!("report_fulfillment_error({:?})", error); match error.code { FulfillmentErrorCode::CodeSelectionError(ref selection_error) => { self.report_selection_error( @@ -1528,6 +1528,7 @@ impl<'a, 'tcx> InferCtxtPrivExt<'tcx> for InferCtxt<'a, 'tcx> { ) } + #[instrument(skip(self), level = "debug")] fn maybe_report_ambiguity( &self, obligation: &PredicateObligation<'tcx>, @@ -1542,8 +1543,7 @@ impl<'a, 'tcx> InferCtxtPrivExt<'tcx> for InferCtxt<'a, 'tcx> { let span = obligation.cause.span; debug!( - "maybe_report_ambiguity(predicate={:?}, obligation={:?} body_id={:?}, code={:?})", - predicate, obligation, body_id, obligation.cause.code, + ?predicate, ?obligation.cause.code, ); // Ambiguity errors are often caused as fallout from earlier @@ -1556,7 +1556,7 @@ impl<'a, 'tcx> InferCtxtPrivExt<'tcx> for InferCtxt<'a, 'tcx> { let mut err = match bound_predicate.skip_binder() { ty::PredicateKind::Trait(data) => { let trait_ref = bound_predicate.rebind(data.trait_ref); - debug!("trait_ref {:?}", trait_ref); + debug!(?trait_ref); if predicate.references_error() { return; 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 6d64dc8254b..397f1da75ef 100644 --- a/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs +++ b/compiler/rustc_trait_selection/src/traits/select/candidate_assembly.rs @@ -220,6 +220,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { self.filter_impls(candidates.pop().unwrap().candidate, stack.obligation) } + #[instrument(skip(self, stack), level = "debug")] pub(super) fn assemble_candidates<'o>( &mut self, stack: &TraitObligationStack<'o, 'tcx>, diff --git a/compiler/rustc_trait_selection/src/traits/select/confirmation.rs b/compiler/rustc_trait_selection/src/traits/select/confirmation.rs index 9e1211336a4..8554723740f 100644 --- a/compiler/rustc_trait_selection/src/traits/select/confirmation.rs +++ b/compiler/rustc_trait_selection/src/traits/select/confirmation.rs @@ -601,12 +601,11 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { Ok(ImplSourceGeneratorData { generator_def_id, substs, nested: obligations }) } + #[instrument(skip(self), level = "debug")] fn confirm_closure_candidate( &mut self, obligation: &TraitObligation<'tcx>, ) -> Result>, SelectionError<'tcx>> { - debug!(?obligation, "confirm_closure_candidate"); - let kind = self .tcx() .fn_trait_kind_from_lang_item(obligation.predicate.def_id()) @@ -680,6 +679,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { /// because these output type parameters should not affect the /// selection of the impl. Therefore, if there is a mismatch, we /// report an error to the user. + #[instrument(skip(self), level = "trace")] fn confirm_poly_trait_refs( &mut self, obligation_cause: ObligationCause<'tcx>, diff --git a/compiler/rustc_trait_selection/src/traits/select/mod.rs b/compiler/rustc_trait_selection/src/traits/select/mod.rs index 50d6f82ae18..af0c7c8f956 100644 --- a/compiler/rustc_trait_selection/src/traits/select/mod.rs +++ b/compiler/rustc_trait_selection/src/traits/select/mod.rs @@ -451,6 +451,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { /// Evaluates the predicates in `predicates` recursively. Note that /// this applies projections in the predicates, and therefore /// is run within an inference probe. + #[instrument(skip(self, stack), level = "debug")] fn evaluate_predicates_recursively<'o, I>( &mut self, stack: TraitObligationStackList<'o, 'tcx>, @@ -460,7 +461,6 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { I: IntoIterator> + std::fmt::Debug, { let mut result = EvaluatedToOk; - debug!(?predicates, "evaluate_predicates_recursively"); for obligation in predicates { let eval = self.evaluate_predicate_recursively(stack, obligation.clone())?; if let EvaluatedToErr = eval { @@ -683,13 +683,12 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { result } + #[instrument(skip(self, previous_stack), level = "debug")] fn evaluate_trait_predicate_recursively<'o>( &mut self, previous_stack: TraitObligationStackList<'o, 'tcx>, mut obligation: TraitObligation<'tcx>, ) -> Result { - debug!(?obligation, "evaluate_trait_predicate_recursively"); - if !self.intercrate && obligation.is_global(self.tcx()) && obligation @@ -701,7 +700,7 @@ 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"); + debug!("in global"); obligation.param_env = obligation.param_env.without_caller_bounds(); } @@ -753,7 +752,7 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { } else { debug!(?result, "PROVISIONAL"); debug!( - "evaluate_trait_predicate_recursively: caching provisionally because {:?} \ + "caching provisionally because {:?} \ is a cycle participant (at depth {}, reached depth {})", fresh_trait_ref, stack.depth, reached_depth, ); @@ -2124,13 +2123,12 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { /// Returns `Ok` if `poly_trait_ref` being true implies that the /// obligation is satisfied. + #[instrument(skip(self), level = "debug")] fn match_poly_trait_ref( &mut self, obligation: &TraitObligation<'tcx>, poly_trait_ref: ty::PolyTraitRef<'tcx>, ) -> Result>, ()> { - debug!(?obligation, ?poly_trait_ref, "match_poly_trait_ref"); - self.infcx .at(&obligation.cause, obligation.param_env) .sup(obligation.predicate.to_poly_trait_ref(), poly_trait_ref) @@ -2174,12 +2172,12 @@ impl<'cx, 'tcx> SelectionContext<'cx, 'tcx> { } } + #[instrument(skip(self), level = "debug")] fn closure_trait_ref_unnormalized( &mut self, obligation: &TraitObligation<'tcx>, substs: SubstsRef<'tcx>, ) -> ty::PolyTraitRef<'tcx> { - debug!(?obligation, ?substs, "closure_trait_ref_unnormalized"); let closure_sig = substs.as_closure().sig(); debug!(?closure_sig); diff --git a/compiler/rustc_typeck/src/astconv/generics.rs b/compiler/rustc_typeck/src/astconv/generics.rs index fd0544a47bb..27d76a69359 100644 --- a/compiler/rustc_typeck/src/astconv/generics.rs +++ b/compiler/rustc_typeck/src/astconv/generics.rs @@ -441,6 +441,7 @@ impl<'o, 'tcx> dyn AstConv<'tcx> + 'o { /// Checks that the correct number of generic arguments have been provided. /// This is used both for datatypes and function calls. + #[instrument(skip(tcx, gen_pos), level = "debug")] pub(crate) fn check_generic_arg_count( tcx: TyCtxt<'_>, span: Span, @@ -452,11 +453,6 @@ impl<'o, 'tcx> dyn AstConv<'tcx> + 'o { has_self: bool, infer_args: bool, ) -> GenericArgCountResult { - debug!( - "check_generic_arg_count(span: {:?}, def_id: {:?}, seg: {:?}, gen_params: {:?}, gen_args: {:?})", - span, def_id, seg, gen_params, gen_args - ); - let default_counts = gen_params.own_defaults(); let param_counts = gen_params.own_counts(); @@ -556,9 +552,12 @@ impl<'o, 'tcx> dyn AstConv<'tcx> + 'o { let mut check_types_and_consts = |expected_min, expected_max, provided, params_offset, args_offset| { debug!( - "check_types_and_consts(expected_min: {:?}, expected_max: {:?}, \ - provided: {:?}, params_offset: {:?}, args_offset: {:?}", - expected_min, expected_max, provided, params_offset, args_offset + ?expected_min, + ?expected_max, + ?provided, + ?params_offset, + ?args_offset, + "check_types_and_consts" ); if (expected_min..=expected_max).contains(&provided) { return true; @@ -589,7 +588,7 @@ impl<'o, 'tcx> dyn AstConv<'tcx> + 'o { } }; - debug!("gen_args_info: {:?}", gen_args_info); + debug!(?gen_args_info); WrongNumberOfGenericArgs::new( tcx, @@ -614,8 +613,8 @@ impl<'o, 'tcx> dyn AstConv<'tcx> + 'o { - default_counts.types - default_counts.consts }; - debug!("expected_min: {:?}", expected_min); - debug!("arg_counts.lifetimes: {:?}", gen_args.num_lifetime_params()); + debug!(?expected_min); + debug!(arg_counts.lifetimes=?gen_args.num_lifetime_params()); check_types_and_consts( expected_min, diff --git a/compiler/rustc_typeck/src/check/check.rs b/compiler/rustc_typeck/src/check/check.rs index 9f0ed0cd18d..c1d14413554 100644 --- a/compiler/rustc_typeck/src/check/check.rs +++ b/compiler/rustc_typeck/src/check/check.rs @@ -70,6 +70,7 @@ pub(super) fn check_abi(tcx: TyCtxt<'_>, hir_id: hir::HirId, span: Span, abi: Ab /// /// * ... /// * inherited: other fields inherited from the enclosing fn (if any) +#[instrument(skip(inherited, body), level = "debug")] pub(super) fn check_fn<'a, 'tcx>( inherited: &'a Inherited<'a, 'tcx>, param_env: ty::ParamEnv<'tcx>, @@ -82,8 +83,6 @@ pub(super) fn check_fn<'a, 'tcx>( ) -> (FnCtxt<'a, 'tcx>, Option>) { let mut fn_sig = fn_sig; - debug!("check_fn(sig={:?}, fn_id={}, param_env={:?})", fn_sig, fn_id, param_env); - // Create the function context. This is either derived from scratch or, // in the case of closures, based on the outer context. let mut fcx = FnCtxt::new(inherited, param_env, body.value.hir_id); diff --git a/compiler/rustc_typeck/src/check/closure.rs b/compiler/rustc_typeck/src/check/closure.rs index 65ba1c08b62..410ac24b1f1 100644 --- a/compiler/rustc_typeck/src/check/closure.rs +++ b/compiler/rustc_typeck/src/check/closure.rs @@ -33,6 +33,7 @@ struct ClosureSignatures<'tcx> { } impl<'a, 'tcx> FnCtxt<'a, 'tcx> { + #[instrument(skip(self, expr, _capture, decl, body_id), level = "debug")] pub fn check_expr_closure( &self, expr: &hir::Expr<'_>, @@ -42,7 +43,8 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { gen: Option, expected: Expectation<'tcx>, ) -> Ty<'tcx> { - debug!("check_expr_closure(expr={:?},expected={:?})", expr, expected); + trace!("decl = {:#?}", decl); + trace!("expr = {:#?}", expr); // It's always helpful for inference if we know the kind of // closure sooner rather than later, so first examine the expected @@ -55,6 +57,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { self.check_closure(expr, expected_kind, decl, body, gen, expected_sig) } + #[instrument(skip(self, expr, body, decl), level = "debug")] fn check_closure( &self, expr: &hir::Expr<'_>, @@ -64,14 +67,14 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { gen: Option, expected_sig: Option>, ) -> Ty<'tcx> { - debug!("check_closure(opt_kind={:?}, expected_sig={:?})", opt_kind, expected_sig); - + trace!("decl = {:#?}", decl); let expr_def_id = self.tcx.hir().local_def_id(expr.hir_id); + debug!(?expr_def_id); let ClosureSignatures { bound_sig, liberated_sig } = self.sig_of_closure(expr.hir_id, expr_def_id.to_def_id(), decl, body, expected_sig); - debug!("check_closure: ty_of_closure returns {:?}", liberated_sig); + debug!(?bound_sig, ?liberated_sig); let return_type_pre_known = !liberated_sig.output().is_ty_infer(); @@ -130,10 +133,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { ) }); - debug!( - "check_closure: expr_def_id={:?}, sig={:?}, opt_kind={:?}", - expr_def_id, sig, opt_kind - ); + debug!(?sig, ?opt_kind); let closure_kind_ty = match opt_kind { Some(kind) => kind.to_ty(self.tcx), @@ -159,19 +159,18 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { let closure_type = self.tcx.mk_closure(expr_def_id.to_def_id(), closure_substs.substs); - debug!("check_closure: expr.hir_id={:?} closure_type={:?}", expr.hir_id, closure_type); + debug!(?expr.hir_id, ?closure_type); closure_type } /// Given the expected type, figures out what it can about this closure we /// are about to type check: + #[instrument(skip(self), level = "debug")] fn deduce_expectations_from_expected_type( &self, expected_ty: Ty<'tcx>, ) -> (Option>, Option) { - debug!("deduce_expectations_from_expected_type(expected_ty={:?})", expected_ty); - match *expected_ty.kind() { ty::Dynamic(ref object_type, ..) => { let sig = object_type.projection_bounds().find_map(|pb| { @@ -314,6 +313,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// If there is no expected signature, then we will convert the /// types that the user gave into a signature. + #[instrument(skip(self, hir_id, expr_def_id, decl, body), level = "debug")] fn sig_of_closure_no_expectation( &self, hir_id: hir::HirId, @@ -321,8 +321,6 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { decl: &hir::FnDecl<'_>, body: &hir::Body<'_>, ) -> ClosureSignatures<'tcx> { - debug!("sig_of_closure_no_expectation()"); - let bound_sig = self.supplied_sig_of_closure(hir_id, expr_def_id, decl, body); self.closure_sigs(expr_def_id, body, bound_sig) @@ -375,6 +373,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// - `expected_sig`: the expected signature (if any). Note that /// this is missing a binder: that is, there may be late-bound /// regions with depth 1, which are bound then by the closure. + #[instrument(skip(self, hir_id, expr_def_id, decl, body), level = "debug")] fn sig_of_closure_with_expectation( &self, hir_id: hir::HirId, @@ -383,8 +382,6 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { body: &hir::Body<'_>, expected_sig: ExpectedSig<'tcx>, ) -> ClosureSignatures<'tcx> { - debug!("sig_of_closure_with_expectation(expected_sig={:?})", expected_sig); - // Watch out for some surprises and just ignore the // expectation if things don't see to match up with what we // expect. @@ -553,6 +550,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// types that the user gave into a signature. /// /// Also, record this closure signature for later. + #[instrument(skip(self, decl, body), level = "debug")] fn supplied_sig_of_closure( &self, hir_id: hir::HirId, @@ -562,10 +560,8 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { ) -> ty::PolyFnSig<'tcx> { let astconv: &dyn AstConv<'_> = self; - debug!( - "supplied_sig_of_closure(decl={:?}, body.generator_kind={:?})", - decl, body.generator_kind, - ); + trace!("decl = {:#?}", decl); + debug!(?body.generator_kind); let bound_vars = self.tcx.late_bound_vars(hir_id); @@ -578,7 +574,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { // we expect the return type of the block to match that of the enclosing // function. Some(hir::GeneratorKind::Async(hir::AsyncGeneratorKind::Fn)) => { - debug!("supplied_sig_of_closure: closure is async fn body"); + debug!("closure is async fn body"); self.deduce_future_output_from_obligations(expr_def_id).unwrap_or_else(|| { // AFAIK, deducing the future output // always succeeds *except* in error cases @@ -606,7 +602,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { bound_vars, ); - debug!("supplied_sig_of_closure: result={:?}", result); + debug!(?result); let c_result = self.inh.infcx.canonicalize_response(result); self.typeck_results.borrow_mut().user_provided_sigs.insert(expr_def_id, c_result); diff --git a/compiler/rustc_typeck/src/check/coercion.rs b/compiler/rustc_typeck/src/check/coercion.rs index ef18c1e7779..79763942d05 100644 --- a/compiler/rustc_typeck/src/check/coercion.rs +++ b/compiler/rustc_typeck/src/check/coercion.rs @@ -482,12 +482,11 @@ impl<'f, 'tcx> Coerce<'f, 'tcx> { // &[T; n] or &mut [T; n] -> &[T] // or &mut [T; n] -> &mut [T] // or &Concrete -> &Trait, etc. + #[instrument(skip(self), level = "debug")] fn coerce_unsized(&self, mut source: Ty<'tcx>, mut target: Ty<'tcx>) -> CoerceResult<'tcx> { - debug!("coerce_unsized(source={:?}, target={:?})", source, target); - source = self.shallow_resolve(source); target = self.shallow_resolve(target); - debug!("coerce_unsized: resolved source={:?} target={:?}", source, target); + debug!(?source, ?target); // These 'if' statements require some explanation. // The `CoerceUnsized` trait is special - it is only diff --git a/compiler/rustc_typeck/src/check/demand.rs b/compiler/rustc_typeck/src/check/demand.rs index 722b110ed61..dcfbaff7ec7 100644 --- a/compiler/rustc_typeck/src/check/demand.rs +++ b/compiler/rustc_typeck/src/check/demand.rs @@ -59,6 +59,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { self.demand_suptype_with_origin(&self.misc(sp), expected, actual) } + #[instrument(skip(self), level = "debug")] pub fn demand_suptype_with_origin( &self, cause: &ObligationCause<'tcx>, diff --git a/compiler/rustc_typeck/src/check/expr.rs b/compiler/rustc_typeck/src/check/expr.rs index 8a69e0a737d..602ecd34f83 100644 --- a/compiler/rustc_typeck/src/check/expr.rs +++ b/compiler/rustc_typeck/src/check/expr.rs @@ -156,7 +156,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// Note that inspecting a type's structure *directly* may expose the fact /// that there are actually multiple representations for `Error`, so avoid /// that when err needs to be handled differently. - #[instrument(skip(self), level = "debug")] + #[instrument(skip(self, expr), level = "debug")] pub(super) fn check_expr_with_expectation( &self, expr: &'tcx hir::Expr<'tcx>, @@ -254,12 +254,13 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { ty } + #[instrument(skip(self, expr), level = "debug")] fn check_expr_kind( &self, expr: &'tcx hir::Expr<'tcx>, expected: Expectation<'tcx>, ) -> Ty<'tcx> { - debug!("check_expr_kind(expected={:?}, expr={:?})", expected, expr); + trace!("expr={:#?}", expr); let tcx = self.tcx; match expr.kind { diff --git a/compiler/rustc_typeck/src/check/fn_ctxt/_impl.rs b/compiler/rustc_typeck/src/check/fn_ctxt/_impl.rs index 553f5ed8a0c..7b9629e534b 100644 --- a/compiler/rustc_typeck/src/check/fn_ctxt/_impl.rs +++ b/compiler/rustc_typeck/src/check/fn_ctxt/_impl.rs @@ -87,23 +87,22 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { self.resolve_vars_with_obligations_and_mutate_fulfillment(ty, |_| {}) } + #[instrument(skip(self, mutate_fulfillment_errors), level = "debug")] pub(in super::super) fn resolve_vars_with_obligations_and_mutate_fulfillment( &self, mut ty: Ty<'tcx>, mutate_fulfillment_errors: impl Fn(&mut Vec>), ) -> Ty<'tcx> { - debug!("resolve_vars_with_obligations(ty={:?})", ty); - // No Infer()? Nothing needs doing. if !ty.has_infer_types_or_consts() { - debug!("resolve_vars_with_obligations: ty={:?}", ty); + debug!("no inference var, nothing needs doing"); return ty; } // If `ty` is a type variable, see whether we already know what it is. ty = self.resolve_vars_if_possible(ty); if !ty.has_infer_types_or_consts() { - debug!("resolve_vars_with_obligations: ty={:?}", ty); + debug!(?ty); return ty; } @@ -114,7 +113,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { self.select_obligations_where_possible(false, mutate_fulfillment_errors); ty = self.resolve_vars_if_possible(ty); - debug!("resolve_vars_with_obligations: ty={:?}", ty); + debug!(?ty); ty } @@ -230,6 +229,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// This should be invoked **before any unifications have /// occurred**, so that annotations like `Vec<_>` are preserved /// properly. + #[instrument(skip(self), level = "debug")] pub fn write_user_type_annotation_from_substs( &self, hir_id: hir::HirId, @@ -237,37 +237,25 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { substs: SubstsRef<'tcx>, user_self_ty: Option>, ) { - debug!( - "write_user_type_annotation_from_substs: hir_id={:?} def_id={:?} substs={:?} \ - user_self_ty={:?} in fcx {}", - hir_id, - def_id, - substs, - user_self_ty, - self.tag(), - ); + debug!("fcx {}", self.tag()); if self.can_contain_user_lifetime_bounds((substs, user_self_ty)) { let canonicalized = self.infcx.canonicalize_user_type_annotation(UserType::TypeOf( def_id, UserSubsts { substs, user_self_ty }, )); - debug!("write_user_type_annotation_from_substs: canonicalized={:?}", canonicalized); + debug!(?canonicalized); self.write_user_type_annotation(hir_id, canonicalized); } } + #[instrument(skip(self), level = "debug")] pub fn write_user_type_annotation( &self, hir_id: hir::HirId, canonical_user_type_annotation: CanonicalUserType<'tcx>, ) { - debug!( - "write_user_type_annotation: hir_id={:?} canonical_user_type_annotation={:?} tag={}", - hir_id, - canonical_user_type_annotation, - self.tag(), - ); + debug!("fcx {}", self.tag()); if !canonical_user_type_annotation.is_identity() { self.typeck_results @@ -275,12 +263,13 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { .user_provided_types_mut() .insert(hir_id, canonical_user_type_annotation); } else { - debug!("write_user_type_annotation: skipping identity substs"); + debug!("skipping identity substs"); } } + #[instrument(skip(self, expr), level = "debug")] pub fn apply_adjustments(&self, expr: &hir::Expr<'_>, adj: Vec>) { - debug!("apply_adjustments(expr={:?}, adj={:?})", expr, adj); + debug!("expr = {:#?}", expr); if adj.is_empty() { return; @@ -652,8 +641,8 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] pub(in super::super) fn select_all_obligations_or_error(&self) { - debug!("select_all_obligations_or_error"); if let Err(errors) = self .fulfillment_cx .borrow_mut() @@ -694,16 +683,15 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { ret_ty.builtin_deref(true).unwrap() } + #[instrument(skip(self), level = "debug")] fn self_type_matches_expected_vid( &self, trait_ref: ty::PolyTraitRef<'tcx>, expected_vid: ty::TyVid, ) -> bool { let self_ty = self.shallow_resolve(trait_ref.skip_binder().self_ty()); - debug!( - "self_type_matches_expected_vid(trait_ref={:?}, self_ty={:?}, expected_vid={:?})", - trait_ref, self_ty, expected_vid - ); + debug!(?self_ty); + match *self_ty.kind() { ty::Infer(ty::TyVar(found_vid)) => { // FIXME: consider using `sub_root_var` here so we @@ -716,6 +704,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] pub(in super::super) fn obligations_for_self_ty<'b>( &'b self, self_ty: ty::TyVid, @@ -725,12 +714,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { // FIXME: consider using `sub_root_var` here so we // can see through subtyping. let ty_var_root = self.root_var(self_ty); - debug!( - "obligations_for_self_ty: self_ty={:?} ty_var_root={:?} pending_obligations={:?}", - self_ty, - ty_var_root, - self.fulfillment_cx.borrow().pending_obligations() - ); + trace!("pending_obligations = {:#?}", self.fulfillment_cx.borrow().pending_obligations()); self.fulfillment_cx .borrow() @@ -780,6 +764,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// Unifies the output type with the expected type early, for more coercions /// and forward type information on the input expressions. + #[instrument(skip(self, call_span), level = "debug")] pub(in super::super) fn expected_inputs_for_expected_output( &self, call_span: Span, @@ -826,10 +811,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { Ok(formal_args.iter().map(|&ty| self.resolve_vars_if_possible(ty)).collect()) }) .unwrap_or_default(); - debug!( - "expected_inputs_for_expected_output(formal={:?} -> {:?}, expected={:?} -> {:?})", - formal_args, formal_ret, expect_args, expected_ret - ); + debug!(?formal_args, ?formal_ret, ?expect_args, ?expected_ret); expect_args } @@ -1195,6 +1177,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { // Instantiates the given path, which must refer to an item with the given // number of type parameters and type. + #[instrument(skip(self, span), level = "debug")] pub fn instantiate_value_path( &self, segments: &[hir::PathSegment<'_>], @@ -1203,11 +1186,6 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { span: Span, hir_id: hir::HirId, ) -> (Ty<'tcx>, Res) { - debug!( - "instantiate_value_path(segments={:?}, self_ty={:?}, res={:?}, hir_id={})", - segments, self_ty, res, hir_id, - ); - let tcx = self.tcx; let path_segs = match res { @@ -1230,7 +1208,7 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { } Res::Def(DefKind::AssocFn | DefKind::AssocConst, def_id) => { let container = tcx.associated_item(def_id).container; - debug!("instantiate_value_path: def_id={:?} container={:?}", def_id, container); + debug!(?def_id, ?container); match container { ty::TraitContainer(trait_did) => { callee::check_legal_trait_for_method_call(tcx, span, None, span, trait_did) diff --git a/compiler/rustc_typeck/src/check/upvar.rs b/compiler/rustc_typeck/src/check/upvar.rs index 917bf4ecd8c..1f2ccffa6f2 100644 --- a/compiler/rustc_typeck/src/check/upvar.rs +++ b/compiler/rustc_typeck/src/check/upvar.rs @@ -122,6 +122,7 @@ impl<'a, 'tcx> Visitor<'tcx> for InferBorrowKindVisitor<'a, 'tcx> { impl<'a, 'tcx> FnCtxt<'a, 'tcx> { /// Analysis starting point. + #[instrument(skip(self, body), level = "debug")] fn analyze_closure( &self, closure_hir_id: hir::HirId, @@ -130,8 +131,6 @@ impl<'a, 'tcx> FnCtxt<'a, 'tcx> { body: &'tcx hir::Body<'tcx>, capture_clause: hir::CaptureBy, ) { - debug!("analyze_closure(id={:?}, body.id={:?})", closure_hir_id, body.id()); - // Extract the type of the closure. let ty = self.node_ty(closure_hir_id); let (closure_def_id, substs) = match *ty.kind() { @@ -1683,15 +1682,12 @@ struct InferBorrowKind<'a, 'tcx> { } impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { + #[instrument(skip(self), level = "debug")] fn adjust_upvar_borrow_kind_for_consume( &mut self, place_with_id: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId, ) { - debug!( - "adjust_upvar_borrow_kind_for_consume(place_with_id={:?}, diag_expr_id={:?})", - place_with_id, diag_expr_id - ); let tcx = self.fcx.tcx; let upvar_id = if let PlaceBase::Upvar(upvar_id) = place_with_id.place.base { upvar_id @@ -1699,7 +1695,7 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { return; }; - debug!("adjust_upvar_borrow_kind_for_consume: upvar={:?}", upvar_id); + debug!(?upvar_id); let usage_span = tcx.hir().span(diag_expr_id); @@ -1718,16 +1714,12 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { /// Indicates that `place_with_id` is being directly mutated (e.g., assigned /// to). If the place is based on a by-ref upvar, this implies that /// the upvar must be borrowed using an `&mut` borrow. + #[instrument(skip(self), level = "debug")] fn adjust_upvar_borrow_kind_for_mut( &mut self, place_with_id: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId, ) { - debug!( - "adjust_upvar_borrow_kind_for_mut(place_with_id={:?}, diag_expr_id={:?})", - place_with_id, diag_expr_id - ); - if let PlaceBase::Upvar(_) = place_with_id.place.base { // Raw pointers don't inherit mutability if place_with_id.place.deref_tys().any(ty::TyS::is_unsafe_ptr) { @@ -1737,16 +1729,12 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] fn adjust_upvar_borrow_kind_for_unique( &mut self, place_with_id: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId, ) { - debug!( - "adjust_upvar_borrow_kind_for_unique(place_with_id={:?}, diag_expr_id={:?})", - place_with_id, diag_expr_id - ); - if let PlaceBase::Upvar(_) = place_with_id.place.base { if place_with_id.place.deref_tys().any(ty::TyS::is_unsafe_ptr) { // Raw pointers don't inherit mutability. @@ -1783,6 +1771,7 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { /// moving from left to right as needed (but never right to left). /// Here the argument `mutbl` is the borrow_kind that is required by /// some particular use. + #[instrument(skip(self), level = "debug")] fn adjust_upvar_borrow_kind( &mut self, place_with_id: &PlaceWithHirId<'tcx>, @@ -1791,10 +1780,7 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { ) { let curr_capture_info = self.capture_information[&place_with_id.place]; - debug!( - "adjust_upvar_borrow_kind(place={:?}, diag_expr_id={:?}, capture_info={:?}, kind={:?})", - place_with_id, diag_expr_id, curr_capture_info, kind - ); + debug!(?curr_capture_info); if let ty::UpvarCapture::ByValue(_) = curr_capture_info.capture_kind { // It's already captured by value, we don't need to do anything here @@ -1814,6 +1800,7 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { }; } + #[instrument(skip(self, diag_expr_id), level = "debug")] fn init_capture_info_for_place( &mut self, place_with_id: &PlaceWithHirId<'tcx>, @@ -1840,7 +1827,7 @@ impl<'a, 'tcx> InferBorrowKind<'a, 'tcx> { self.capture_information.insert(place_with_id.place.clone(), capture_info); } else { - debug!("Not upvar: {:?}", place_with_id); + debug!("Not upvar"); } } } @@ -1867,9 +1854,8 @@ impl<'a, 'tcx> euv::Delegate<'tcx> for InferBorrowKind<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] fn consume(&mut self, place_with_id: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId) { - debug!("consume(place_with_id={:?}, diag_expr_id={:?})", place_with_id, diag_expr_id); - if !self.capture_information.contains_key(&place_with_id.place) { self.init_capture_info_for_place(&place_with_id, diag_expr_id); } @@ -1877,17 +1863,13 @@ impl<'a, 'tcx> euv::Delegate<'tcx> for InferBorrowKind<'a, 'tcx> { self.adjust_upvar_borrow_kind_for_consume(&place_with_id, diag_expr_id); } + #[instrument(skip(self), level = "debug")] fn borrow( &mut self, place_with_id: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId, bk: ty::BorrowKind, ) { - debug!( - "borrow(place_with_id={:?}, diag_expr_id={:?}, bk={:?})", - place_with_id, diag_expr_id, bk - ); - // The region here will get discarded/ignored let dummy_capture_kind = ty::UpvarCapture::ByRef(ty::UpvarBorrow { kind: bk, region: &ty::ReErased }); @@ -1924,9 +1906,8 @@ impl<'a, 'tcx> euv::Delegate<'tcx> for InferBorrowKind<'a, 'tcx> { } } + #[instrument(skip(self), level = "debug")] fn mutate(&mut self, assignee_place: &PlaceWithHirId<'tcx>, diag_expr_id: hir::HirId) { - debug!("mutate(assignee_place={:?}, diag_expr_id={:?})", assignee_place, diag_expr_id); - self.borrow(assignee_place, diag_expr_id, ty::BorrowKind::MutBorrow); } } diff --git a/compiler/rustc_typeck/src/check/writeback.rs b/compiler/rustc_typeck/src/check/writeback.rs index c57ec9ef78f..b267909be7b 100644 --- a/compiler/rustc_typeck/src/check/writeback.rs +++ b/compiler/rustc_typeck/src/check/writeback.rs @@ -497,6 +497,7 @@ impl<'cx, 'tcx> WritebackCx<'cx, 'tcx> { fcx_typeck_results.generator_interior_types.clone(); } + #[instrument(skip(self, span), level = "debug")] fn visit_opaque_types(&mut self, span: Span) { let opaque_types = self.fcx.infcx.inner.borrow().opaque_types.clone(); for (opaque_type_key, opaque_defn) in opaque_types { @@ -564,6 +565,7 @@ impl<'cx, 'tcx> WritebackCx<'cx, 'tcx> { } } + #[instrument(skip(self, span), level = "debug")] fn visit_node_id(&mut self, span: Span, hir_id: hir::HirId) { // Export associated path extensions and method resolutions. if let Some(def) = @@ -579,7 +581,7 @@ impl<'cx, 'tcx> WritebackCx<'cx, 'tcx> { let n_ty = self.fcx.node_ty(hir_id); let n_ty = self.resolve(n_ty, &span); self.write_ty_to_typeck_results(hir_id, n_ty); - debug!("node {:?} has type {:?}", hir_id, n_ty); + debug!(?n_ty); // Resolve any substitutions if let Some(substs) = self.fcx.typeck_results.borrow().node_substs_opt(hir_id) { @@ -590,31 +592,33 @@ impl<'cx, 'tcx> WritebackCx<'cx, 'tcx> { } } + #[instrument(skip(self, span), level = "debug")] fn visit_adjustments(&mut self, span: Span, hir_id: hir::HirId) { let adjustment = self.fcx.typeck_results.borrow_mut().adjustments_mut().remove(hir_id); match adjustment { None => { - debug!("no adjustments for node {:?}", hir_id); + debug!("no adjustments for node"); } Some(adjustment) => { let resolved_adjustment = self.resolve(adjustment, &span); - debug!("adjustments for node {:?}: {:?}", hir_id, resolved_adjustment); + debug!(?resolved_adjustment); self.typeck_results.adjustments_mut().insert(hir_id, resolved_adjustment); } } } + #[instrument(skip(self, span), level = "debug")] fn visit_pat_adjustments(&mut self, span: Span, hir_id: hir::HirId) { let adjustment = self.fcx.typeck_results.borrow_mut().pat_adjustments_mut().remove(hir_id); match adjustment { None => { - debug!("no pat_adjustments for node {:?}", hir_id); + debug!("no pat_adjustments for node"); } Some(adjustment) => { let resolved_adjustment = self.resolve(adjustment, &span); - debug!("pat_adjustments for node {:?}: {:?}", hir_id, resolved_adjustment); + debug!(?resolved_adjustment); self.typeck_results.pat_adjustments_mut().insert(hir_id, resolved_adjustment); } }