Skip to content

Commit

Permalink
Merge pull request rust-lang#1346 from bjorn3/self_profile_cleanup
Browse files Browse the repository at this point in the history 
Improve -Ztime-passes and -Zself-profile output
  • Loading branch information
@bjorn3
bjorn3 authored Feb 3, 2023
2 parents 21bdff8 + a0d3b09 commit 2c229a8
Show file tree
Hide file tree
Showing 5 changed files with 136 additions and 123 deletions.
60 changes: 36 additions & 24 deletions src/base.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,23 +21,6 @@ pub(crate) struct CodegenedFunction {
func_debug_cx: Option<FunctionDebugContext>,
}

#[cfg_attr(not(feature = "jit"), allow(dead_code))]
pub(crate) fn codegen_and_compile_fn<'tcx>(
tcx: TyCtxt<'tcx>,
cx: &mut crate::CodegenCx,
cached_context: &mut Context,
module: &mut dyn Module,
instance: Instance<'tcx>,
) {
let _inst_guard =
crate::PrintOnPanic(|| format!("{:?} {}", instance, tcx.symbol_name(instance).name));

let cached_func = std::mem::replace(&mut cached_context.func, Function::new());
let codegened_func = codegen_fn(tcx, cx, cached_func, module, instance);

compile_fn(cx, cached_context, module, codegened_func);
}

pub(crate) fn codegen_fn<'tcx>(
tcx: TyCtxt<'tcx>,
cx: &mut crate::CodegenCx,
Expand All @@ -47,6 +30,9 @@ pub(crate) fn codegen_fn<'tcx>(
) -> CodegenedFunction {
debug_assert!(!instance.substs.needs_infer());

let symbol_name = tcx.symbol_name(instance).name.to_string();
let _timer = tcx.prof.generic_activity_with_arg("codegen fn", &*symbol_name);

let mir = tcx.instance_mir(instance.def);
let _mir_guard = crate::PrintOnPanic(|| {
let mut buf = Vec::new();
Expand All @@ -58,7 +44,6 @@ pub(crate) fn codegen_fn<'tcx>(
});

// Declare function
let symbol_name = tcx.symbol_name(instance).name.to_string();
let sig = get_function_sig(tcx, module.target_config().default_call_conv, instance);
let func_id = module.declare_function(&symbol_name, Linkage::Local, &sig).unwrap();

Expand Down Expand Up @@ -112,7 +97,7 @@ pub(crate) fn codegen_fn<'tcx>(
next_ssa_var: 0,
};

tcx.sess.time("codegen clif ir", || codegen_fn_body(&mut fx, start_block));
tcx.prof.generic_activity("codegen clif ir").run(|| codegen_fn_body(&mut fx, start_block));
fx.bcx.seal_all_blocks();
fx.bcx.finalize();

