Rollup merge of #125036 - lcnr:new-solver-trace, r=compiler-errors

solve: all "non-structural" logging to trace

This enables us to start with `RUSTC_LOG=rustc_trait_selection::solve=debug` to figure out *where* something went wrong, to then separately use `trace` to get to the details.

r? ``@compiler-errors``
This commit is contained in:
Guillaume Gomez 2024-05-12 13:41:58 +02:00 committed by GitHub
commit d3625fc8df
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
14 changed files with 56 additions and 53 deletions

View File

@ -20,7 +20,7 @@ use rustc_middle::traits::solve::{Certainty, Goal, QueryResult};
use rustc_middle::ty;
impl<'tcx> EvalCtxt<'_, 'tcx> {
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(super) fn compute_alias_relate_goal(
&mut self,
goal: Goal<'tcx, (ty::Term<'tcx>, ty::Term<'tcx>, ty::AliasRelationDirection)>,
@ -50,7 +50,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
self.try_evaluate_added_goals()?;
let lhs = self.resolve_vars_if_possible(lhs);
let rhs = self.resolve_vars_if_possible(rhs);
debug!(?lhs, ?rhs);
trace!(?lhs, ?rhs);
let variance = match direction {
ty::AliasRelationDirection::Equate => ty::Variance::Invariant,

View File

@ -331,7 +331,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
.enter(|this| this.evaluate_added_goals_and_make_canonical_response(certainty))
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_non_blanket_impl_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -447,7 +447,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_blanket_impl_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -470,7 +470,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_builtin_impl_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -544,7 +544,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_param_env_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -561,7 +561,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_alias_bound_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -665,7 +665,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_object_bound_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,
@ -756,7 +756,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
///
/// To do so we add an ambiguous candidate in case such an unknown impl could
/// apply to the current goal.
#[instrument(level = "debug", skip_all)]
#[instrument(level = "trace", skip_all)]
fn assemble_coherence_unknowable_candidates<G: GoalKind<'tcx>>(
&mut self,
goal: Goal<'tcx, G>,

View File

@ -17,7 +17,7 @@ use crate::solve::EvalCtxt;
//
// For types with an "existential" binder, i.e. coroutine witnesses, we also
// instantiate the binder with placeholders eagerly.
#[instrument(level = "debug", skip(ecx), ret)]
#[instrument(level = "trace", skip(ecx), ret)]
pub(in crate::solve) fn instantiate_constituent_tys_for_auto_trait<'tcx>(
ecx: &EvalCtxt<'_, 'tcx>,
ty: Ty<'tcx>,
@ -96,7 +96,7 @@ pub(in crate::solve) fn instantiate_constituent_tys_for_auto_trait<'tcx>(
}
}
#[instrument(level = "debug", skip(ecx), ret)]
#[instrument(level = "trace", skip(ecx), ret)]
pub(in crate::solve) fn instantiate_constituent_tys_for_sized_trait<'tcx>(
ecx: &EvalCtxt<'_, 'tcx>,
ty: Ty<'tcx>,
@ -160,7 +160,7 @@ pub(in crate::solve) fn instantiate_constituent_tys_for_sized_trait<'tcx>(
}
}
#[instrument(level = "debug", skip(ecx), ret)]
#[instrument(level = "trace", skip(ecx), ret)]
pub(in crate::solve) fn instantiate_constituent_tys_for_copy_clone_trait<'tcx>(
ecx: &EvalCtxt<'_, 'tcx>,
ty: Ty<'tcx>,

View File

