Better self profiling integration

Author: bjorn3

.gitignore

@@ -4,6 +4,8 @@ target
 *.o
 perf.data
 perf.data.old
+*.events
+*.string*
 /build_sysroot/sysroot
 /build_sysroot/sysroot_src
 /build_sysroot/Cargo.lock

src/base.rs

@@ -61,8 +61,10 @@ pub fn trans_fn<'clif, 'tcx, B: Backend + 'static>(
         fx.bcx.switch_to_block(entry_block);
         crate::trap::trap_unreachable(&mut fx, "function has uninhabited argument");
     } else {
-        crate::abi::codegen_fn_prelude(&mut fx, start_ebb);
-        codegen_fn_content(&mut fx);
+        tcx.sess.time("codegen clif ir", || {
+            tcx.sess.time("codegen prelude", || crate::abi::codegen_fn_prelude(&mut fx, start_ebb));
+            codegen_fn_content(&mut fx);
+        });
     }
 
     // Recover all necessary data from fx, before accessing func will prevent future access to it.
@@ -78,10 +80,13 @@ pub fn trans_fn<'clif, 'tcx, B: Backend + 'static>(
     verify_func(tcx, &clif_comments, &context.func);
 
     // Perform rust specific optimizations
-    crate::optimize::optimize_function(cx.tcx, instance, context, &mut clif_comments);
+    tcx.sess.time("optimize clif ir", || {
+        crate::optimize::optimize_function(tcx, instance, context, &mut clif_comments);
+    });
 
     // Define function
-    cx.module.define_function(func_id, context).unwrap();
+    let module = &mut cx.module;
+    tcx.sess.time("define function", || module.define_function(func_id, context).unwrap());
 
     // Write optimized function to file for debugging
     #[cfg(debug_assertions)]
@@ -102,30 +107,34 @@ pub fn trans_fn<'clif, 'tcx, B: Backend + 'static>(
 
     // Define debuginfo for function
     let isa = cx.module.isa();
-    debug_context
-        .as_mut()
-        .map(|x| x.define(context, isa, &source_info_set, local_map));
+    tcx.sess.time("generate debug info", || {
+        debug_context
+            .as_mut()
+            .map(|x| x.define(context, isa, &source_info_set, local_map));
+    });
 
     // Clear context to make it usable for the next function
     context.clear();
 }
 
 pub fn verify_func(tcx: TyCtxt, writer: &crate::pretty_clif::CommentWriter, func: &Function) {
-    let flags = settings::Flags::new(settings::builder());
-    match ::cranelift_codegen::verify_function(&func, &flags) {
-        Ok(_) => {}
-        Err(err) => {
-            tcx.sess.err(&format!("{:?}", err));
-            let pretty_error = ::cranelift_codegen::print_errors::pretty_verifier_error(
-                &func,
-                None,
-                Some(Box::new(writer)),
-                err,
-            );
-            tcx.sess
-                .fatal(&format!("cranelift verify error:\n{}", pretty_error));
+    tcx.sess.time("verify clif ir", || {
+        let flags = settings::Flags::new(settings::builder());
+        match ::cranelift_codegen::verify_function(&func, &flags) {
+            Ok(_) => {}
+            Err(err) => {
+                tcx.sess.err(&format!("{:?}", err));
+                let pretty_error = ::cranelift_codegen::print_errors::pretty_verifier_error(
+                    &func,
+                    None,
+                    Some(Box::new(writer)),
+                    err,
+                );
+                tcx.sess
+                    .fatal(&format!("cranelift verify error:\n{}", pretty_error));
+            }
         }
-    }
+    });
 }
 
 fn codegen_fn_content(fx: &mut FunctionCx<'_, '_, impl Backend>) {
@@ -225,13 +234,13 @@ fn codegen_fn_content(fx: &mut FunctionCx<'_, '_, impl Backend>) {
                 cleanup: _,
                 from_hir_call: _,
             } => {
-                crate::abi::codegen_terminator_call(
+                fx.tcx.sess.time("codegen call", || crate::abi::codegen_terminator_call(
                     fx,
                     func,
                     args,
                     destination,
                     bb_data.terminator().source_info.span,
-                );
+                ));
             }
             TerminatorKind::Resume | TerminatorKind::Abort => {
                 trap_unreachable(fx, "[corruption] Unwinding bb reached.");

src/driver.rs

@@ -294,18 +294,20 @@ fn codegen_mono_items<'tcx>(
 ) {
     let mut cx = CodegenCx::new(tcx, module, debug_context);
 
-    time("codegen mono items", move || {
-        for (&mono_item, &(linkage, visibility)) in &mono_items {
-            match mono_item {
-                MonoItem::Fn(instance) => {
-                    let (name, sig) =
-                        get_function_name_and_sig(tcx, cx.module.isa().triple(), instance, false);
-                    let linkage = crate::linkage::get_clif_linkage(mono_item, linkage, visibility);
-                    cx.module.declare_function(&name, linkage, &sig).unwrap();
+    time(tcx.sess, "codegen mono items", move || {
+        tcx.sess.time("predefine functions", || {
+            for (&mono_item, &(linkage, visibility)) in &mono_items {
+                match mono_item {
+                    MonoItem::Fn(instance) => {
+                        let (name, sig) =
+                            get_function_name_and_sig(tcx, cx.module.isa().triple(), instance, false);
+                        let linkage = crate::linkage::get_clif_linkage(mono_item, linkage, visibility);
+                        cx.module.declare_function(&name, linkage, &sig).unwrap();
+                    }
+                    MonoItem::Static(_) | MonoItem::GlobalAsm(_) => {}
                 }
-                MonoItem::Static(_) | MonoItem::GlobalAsm(_) => {}
             }
-        }
+        });
 
         for (mono_item, (linkage, visibility)) in mono_items {
             crate::unimpl::try_unimpl(tcx, || {
@@ -314,7 +316,7 @@ fn codegen_mono_items<'tcx>(
             });
         }
 
-        cx.finalize();
+        tcx.sess.time("finalize CodegenCx", || cx.finalize());
     });
 }
 
@@ -350,7 +352,7 @@ fn trans_mono_item<'clif, 'tcx, B: Backend + 'static>(
                 }
             });
 
-            crate::base::trans_fn(cx, inst, linkage);
+            cx.tcx.sess.time("codegen fn", || crate::base::trans_fn(cx, inst, linkage));
         }
         MonoItem::Static(def_id) => {
             crate::constant::codegen_static(&mut cx.constants_cx, def_id);
@@ -361,10 +363,10 @@ fn trans_mono_item<'clif, 'tcx, B: Backend + 'static>(
     }
 }
 
-fn time<R>(name: &str, f: impl FnOnce() -> R) -> R {
+fn time<R>(sess: &Session, name: &str, f: impl FnOnce() -> R) -> R {
     println!("[{}] start", name);
     let before = std::time::Instant::now();
-    let res = f();
+    let res = sess.time(name, f);
     let after = std::time::Instant::now();
     println!("[{}] end time: {:?}", name, after - before);
     res