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