diff --git a/compiler/rustc_const_eval/src/interpret/call.rs b/compiler/rustc_const_eval/src/interpret/call.rs index 5b3adba02659c..b8a653698258f 100644 --- a/compiler/rustc_const_eval/src/interpret/call.rs +++ b/compiler/rustc_const_eval/src/interpret/call.rs @@ -11,6 +11,7 @@ use rustc_middle::ty::{self, AdtDef, Instance, Ty, VariantDef}; use rustc_middle::{bug, mir, span_bug}; use rustc_span::sym; use rustc_target::callconv::{ArgAbi, FnAbi, PassMode}; +use tracing::field::Empty; use tracing::{info, instrument, trace}; use super::{ @@ -18,7 +19,8 @@ use super::{ Projectable, Provenance, ReturnAction, ReturnContinuation, Scalar, StackPopInfo, interp_ok, throw_ub, throw_ub_custom, throw_unsup_format, }; -use crate::fluent_generated as fluent; +use crate::interpret::EnteredTraceSpan; +use crate::{enter_trace_span, fluent_generated as fluent}; /// An argument passed to a function. #[derive(Clone, Debug)] @@ -344,6 +346,8 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { destination: &PlaceTy<'tcx, M::Provenance>, mut cont: ReturnContinuation, ) -> InterpResult<'tcx> { + let _span = enter_trace_span!(M, step::init_stack_frame, %instance, tracing_separate_thread = Empty); + // Compute callee information. // FIXME: for variadic support, do we have to somehow determine callee's extra_args? let callee_fn_abi = self.fn_abi_of_instance(instance, ty::List::empty())?; @@ -523,7 +527,9 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { target: Option, unwind: mir::UnwindAction, ) -> InterpResult<'tcx> { - trace!("init_fn_call: {:#?}", fn_val); + let _span = + enter_trace_span!(M, step::init_fn_call, tracing_separate_thread = Empty, ?fn_val) + .or_if_tracing_disabled(|| trace!("init_fn_call: {:#?}", fn_val)); let instance = match fn_val { FnVal::Instance(instance) => instance, diff --git a/compiler/rustc_const_eval/src/interpret/operand.rs b/compiler/rustc_const_eval/src/interpret/operand.rs index 21afd082a0551..4171345790864 100644 --- a/compiler/rustc_const_eval/src/interpret/operand.rs +++ b/compiler/rustc_const_eval/src/interpret/operand.rs @@ -13,6 +13,7 @@ use rustc_middle::ty::print::{FmtPrinter, PrettyPrinter}; use rustc_middle::ty::{ConstInt, ScalarInt, Ty, TyCtxt}; use rustc_middle::{bug, mir, span_bug, ty}; use rustc_span::DUMMY_SP; +use tracing::field::Empty; use tracing::trace; use super::{ @@ -20,6 +21,7 @@ use super::{ OffsetMode, PlaceTy, Pointer, Projectable, Provenance, Scalar, alloc_range, err_ub, from_known_layout, interp_ok, mir_assign_valid_types, throw_ub, }; +use crate::enter_trace_span; /// An `Immediate` represents a single immediate self-contained Rust value. /// @@ -770,6 +772,13 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { mir_place: mir::Place<'tcx>, layout: Option>, ) -> InterpResult<'tcx, OpTy<'tcx, M::Provenance>> { + let _span = enter_trace_span!( + M, + step::eval_place_to_op, + ?mir_place, + tracing_separate_thread = Empty + ); + // Do not use the layout passed in as argument if the base we are looking at // here is not the entire place. let layout = if mir_place.projection.is_empty() { layout } else { None }; @@ -813,6 +822,9 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { mir_op: &mir::Operand<'tcx>, layout: Option>, ) -> InterpResult<'tcx, OpTy<'tcx, M::Provenance>> { + let _span = + enter_trace_span!(M, step::eval_operand, ?mir_op, tracing_separate_thread = Empty); + use rustc_middle::mir::Operand::*; let op = match mir_op { // FIXME: do some more logic on `move` to invalidate the old location diff --git a/compiler/rustc_const_eval/src/interpret/place.rs b/compiler/rustc_const_eval/src/interpret/place.rs index e2284729efdcf..45c4edb850373 100644 --- a/compiler/rustc_const_eval/src/interpret/place.rs +++ b/compiler/rustc_const_eval/src/interpret/place.rs @@ -9,6 +9,7 @@ use rustc_abi::{BackendRepr, HasDataLayout, Size}; use rustc_middle::ty::Ty; use rustc_middle::ty::layout::TyAndLayout; use rustc_middle::{bug, mir, span_bug}; +use tracing::field::Empty; use tracing::{instrument, trace}; use super::{ @@ -16,6 +17,7 @@ use super::{ InterpResult, Machine, MemoryKind, Misalignment, OffsetMode, OpTy, Operand, Pointer, Projectable, Provenance, Scalar, alloc_range, interp_ok, mir_assign_valid_types, }; +use crate::enter_trace_span; #[derive(Copy, Clone, Hash, PartialEq, Eq, Debug)] /// Information required for the sound usage of a `MemPlace`. @@ -524,6 +526,9 @@ where &self, mir_place: mir::Place<'tcx>, ) -> InterpResult<'tcx, PlaceTy<'tcx, M::Provenance>> { + let _span = + enter_trace_span!(M, step::eval_place, ?mir_place, tracing_separate_thread = Empty); + let mut place = self.local_to_place(mir_place.local)?; // Using `try_fold` turned out to be bad for performance, hence the loop. for elem in mir_place.projection.iter() { diff --git a/compiler/rustc_const_eval/src/interpret/step.rs b/compiler/rustc_const_eval/src/interpret/step.rs index 629dcc3523ca0..9df49c0f4ccdf 100644 --- a/compiler/rustc_const_eval/src/interpret/step.rs +++ b/compiler/rustc_const_eval/src/interpret/step.rs @@ -9,13 +9,15 @@ use rustc_middle::ty::{self, Instance, Ty}; use rustc_middle::{bug, mir, span_bug}; use rustc_span::source_map::Spanned; use rustc_target::callconv::FnAbi; +use tracing::field::Empty; use tracing::{info, instrument, trace}; use super::{ FnArg, FnVal, ImmTy, Immediate, InterpCx, InterpResult, Machine, MemPlaceMeta, PlaceTy, Projectable, Scalar, interp_ok, throw_ub, throw_unsup_format, }; -use crate::util; +use crate::interpret::EnteredTraceSpan; +use crate::{enter_trace_span, util}; struct EvaluatedCalleeAndArgs<'tcx, M: Machine<'tcx>> { callee: FnVal<'tcx, M::ExtraFnVal>, @@ -74,7 +76,14 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { /// /// This does NOT move the statement counter forward, the caller has to do that! pub fn eval_statement(&mut self, stmt: &mir::Statement<'tcx>) -> InterpResult<'tcx> { - info!("{:?}", stmt); + let _span = enter_trace_span!( + M, + step::eval_statement, + stmt = ?stmt.kind, + span = ?stmt.source_info.span, + tracing_separate_thread = Empty, + ) + .or_if_tracing_disabled(|| info!(stmt = ?stmt.kind)); use rustc_middle::mir::StatementKind::*; @@ -456,7 +465,14 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { } fn eval_terminator(&mut self, terminator: &mir::Terminator<'tcx>) -> InterpResult<'tcx> { - info!("{:?}", terminator.kind); + let _span = enter_trace_span!( + M, + step::eval_terminator, + terminator = ?terminator.kind, + span = ?terminator.source_info.span, + tracing_separate_thread = Empty, + ) + .or_if_tracing_disabled(|| info!(terminator = ?terminator.kind)); use rustc_middle::mir::TerminatorKind::*; match terminator.kind { diff --git a/compiler/rustc_const_eval/src/interpret/util.rs b/compiler/rustc_const_eval/src/interpret/util.rs index 6696a0c502600..71800950faab2 100644 --- a/compiler/rustc_const_eval/src/interpret/util.rs +++ b/compiler/rustc_const_eval/src/interpret/util.rs @@ -48,10 +48,24 @@ pub(crate) fn create_static_alloc<'tcx>( /// A marker trait returned by [crate::interpret::Machine::enter_trace_span], identifying either a /// real [tracing::span::EnteredSpan] in case tracing is enabled, or the dummy type `()` when -/// tracing is disabled. -pub trait EnteredTraceSpan {} -impl EnteredTraceSpan for () {} -impl EnteredTraceSpan for tracing::span::EnteredSpan {} +/// tracing is disabled. Also see [crate::enter_trace_span!] below. +pub trait EnteredTraceSpan { + /// Allows executing an alternative function when tracing is disabled. Useful for example if you + /// want to open a trace span when tracing is enabled, and alternatively just log a line when + /// tracing is disabled. + fn or_if_tracing_disabled(self, f: impl FnOnce()) -> Self; +} +impl EnteredTraceSpan for () { + fn or_if_tracing_disabled(self, f: impl FnOnce()) -> Self { + f(); // tracing is disabled, execute the function + self + } +} +impl EnteredTraceSpan for tracing::span::EnteredSpan { + fn or_if_tracing_disabled(self, _f: impl FnOnce()) -> Self { + self // tracing is enabled, don't execute anything + } +} /// Shortand for calling [crate::interpret::Machine::enter_trace_span] on a [tracing::info_span!]. /// This is supposed to be compiled out when [crate::interpret::Machine::enter_trace_span] has the @@ -112,6 +126,19 @@ impl EnteredTraceSpan for tracing::span::EnteredSpan {} /// # type M = rustc_const_eval::const_eval::CompileTimeMachine<'static>; /// let _span = enter_trace_span!(M, step::eval_statement, tracing_separate_thread = tracing::field::Empty); /// ``` +/// +/// ### Executing something else when tracing is disabled +/// +/// [crate::interpret::Machine::enter_trace_span] returns [EnteredTraceSpan], on which you can call +/// [EnteredTraceSpan::or_if_tracing_disabled], to e.g. log a line as an alternative to the tracing +/// span for when tracing is disabled. For example: +/// ```rust +/// # use rustc_const_eval::enter_trace_span; +/// # use rustc_const_eval::interpret::EnteredTraceSpan; +/// # type M = rustc_const_eval::const_eval::CompileTimeMachine<'static>; +/// let _span = enter_trace_span!(M, step::eval_statement) +/// .or_if_tracing_disabled(|| tracing::info!("eval_statement")); +/// ``` #[macro_export] macro_rules! enter_trace_span { ($machine:ty, $name:ident :: $subname:ident $($tt:tt)*) => {