@ -83,7 +83,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// the values inferred while solving the instantiated goal.
/// - `external_constraints`: additional constraints which aren't expressible
/// using simple unification of inference variables.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(in crate::solve) fn evaluate_added_goals_and_make_canonical_response(
&mut self,
certainty: Certainty,
@ -166,7 +166,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// external constraints do not need to record that opaque, since if it is
/// further constrained by inference, that will be passed back in the var
/// values.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn compute_external_query_constraints(
&self,
normalization_nested_goals: NestedNormalizationGoals<'tcx>,
@ -174,7 +174,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
// We only check for leaks from universes which were entered inside
// of the query.
self.infcx.leak_check(self.max_input_universe, None).map_err(|e| {
debug!(?e, "failed the leak check");
trace!(?e, "failed the leak check");
NoSolution
})?;
@ -334,7 +334,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// whether an alias is rigid by using the trait solver. When instantiating a response
/// from the solver we assume that the solver correctly handled aliases and therefore
/// always relate them structurally here.
#[instrument(level = "debug", skip(infcx))]
#[instrument(level = "trace", skip(infcx))]
fn unify_query_var_values(
infcx: &InferCtxt<'tcx>,
param_env: ty::ParamEnv<'tcx>,
@ -407,7 +407,7 @@ pub(in crate::solve) fn make_canonical_state<'tcx, T: TypeFoldable<TyCtxt<'tcx>>
/// This currently assumes that unifying the var values trivially succeeds.
/// Adding any inference constraints which weren't present when originally
/// computing the canonical query can result in bugs.
#[instrument(level = "debug", skip(infcx, span, param_env))]
#[instrument(level = "trace", skip(infcx, span, param_env))]
pub(in crate::solve) fn instantiate_canonical_state<'tcx, T: TypeFoldable<TyCtxt<'tcx>>>(
infcx: &InferCtxt<'tcx>,
span: Span,

View File

@ -458,7 +458,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
}
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
pub(super) fn add_normalizes_to_goal(&mut self, goal: Goal<'tcx, ty::NormalizesTo<'tcx>>) {
self.inspect.add_normalizes_to_goal(self.infcx, self.max_input_universe, goal);
self.nested_goals.normalizes_to_goals.push(goal);
@ -472,7 +472,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
// Recursively evaluates all the goals added to this `EvalCtxt` to completion, returning
// the certainty of all the goals.
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
pub(super) fn try_evaluate_added_goals(&mut self) -> Result<Certainty, NoSolution> {
self.inspect.start_evaluate_added_goals();
let mut response = Ok(Certainty::overflow(false));
@ -526,7 +526,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
unconstrained_goal,
)?;
// Add the nested goals from normalization to our own nested goals.
debug!(?nested_goals);
trace!(?nested_goals);
goals.goals.extend(nested_goals);
// Finally, equate the goal's RHS with the unconstrained var.
@ -622,7 +622,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
///
/// This is the case if the `term` does not occur in any other part of the predicate
/// and is able to name all other placeholder and inference variables.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(super) fn term_is_fully_unconstrained(
&self,
goal: Goal<'tcx, ty::NormalizesTo<'tcx>>,
@ -718,7 +718,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
&& goal.param_env.visit_with(&mut visitor).is_continue()
}
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
pub(super) fn eq<T: ToTrace<'tcx>>(
&mut self,
param_env: ty::ParamEnv<'tcx>,
@ -733,7 +733,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
self.add_goals(GoalSource::Misc, obligations.into_iter().map(|o| o.into()));
})
.map_err(|e| {
debug!(?e, "failed to equate");
trace!(?e, "failed to equate");
NoSolution
})
}
@ -743,7 +743,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// Normally we emit a nested `AliasRelate` when equating an inference
/// variable and an alias. This causes us to instead constrain the inference
/// variable to the alias without emitting a nested alias relate goals.
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
pub(super) fn relate_rigid_alias_non_alias(
&mut self,
param_env: ty::ParamEnv<'tcx>,
@ -781,7 +781,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// This sohuld only be used when we're either instantiating a previously
/// unconstrained "return value" or when we're sure that all aliases in
/// the types are rigid.
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
pub(super) fn eq_structurally_relating_aliases<T: ToTrace<'tcx>>(
&mut self,
param_env: ty::ParamEnv<'tcx>,
@ -798,7 +798,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
Ok(())
}
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
pub(super) fn sub<T: ToTrace<'tcx>>(
&mut self,
param_env: ty::ParamEnv<'tcx>,
@ -813,12 +813,12 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
self.add_goals(GoalSource::Misc, obligations.into_iter().map(|o| o.into()));
})
.map_err(|e| {
debug!(?e, "failed to subtype");
trace!(?e, "failed to subtype");
NoSolution
})
}
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
pub(super) fn relate<T: ToTrace<'tcx>>(
&mut self,
param_env: ty::ParamEnv<'tcx>,
@ -834,7 +834,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
self.add_goals(GoalSource::Misc, obligations.into_iter().map(|o| o.into()));
})
.map_err(|e| {
debug!(?e, "failed to relate");
trace!(?e, "failed to relate");
NoSolution
})
}
@ -859,7 +859,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
obligations.into_iter().map(|o| o.into()).collect()
})
.map_err(|e| {
debug!(?e, "failed to equate");
trace!(?e, "failed to equate");
NoSolution
})
}

