Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove -Ztime #102725

Merged
merged 3 commits into from
Oct 6, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion compiler/rustc_codegen_llvm/src/back/lto.rs
Original file line number Diff line number Diff line change
Expand Up @@ -573,7 +573,7 @@ pub(crate) fn run_pass_manager(
module: &mut ModuleCodegen<ModuleLlvm>,
thin: bool,
) -> Result<(), FatalError> {
let _timer = cgcx.prof.extra_verbose_generic_activity("LLVM_lto_optimize", &*module.name);
let _timer = cgcx.prof.verbose_generic_activity_with_arg("LLVM_lto_optimize", &*module.name);
let config = cgcx.config(module.kind);

// Now we have one massive module inside of llmod. Time to run the
Expand Down
2 changes: 1 addition & 1 deletion compiler/rustc_codegen_ssa/src/back/write.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1637,7 +1637,7 @@ fn start_executing_work<B: ExtraBackendMethods>(
llvm_start_time: &mut Option<VerboseTimingGuard<'a>>,
) {
if config.time_module && llvm_start_time.is_none() {
*llvm_start_time = Some(prof.extra_verbose_generic_activity("LLVM_passes", "crate"));
*llvm_start_time = Some(prof.verbose_generic_activity("LLVM_passes"));
}
}
}
Expand Down
64 changes: 27 additions & 37 deletions compiler/rustc_data_structures/src/profiling.rs
Original file line number Diff line number Diff line change
Expand Up @@ -158,30 +158,21 @@ pub struct SelfProfilerRef {
// actually enabled.
event_filter_mask: EventFilter,

// Print verbose generic activities to stdout
// Print verbose generic activities to stderr?
print_verbose_generic_activities: bool,

// Print extra verbose generic activities to stdout
print_extra_verbose_generic_activities: bool,
}