Expand Down Expand Up @@ -146,6 +131,9 @@ pub(crate) fn compile_fn(
module: &mut dyn Module,
codegened_func: CodegenedFunction,
) {
let _timer =
cx.profiler.generic_activity_with_arg("compile function", &*codegened_func.symbol_name);

let clif_comments = codegened_func.clif_comments;

// Store function in context
Expand Down Expand Up @@ -191,9 +179,30 @@ pub(crate) fn compile_fn(
};

// Define function
cx.profiler.verbose_generic_activity("define function").run(|| {
cx.profiler.generic_activity("define function").run(|| {
context.want_disasm = cx.should_write_ir;
module.define_function(codegened_func.func_id, context).unwrap();

if cx.profiler.enabled() {
let mut recording_args = false;
cx.profiler
.generic_activity_with_arg_recorder(
"define function (clif pass timings)",
|recorder| {
let pass_times = cranelift_codegen::timing::take_current();
// Replace newlines with | as measureme doesn't allow control characters like
// newlines inside strings.
recorder.record_arg(format!("{}", pass_times).replace("\n", " | "));
recording_args = true;
},
)
.run(|| {
if recording_args {
// Wait a tiny bit to ensure chrome's profiler doesn't hide the event
std::thread::sleep(std::time::Duration::from_nanos(2))
}
});
}
});

if cx.should_write_ir {
Expand All @@ -220,7 +229,7 @@ pub(crate) fn compile_fn(
let isa = module.isa();
let debug_context = &mut cx.debug_context;
let unwind_context = &mut cx.unwind_context;
cx.profiler.verbose_generic_activity("generate debug info").run(|| {
cx.profiler.generic_activity("generate debug info").run(|| {
if let Some(debug_context) = debug_context {
codegened_func.func_debug_cx.unwrap().finalize(
debug_context,
Expand All @@ -237,7 +246,7 @@ pub(crate) fn verify_func(
writer: &crate::pretty_clif::CommentWriter,
func: &Function,
) {
tcx.sess.time("verify clif ir", || {
tcx.prof.generic_activity("verify clif ir").run(|| {
let flags = cranelift_codegen::settings::Flags::new(cranelift_codegen::settings::builder());
match cranelift_codegen::verify_function(&func, &flags) {
Ok(_) => {}
Expand Down Expand Up @@ -273,7 +282,10 @@ fn codegen_fn_body(fx: &mut FunctionCx<'_, '_, '_>, start_block: Block) {
fx.bcx.ins().trap(TrapCode::UnreachableCodeReached);
return;
}
fx.tcx.sess.time("codegen prelude", || crate::abi::codegen_fn_prelude(fx, start_block));
fx.tcx
.prof
.generic_activity("codegen prelude")
.run(|| crate::abi::codegen_fn_prelude(fx, start_block));

for (bb, bb_data) in fx.mir.basic_blocks.iter_enumerated() {
let block = fx.get_block(bb);
Expand Down Expand Up @@ -434,7 +446,7 @@ fn codegen_fn_body(fx: &mut FunctionCx<'_, '_, '_>, start_block: Block) {
cleanup: _,
from_hir_call: _,
} => {
fx.tcx.sess.time("codegen call", || {
fx.tcx.prof.generic_activity("codegen call").run(|| {
crate::abi::codegen_terminator_call(
fx,
mir::SourceInfo { span: *fn_span, ..source_info },
Expand Down
8 changes: 0 additions & 8 deletions src/config.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,12 +42,6 @@ pub struct BackendConfig {
/// Defaults to the value of `CG_CLIF_JIT_ARGS`.
pub jit_args: Vec<String>,

/// Display the time it took to perform codegen for a crate.
///
/// Defaults to true when the `CG_CLIF_DISPLAY_CG_TIME` env var is set to 1 or false otherwise.
/// Can be set using `-Cllvm-args=display_cg_time=...`.
pub display_cg_time: bool,

/// Enable the Cranelift ir verifier for all compilation passes. If not set it will only run
/// once before passing the clif ir to Cranelift for compilation.
///
Expand All @@ -73,7 +67,6 @@ impl Default for BackendConfig {
let args = std::env::var("CG_CLIF_JIT_ARGS").unwrap_or_else(|_| String::new());
args.split(' ').map(|arg| arg.to_string()).collect()
},
display_cg_time: bool_env_var("CG_CLIF_DISPLAY_CG_TIME"),
enable_verifier: cfg!(debug_assertions) || bool_env_var("CG_CLIF_ENABLE_VERIFIER"),
disable_incr_cache: bool_env_var("CG_CLIF_DISABLE_INCR_CACHE"),
}
Expand All @@ -92,7 +85,6 @@ impl BackendConfig {
if let Some((name, value)) = opt.split_once('=') {
match name {
"mode" => config.codegen_mode = value.parse()?,
"display_cg_time" => config.display_cg_time = parse_bool(name, value)?,
"enable_verifier" => config.enable_verifier = parse_bool(name, value)?,
"disable_incr_cache" => config.disable_incr_cache = parse_bool(name, value)?,
_ => return Err(format!("Unknown option `{}`", name)),
Expand Down
130 changes: 72 additions & 58 deletions src/driver/aot.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -272,25 +272,25 @@ fn module_codegen(
ConcurrencyLimiterToken,
),
) -> OngoingModuleCodegen {
let (cgu_name, mut cx, mut module, codegened_functions) = tcx.sess.time("codegen cgu", || {
let cgu = tcx.codegen_unit(cgu_name);
let mono_items = cgu.items_in_deterministic_order(tcx);

let mut module = make_module(tcx.sess, &backend_config, cgu_name.as_str().to_string());

let mut cx = crate::CodegenCx::new(
tcx,
backend_config.clone(),
module.isa(),
tcx.sess.opts.debuginfo != DebugInfo::None,
cgu_name,
);
super::predefine_mono_items(tcx, &mut module, &mono_items);
let mut codegened_functions = vec![];
for (mono_item, _) in mono_items {
match mono_item {
MonoItem::Fn(inst) => {
tcx.sess.time("codegen fn", || {
let (cgu_name, mut cx, mut module, codegened_functions) =
tcx.prof.verbose_generic_activity_with_arg("codegen cgu", cgu_name.as_str()).run(|| {
let cgu = tcx.codegen_unit(cgu_name);
let mono_items = cgu.items_in_deterministic_order(tcx);

let mut module = make_module(tcx.sess, &backend_config, cgu_name.as_str().to_string());

let mut cx = crate::CodegenCx::new(
tcx,
backend_config.clone(),
module.isa(),
tcx.sess.opts.debuginfo != DebugInfo::None,
cgu_name,
);
super::predefine_mono_items(tcx, &mut module, &mono_items);
let mut codegened_functions = vec![];
for (mono_item, _) in mono_items {
match mono_item {
MonoItem::Fn(inst) => {
let codegened_function = crate::base::codegen_fn(
tcx,
&mut cx,
Expand All @@ -299,53 +299,68 @@ fn module_codegen(
inst,
);
codegened_functions.push(codegened_function);
});
}
MonoItem::Static(def_id) => {
crate::constant::codegen_static(tcx, &mut module, def_id)
}
MonoItem::GlobalAsm(item_id) => {
crate::global_asm::codegen_global_asm_item(tcx, &mut cx.global_asm, item_id);
}
MonoItem::Static(def_id) => {
crate::constant::codegen_static(tcx, &mut module, def_id)
}
MonoItem::GlobalAsm(item_id) => {
crate::global_asm::codegen_global_asm_item(
tcx,
&mut cx.global_asm,
item_id,
);
}
}
}
}
crate::main_shim::maybe_create_entry_wrapper(
tcx,
&mut module,
&mut cx.unwind_context,
false,
cgu.is_primary(),
);
crate::main_shim::maybe_create_entry_wrapper(
tcx,
&mut module,
&mut cx.unwind_context,
false,
cgu.is_primary(),
);

let cgu_name = cgu.name().as_str().to_owned();
let cgu_name = cgu.name().as_str().to_owned();

(cgu_name, cx, module, codegened_functions)
});
(cgu_name, cx, module, codegened_functions)
});

OngoingModuleCodegen::Async(std::thread::spawn(move || {
cx.profiler.clone().verbose_generic_activity("compile functions").run(|| {
let mut cached_context = Context::new();
for codegened_func in codegened_functions {
crate::base::compile_fn(&mut cx, &mut cached_context, &mut module, codegened_func);
}
});
cx.profiler.clone().verbose_generic_activity_with_arg("compile functions", &*cgu_name).run(
|| {
let mut cached_context = Context::new();
for codegened_func in codegened_functions {
crate::base::compile_fn(
&mut cx,
&mut cached_context,
&mut module,
codegened_func,
);
}
},
);

let global_asm_object_file =
cx.profiler.verbose_generic_activity("compile assembly").run(|| {
let global_asm_object_file = cx
.profiler
.verbose_generic_activity_with_arg("compile assembly", &*cgu_name)
.run(|| {
crate::global_asm::compile_global_asm(&global_asm_config, &cgu_name, &cx.global_asm)
})?;

let codegen_result = cx.profiler.verbose_generic_activity("write object file").run(|| {
emit_cgu(
&global_asm_config.output_filenames,
&cx.profiler,
cgu_name,
module,
cx.debug_context,
cx.unwind_context,
global_asm_object_file,
)
});
let codegen_result = cx
.profiler
.verbose_generic_activity_with_arg("write object file", &*cgu_name)
.run(|| {
emit_cgu(
&global_asm_config.output_filenames,
&cx.profiler,
cgu_name,
module,
cx.debug_context,
cx.unwind_context,
global_asm_object_file,
)
});
std::mem::drop(token);
codegen_result
}))
Expand Down Expand Up @@ -375,7 +390,7 @@ pub(crate) fn run_aot(

let mut concurrency_limiter = ConcurrencyLimiter::new(tcx.sess, cgus.len());

let modules = super::time(tcx, backend_config.display_cg_time, "codegen mono items", || {
let modules = tcx.sess.time("codegen mono items", || {
cgus.iter()
.map(|cgu| {
let cgu_reuse = if backend_config.disable_incr_cache {
Expand Down Expand Up @@ -437,7 +452,6 @@ pub(crate) fn run_aot(
};

let metadata_module = if need_metadata_module {
let _timer = tcx.prof.generic_activity("codegen crate metadata");
let (metadata_cgu_name, tmp_file) = tcx.sess.time("write compressed metadata", || {
use rustc_middle::mir::mono::CodegenUnitNameBuilder;

Expand Down
Loading

0 comments on commit 2c229a8

Please sign in to comment.