View File

@ -58,6 +58,7 @@ impl<'tcx, F> TraitProbeCtxt<'_, '_, 'tcx, F>
where
F: FnOnce(&QueryResult<'tcx>) -> inspect::ProbeKind<'tcx>,
{
#[instrument(level = "debug", skip_all, fields(source = ?self.source))]
pub(in crate::solve) fn enter(
self,
f: impl FnOnce(&mut EvalCtxt<'_, 'tcx>) -> QueryResult<'tcx>,

View File

@ -119,7 +119,7 @@ impl<'tcx> FulfillmentCtxt<'tcx> {
}
impl<'tcx> TraitEngine<'tcx> for FulfillmentCtxt<'tcx> {
#[instrument(level = "debug", skip(self, infcx))]
#[instrument(level = "trace", skip(self, infcx))]
fn register_predicate_obligation(
&mut self,
infcx: &InferCtxt<'tcx>,

View File

@ -82,7 +82,7 @@ impl<'tcx> Canonical<'tcx, Response<'tcx>> {
}
impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_type_outlives_goal(
&mut self,
goal: Goal<'tcx, TypeOutlivesPredicate<'tcx>>,
@ -92,7 +92,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
self.evaluate_added_goals_and_make_canonical_response(Certainty::Yes)
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_region_outlives_goal(
&mut self,
goal: Goal<'tcx, RegionOutlivesPredicate<'tcx>>,
@ -102,7 +102,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
self.evaluate_added_goals_and_make_canonical_response(Certainty::Yes)
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_coerce_goal(
&mut self,
goal: Goal<'tcx, CoercePredicate<'tcx>>,
@ -117,7 +117,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
})
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_subtype_goal(
&mut self,
goal: Goal<'tcx, SubtypePredicate<'tcx>>,
@ -138,7 +138,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
}
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_well_formed_goal(
&mut self,
goal: Goal<'tcx, ty::GenericArg<'tcx>>,
@ -152,7 +152,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
}
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn compute_const_evaluatable_goal(
&mut self,
Goal { param_env, predicate: ct }: Goal<'tcx, ty::Const<'tcx>>,
@ -189,7 +189,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
}
}
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn compute_const_arg_has_type_goal(
&mut self,
goal: Goal<'tcx, (ty::Const<'tcx>, Ty<'tcx>)>,
@ -201,7 +201,7 @@ impl<'a, 'tcx> EvalCtxt<'a, 'tcx> {
}
impl<'tcx> EvalCtxt<'_, 'tcx> {
#[instrument(level = "debug", skip(self, goals))]
#[instrument(level = "trace", skip(self, goals))]
fn add_goals(
&mut self,
source: GoalSource,
@ -215,7 +215,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// Try to merge multiple possible ways to prove a goal, if that is not possible returns `None`.
///
/// In this case we tend to flounder and return ambiguity by calling `[EvalCtxt::flounder]`.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn try_merge_responses(
&mut self,
responses: &[CanonicalResponse<'tcx>],
@ -241,7 +241,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
}
/// If we fail to merge responses we flounder and return overflow or ambiguity.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn flounder(&mut self, responses: &[CanonicalResponse<'tcx>]) -> QueryResult<'tcx> {
if responses.is_empty() {
return Err(NoSolution);
@ -263,7 +263,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// This function is necessary in nearly all cases before matching on a type.
/// Not doing so is likely to be incomplete and therefore unsound during
/// coherence.
#[instrument(level = "debug", skip(self, param_env), ret)]
#[instrument(level = "trace", skip(self, param_env), ret)]
fn structurally_normalize_ty(
&mut self,
param_env: ty::ParamEnv<'tcx>,

View File

@ -162,7 +162,7 @@ impl<'tcx> FallibleTypeFolder<TyCtxt<'tcx>> for NormalizationFolder<'_, 'tcx> {
Ok(t)
}
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn try_fold_ty(&mut self, ty: Ty<'tcx>) -> Result<Ty<'tcx>, Self::Error> {
let infcx = self.at.infcx;
debug_assert_eq!(ty, infcx.shallow_resolve(ty));
@ -189,7 +189,7 @@ impl<'tcx> FallibleTypeFolder<TyCtxt<'tcx>> for NormalizationFolder<'_, 'tcx> {
}
}
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn try_fold_const(&mut self, ct: ty::Const<'tcx>) -> Result<ty::Const<'tcx>, Self::Error> {
let infcx = self.at.infcx;
debug_assert_eq!(ct, infcx.shallow_resolve_const(ct));

View File

@ -3,7 +3,7 @@ use rustc_middle::traits::solve::{Certainty, Goal, QueryResult};
use rustc_middle::ty;
impl<'tcx> EvalCtxt<'_, 'tcx> {
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(super) fn normalize_anon_const(
&mut self,
goal: Goal<'tcx, ty::NormalizesTo<'tcx>>,

View File

@ -25,7 +25,7 @@ mod opaque_types;
mod weak_types;
impl<'tcx> EvalCtxt<'_, 'tcx> {
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(super) fn compute_normalizes_to_goal(
&mut self,
goal: Goal<'tcx, NormalizesTo<'tcx>>,
@ -59,7 +59,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
/// Normalize the given alias by at least one step. If the alias is rigid, this
/// returns `NoSolution`.
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
fn normalize_at_least_one_step(
&mut self,
goal: Goal<'tcx, NormalizesTo<'tcx>>,
@ -897,7 +897,7 @@ impl<'tcx> assembly::GoalKind<'tcx> for NormalizesTo<'tcx> {
///
/// FIXME: We should merge these 3 implementations as it's likely that they otherwise
/// diverge.
#[instrument(level = "debug", skip(ecx, param_env), ret)]
#[instrument(level = "trace", skip(ecx, param_env), ret)]
fn fetch_eligible_assoc_item_def<'tcx>(
ecx: &EvalCtxt<'_, 'tcx>,
param_env: ty::ParamEnv<'tcx>,
@ -920,7 +920,7 @@ fn fetch_eligible_assoc_item_def<'tcx>(
let poly_trait_ref = ecx.resolve_vars_if_possible(goal_trait_ref);
!poly_trait_ref.still_further_specializable()
} else {
debug!(?node_item.item.def_id, "not eligible due to default");
trace!(?node_item.item.def_id, "not eligible due to default");
false
}
};

View File

@ -5,7 +5,7 @@ use rustc_middle::traits::solve::{Certainty, Goal, QueryResult};
use rustc_middle::ty::{self, ProjectionPredicate};
impl<'tcx> EvalCtxt<'_, 'tcx> {
#[instrument(level = "debug", skip(self), ret)]
#[instrument(level = "trace", skip(self), ret)]
pub(super) fn compute_projection_goal(
&mut self,
goal: Goal<'tcx, ProjectionPredicate<'tcx>>,

View File

@ -130,7 +130,7 @@ impl<'tcx> SearchGraph<'tcx> {
}
/// Update the stack and reached depths on cache hits.
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
fn on_cache_hit(&mut self, additional_depth: usize, encountered_overflow: bool) {
let reached_depth = self.stack.next_index().plus(additional_depth);
if let Some(last) = self.stack.raw.last_mut() {
@ -296,6 +296,7 @@ impl<'tcx> SearchGraph<'tcx> {
}
self.on_cache_hit(reached_depth, encountered_overflow);
debug!("global cache hit");
return result;
}
@ -315,6 +316,7 @@ impl<'tcx> SearchGraph<'tcx> {
.filter(|p| !Self::stack_coinductive_from(tcx, &self.stack, p.head))
})
{
debug!("provisional cache hit");
// We have a nested goal which is already in the provisional cache, use
// its result. We do not provide any usage kind as that should have been
// already set correctly while computing the cache entry.

View File

@ -1130,7 +1130,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
},
);
if let Some(def_id) = disqualifying_impl {
debug!(?def_id, ?goal, "disqualified auto-trait implementation");
trace!(?def_id, ?goal, "disqualified auto-trait implementation");
// No need to actually consider the candidate here,
// since we do that in `consider_impl_candidate`.
return Some(Err(NoSolution));
@ -1171,7 +1171,7 @@ impl<'tcx> EvalCtxt<'_, 'tcx> {
})
}
#[instrument(level = "debug", skip(self))]
#[instrument(level = "trace", skip(self))]
pub(super) fn compute_trait_goal(
&mut self,
goal: Goal<'tcx, TraitPredicate<'tcx>>,