impl SelfProfilerRef {
pub fn new(
profiler: Option<Arc<SelfProfiler>>,
print_verbose_generic_activities: bool,
print_extra_verbose_generic_activities: bool,
) -> SelfProfilerRef {
// If there is no SelfProfiler then the filter mask is set to NONE,
// ensuring that nothing ever tries to actually access it.
let event_filter_mask =
profiler.as_ref().map_or(EventFilter::empty(), |p| p.event_filter_mask);

SelfProfilerRef {
profiler,
event_filter_mask,
print_verbose_generic_activities,
print_extra_verbose_generic_activities,
}
SelfProfilerRef { profiler, event_filter_mask, print_verbose_generic_activities }
}

/// This shim makes sure that calls only get executed if the filter mask
Expand Down Expand Up @@ -214,7 +205,7 @@ impl SelfProfilerRef {
/// Start profiling a verbose generic activity. Profiling continues until the
/// VerboseTimingGuard returned from this call is dropped. In addition to recording
/// a measureme event, "verbose" generic activities also print a timing entry to
/// stdout if the compiler is invoked with -Ztime or -Ztime-passes.
/// stderr if the compiler is invoked with -Ztime-passes.
pub fn verbose_generic_activity<'a>(
&'a self,
event_label: &'static str,
Expand All @@ -225,19 +216,16 @@ impl SelfProfilerRef {
VerboseTimingGuard::start(message, self.generic_activity(event_label))
}

/// Start profiling an extra verbose generic activity. Profiling continues until the
/// VerboseTimingGuard returned from this call is dropped. In addition to recording
/// a measureme event, "extra verbose" generic activities also print a timing entry to
/// stdout if the compiler is invoked with -Ztime-passes.
pub fn extra_verbose_generic_activity<'a, A>(
/// Like `verbose_generic_activity`, but with an extra arg.
pub fn verbose_generic_activity_with_arg<'a, A>(
&'a self,
event_label: &'static str,
event_arg: A,
) -> VerboseTimingGuard<'a>
where
A: Borrow<str> + Into<String>,
{
let message = if self.print_extra_verbose_generic_activities {
let message = if self.print_verbose_generic_activities {
Some(format!("{}({})", event_label, event_arg.borrow()))
} else {
None
Expand Down Expand Up @@ -745,27 +733,9 @@ impl Drop for VerboseTimingGuard<'_> {
if let Some((start_time, start_rss, ref message)) = self.start_and_message {
let end_rss = get_resident_set_size();
let dur = start_time.elapsed();

if should_print_passes(dur, start_rss, end_rss) {
print_time_passes_entry(&message, dur, start_rss, end_rss);
}
}
}
}

fn should_print_passes(dur: Duration, start_rss: Option<usize>, end_rss: Option<usize>) -> bool {
if dur.as_millis() > 5 {
return true;
}

if let (Some(start_rss), Some(end_rss)) = (start_rss, end_rss) {
let change_rss = end_rss.abs_diff(start_rss);
if change_rss > 0 {
return true;
print_time_passes_entry(&message, dur, start_rss, end_rss);
}
}

false
}

pub fn print_time_passes_entry(
Expand All @@ -774,6 +744,26 @@ pub fn print_time_passes_entry(
start_rss: Option<usize>,
end_rss: Option<usize>,
) {
// Print the pass if its duration is greater than 5 ms, or it changed the
// measured RSS.
let is_notable = || {
if dur.as_millis() > 5 {
return true;
}

if let (Some(start_rss), Some(end_rss)) = (start_rss, end_rss) {
let change_rss = end_rss.abs_diff(start_rss);
if change_rss > 0 {
return true;
}
}

false
};
if !is_notable() {
return;
}

let rss_to_mb = |rss| (rss as f64 / 1_000_000.0).round() as usize;
let rss_change_to_mb = |rss| (rss as f64 / 1_000_000.0).round() as i128;

Expand Down
9 changes: 6 additions & 3 deletions compiler/rustc_driver/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -127,10 +127,13 @@ pub struct TimePassesCallbacks {
}

impl Callbacks for TimePassesCallbacks {
// JUSTIFICATION: the session doesn't exist at this point.
#[allow(rustc::bad_opt_access)]
fn config(&mut self, config: &mut interface::Config) {
// If a --prints=... option has been given, we don't print the "total"
// time because it will mess up the --prints output. See #64339.
self.time_passes = config.opts.prints.is_empty() && config.opts.time_passes();
// If a --print=... option has been given, we don't print the "total"
// time because it will mess up the --print output. See #64339.
//
self.time_passes = config.opts.prints.is_empty() && config.opts.unstable_opts.time_passes;
config.opts.trimmed_def_paths = TrimmedDefPaths::GoodPath;
}
}
Expand Down
1 change: 0 additions & 1 deletion compiler/rustc_interface/src/tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -692,7 +692,6 @@ fn test_unstable_options_tracking_hash() {
untracked!(span_free_formats, true);
untracked!(temps_dir, Some(String::from("abc")));
untracked!(threads, 99);
untracked!(time, true);
untracked!(time_llvm_passes, true);
untracked!(time_passes, true);
untracked!(trace_macros, true);
Expand Down
2 changes: 1 addition & 1 deletion compiler/rustc_lint/src/early.rs
Original file line number Diff line number Diff line change
Expand Up @@ -409,7 +409,7 @@ pub fn check_ast_node<'a>(
if sess.opts.unstable_opts.no_interleave_lints {
for (i, pass) in passes.iter_mut().enumerate() {
buffered =
sess.prof.extra_verbose_generic_activity("run_lint", pass.name()).run(|| {
sess.prof.verbose_generic_activity_with_arg("run_lint", pass.name()).run(|| {
early_lint_node(
sess,
!pre_expansion && i == 0,
Expand Down
17 changes: 10 additions & 7 deletions compiler/rustc_lint/src/late.rs
Original file line number Diff line number Diff line change
Expand Up @@ -425,20 +425,23 @@ fn late_lint_crate<'tcx, T: LateLintPass<'tcx>>(tcx: TyCtxt<'tcx>, builtin_lints
late_lint_pass_crate(tcx, builtin_lints);
} else {
for pass in &mut passes {
tcx.sess.prof.extra_verbose_generic_activity("run_late_lint", pass.name()).run(|| {
late_lint_pass_crate(tcx, LateLintPassObjects { lints: slice::from_mut(pass) });
});
tcx.sess.prof.verbose_generic_activity_with_arg("run_late_lint", pass.name()).run(
|| {
late_lint_pass_crate(tcx, LateLintPassObjects { lints: slice::from_mut(pass) });
},
);
}

let mut passes: Vec<_> =
unerased_lint_store(tcx).late_module_passes.iter().map(|pass| (pass)(tcx)).collect();

for pass in &mut passes {
tcx.sess.prof.extra_verbose_generic_activity("run_late_module_lint", pass.name()).run(
|| {
tcx.sess
.prof
.verbose_generic_activity_with_arg("run_late_module_lint", pass.name())
.run(|| {
late_lint_pass_crate(tcx, LateLintPassObjects { lints: slice::from_mut(pass) });
},
);
});
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion compiler/rustc_query_impl/src/on_disk_cache.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1067,7 +1067,7 @@ pub fn encode_query_results<'a, 'tcx, CTX, Q>(
let _timer = tcx
.dep_context()
.profiler()
.extra_verbose_generic_activity("encode_query_results_for", std::any::type_name::<Q>());
.verbose_generic_activity_with_arg("encode_query_results_for", std::any::type_name::<Q>());

assert!(Q::query_state(tcx).all_inactive());
let cache = Q::query_cache(tcx);
Expand Down
11 changes: 0 additions & 11 deletions compiler/rustc_session/src/options.rs
Original file line number Diff line number Diff line change
Expand Up @@ -280,14 +280,6 @@ macro_rules! options {

) }

impl Options {
// JUSTIFICATION: defn of the suggested wrapper fn
#[allow(rustc::bad_opt_access)]
pub fn time_passes(&self) -> bool {
self.unstable_opts.time_passes || self.unstable_opts.time
}
}

impl CodegenOptions {
// JUSTIFICATION: defn of the suggested wrapper fn
#[allow(rustc::bad_opt_access)]
Expand Down Expand Up @@ -1596,9 +1588,6 @@ options! {
#[rustc_lint_opt_deny_field_access("use `Session::threads` instead of this field")]
threads: usize = (1, parse_threads, [UNTRACKED],
"use a thread pool with N threads"),
#[rustc_lint_opt_deny_field_access("use `Session::time_passes` instead of this field")]
time: bool = (false, parse_bool, [UNTRACKED],
"measure time of rustc processes (default: no)"),
#[rustc_lint_opt_deny_field_access("use `Session::time_llvm_passes` instead of this field")]
time_llvm_passes: bool = (false, parse_bool, [UNTRACKED],
"measure time of each LLVM pass (default: no)"),
Expand Down
11 changes: 5 additions & 6 deletions compiler/rustc_session/src/session.rs
Original file line number Diff line number Diff line change
Expand Up @@ -606,10 +606,6 @@ impl Session {
self.parse_sess.source_map()
}

pub fn time_passes(&self) -> bool {
self.opts.time_passes()
}

/// Returns `true` if internal lints should be added to the lint store - i.e. if
/// `-Zunstable-options` is provided and this isn't rustdoc (internal lints can trigger errors
/// to be emitted under rustdoc).
Expand Down Expand Up @@ -927,6 +923,10 @@ impl Session {
self.opts.unstable_opts.instrument_mcount
}

pub fn time_passes(&self) -> bool {
self.opts.unstable_opts.time_passes
}

pub fn time_llvm_passes(&self) -> bool {
self.opts.unstable_opts.time_llvm_passes
}
Expand Down Expand Up @@ -1403,8 +1403,7 @@ pub fn build_session(
CguReuseTracker::new_disabled()
};

let prof =
SelfProfilerRef::new(self_profiler, sopts.time_passes(), sopts.unstable_opts.time_passes);
let prof = SelfProfilerRef::new(self_profiler, sopts.unstable_opts.time_passes);

let ctfe_backtrace = Lock::new(match env::var("RUSTC_CTFE_BACKTRACE") {
Ok(ref val) if val == "immediate" => CtfeBacktrace::Immediate,
Expand Down
2 changes: 1 addition & 1 deletion src/bootstrap/bin/rustc.rs
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ fn main() {
if target == "all"
|| target.into_string().unwrap().split(',').any(|c| c.trim() == crate_name)
{
cmd.arg("-Ztime");
cmd.arg("-Ztime-passes");
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion src/doc/rustc/src/command-line-arguments.md
Original file line number Diff line number Diff line change
Expand Up @@ -300,7 +300,7 @@ _Note:_ The order of these lint level arguments is taken into account, see [lint
## `-Z`: set unstable options

This flag will allow you to set unstable options of rustc. In order to set multiple options,
the -Z flag can be used multiple times. For example: `rustc -Z verbose -Z time`.
the -Z flag can be used multiple times. For example: `rustc -Z verbose -Z time-passes`.
Specifying options with -Z is only available on nightly. To view all available options
run: `rustc -Z help`.

Expand Down
4 changes: 2 additions & 2 deletions src/librustdoc/formats/renderer.rs
Original file line number Diff line number Diff line change
Expand Up @@ -58,7 +58,7 @@ pub(crate) fn run_format<'tcx, T: FormatRenderer<'tcx>>(

let emit_crate = options.should_emit_crate();
let (mut format_renderer, krate) = prof
.extra_verbose_generic_activity("create_renderer", T::descr())
.verbose_generic_activity_with_arg("create_renderer", T::descr())
.run(|| T::init(krate, options, cache, tcx))?;

if !emit_crate {
Expand Down Expand Up @@ -92,6 +92,6 @@ pub(crate) fn run_format<'tcx, T: FormatRenderer<'tcx>>(
.run(|| cx.item(item))?;
}
}
prof.extra_verbose_generic_activity("renderer_after_krate", T::descr())
prof.verbose_generic_activity_with_arg("renderer_after_krate", T::descr())
.run(|| format_renderer.after_krate())
}
1 change: 0 additions & 1 deletion src/test/rustdoc-ui/z-help.stdout
Original file line number Diff line number Diff line change
Expand Up @@ -170,7 +170,6 @@
-Z thinlto=val -- enable ThinLTO when possible
-Z thir-unsafeck=val -- use the THIR unsafety checker (default: no)
-Z threads=val -- use a thread pool with N threads
-Z time=val -- measure time of rustc processes (default: no)
-Z time-llvm-passes=val -- measure time of each LLVM pass (default: no)
-Z time-passes=val -- measure time of each rustc pass (default: no)
-Z tls-model=val -- choose the TLS model to use (`rustc --print tls-models` for details)
Expand Down