Rollup merge of rust-lang#68932 - michaelwoerister:self-profile-gener…

…ic-activity-args, r=wesleywiser

self-profile: Support arguments for generic_activities.

This PR adds support for recording arguments of "generic activities". The most notable use case is LLVM module names, which should be very interesting for `crox` profiles. In the future it might be interesting to add more fine-grained events for pre-query passes like macro expansion.

I tried to judiciously de-duplicate existing self-profile events with `extra_verbose_generic_activity`, now that the latter also generates self-profile events.

r? @wesleywiser

src/librustc/ty/query/on_disk_cache.rs

@@ -1053,8 +1053,10 @@ where
     Q: super::config::QueryDescription<'tcx, Value: Encodable>,
     E: 'a + TyEncoder,
 {
-    let desc = &format!("encode_query_results_for_{}", ::std::any::type_name::<Q>());
-    let _timer = tcx.sess.prof.extra_verbose_generic_activity(desc);
+    let _timer = tcx
+        .sess
+        .prof
+        .extra_verbose_generic_activity("encode_query_results_for", ::std::any::type_name::<Q>());
 
     let shards = Q::query_cache(tcx).lock_shards();
     assert!(shards.iter().all(|shard| shard.active.is_empty()));

src/librustc_codegen_llvm/back/lto.rs

@@ -110,23 +110,21 @@ fn prepare_lto(
                 symbol_white_list.extend(exported_symbols[&cnum].iter().filter_map(symbol_filter));
             }
 
-            let _timer = cgcx.prof.generic_activity("LLVM_lto_load_upstream_bitcode");
             let archive = ArchiveRO::open(&path).expect("wanted an rlib");
             let bytecodes = archive
                 .iter()
                 .filter_map(|child| child.ok().and_then(|c| c.name().map(|name| (name, c))))
                 .filter(|&(name, _)| name.ends_with(RLIB_BYTECODE_EXTENSION));
             for (name, data) in bytecodes {
+                let _timer =
+                    cgcx.prof.generic_activity_with_arg("LLVM_lto_load_upstream_bitcode", name);
                 info!("adding bytecode {}", name);
                 let bc_encoded = data.data();
 
-                let (bc, id) = cgcx
-                    .prof
-                    .extra_verbose_generic_activity(&format!("decode {}", name))
-                    .run(|| match DecodedBytecode::new(bc_encoded) {
-                        Ok(b) => Ok((b.bytecode(), b.identifier().to_string())),
-                        Err(e) => Err(diag_handler.fatal(&e)),
-                    })?;
+                let (bc, id) = match DecodedBytecode::new(bc_encoded) {
+                    Ok(b) => Ok((b.bytecode(), b.identifier().to_string())),
+                    Err(e) => Err(diag_handler.fatal(&e)),
+                }?;
                 let bc = SerializedModule::FromRlib(bc);
                 upstream_modules.push((bc, CString::new(id).unwrap()));
             }
@@ -281,14 +279,14 @@ fn fat_lto(
         // save and persist everything with the original module.
         let mut linker = Linker::new(llmod);
         for (bc_decoded, name) in serialized_modules {
-            let _timer = cgcx.prof.generic_activity("LLVM_fat_lto_link_module");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_fat_lto_link_module", format!("{:?}", name));
             info!("linking {:?}", name);
-            cgcx.prof.extra_verbose_generic_activity(&format!("ll link {:?}", name)).run(|| {
-                let data = bc_decoded.data();
-                linker.add(&data).map_err(|()| {
-                    let msg = format!("failed to load bc of {:?}", name);
-                    write::llvm_err(&diag_handler, &msg)
-                })
+            let data = bc_decoded.data();
+            linker.add(&data).map_err(|()| {
+                let msg = format!("failed to load bc of {:?}", name);
+                write::llvm_err(&diag_handler, &msg)
             })?;
             serialized_bitcode.push(bc_decoded);
         }
@@ -577,6 +575,8 @@ pub(crate) fn run_pass_manager(
     config: &ModuleConfig,
     thin: bool,
 ) {
+    let _timer = cgcx.prof.extra_verbose_generic_activity("LLVM_lto_optimize", &module.name[..]);
+
     // Now we have one massive module inside of llmod. Time to run the
     // LTO-specific optimization passes that LLVM provides.
     //
@@ -634,9 +634,7 @@ pub(crate) fn run_pass_manager(
             llvm::LLVMRustAddPass(pm, pass.unwrap());
         }
 
-        cgcx.prof
-            .extra_verbose_generic_activity("LTO_passes")
-            .run(|| llvm::LLVMRunPassManager(pm, module.module_llvm.llmod()));
+        llvm::LLVMRunPassManager(pm, module.module_llvm.llmod());
 
         llvm::LLVMDisposePassManager(pm);
     }
@@ -760,7 +758,9 @@ pub unsafe fn optimize_thin_module(
         // Like with "fat" LTO, get some better optimizations if landing pads
         // are disabled by removing all landing pads.
         if cgcx.no_landing_pads {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_remove_landing_pads");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_thin_lto_remove_landing_pads", thin_module.name());
             llvm::LLVMRustMarkAllFunctionsNounwind(llmod);
             save_temp_bitcode(&cgcx, &module, "thin-lto-after-nounwind");
         }
@@ -774,7 +774,8 @@ pub unsafe fn optimize_thin_module(
         // You can find some more comments about these functions in the LLVM
         // bindings we've got (currently `PassWrapper.cpp`)
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_rename");
+            let _timer =
+                cgcx.prof.generic_activity_with_arg("LLVM_thin_lto_rename", thin_module.name());
             if !llvm::LLVMRustPrepareThinLTORename(thin_module.shared.data.0, llmod) {
                 let msg = "failed to prepare thin LTO module";
                 return Err(write::llvm_err(&diag_handler, msg));
@@ -783,7 +784,9 @@ pub unsafe fn optimize_thin_module(
         }
 
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_resolve_weak");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_thin_lto_resolve_weak", thin_module.name());
             if !llvm::LLVMRustPrepareThinLTOResolveWeak(thin_module.shared.data.0, llmod) {
                 let msg = "failed to prepare thin LTO module";
                 return Err(write::llvm_err(&diag_handler, msg));
@@ -792,7 +795,9 @@ pub unsafe fn optimize_thin_module(
         }
 
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_internalize");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_thin_lto_internalize", thin_module.name());
             if !llvm::LLVMRustPrepareThinLTOInternalize(thin_module.shared.data.0, llmod) {
                 let msg = "failed to prepare thin LTO module";
                 return Err(write::llvm_err(&diag_handler, msg));
@@ -801,7 +806,8 @@ pub unsafe fn optimize_thin_module(
         }
 
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_import");
+            let _timer =
+                cgcx.prof.generic_activity_with_arg("LLVM_thin_lto_import", thin_module.name());
             if !llvm::LLVMRustPrepareThinLTOImport(thin_module.shared.data.0, llmod) {
                 let msg = "failed to prepare thin LTO module";
                 return Err(write::llvm_err(&diag_handler, msg));
@@ -839,7 +845,9 @@ pub unsafe fn optimize_thin_module(
         // so it appears). Hopefully we can remove this once upstream bugs are
         // fixed in LLVM.
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_patch_debuginfo");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_thin_lto_patch_debuginfo", thin_module.name());
             llvm::LLVMRustThinLTOPatchDICompileUnit(llmod, cu1);
             save_temp_bitcode(cgcx, &module, "thin-lto-after-patch");
         }
@@ -850,7 +858,6 @@ pub unsafe fn optimize_thin_module(
         // populate a thin-specific pass manager, which presumably LLVM treats a
         // little differently.
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_thin_lto_optimize");
             info!("running thin lto passes over {}", module.name);
             let config = cgcx.config(module.kind);
             run_pass_manager(cgcx, &module, config, true);

src/librustc_codegen_llvm/back/write.rs

@@ -310,7 +310,7 @@ pub(crate) unsafe fn optimize(
     module: &ModuleCodegen<ModuleLlvm>,
     config: &ModuleConfig,
 ) -> Result<(), FatalError> {
-    let _timer = cgcx.prof.generic_activity("LLVM_module_optimize");
+    let _timer = cgcx.prof.generic_activity_with_arg("LLVM_module_optimize", &module.name[..]);
 
     let llmod = module.module_llvm.llmod();
     let llcx = &*module.module_llvm.llcx;
@@ -424,23 +424,17 @@ pub(crate) unsafe fn optimize(
 
         // Finally, run the actual optimization passes
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_module_optimize_function_passes");
-            let desc = &format!("llvm function passes [{}]", module_name.unwrap());
-            let _timer = if config.time_module {
-                Some(cgcx.prof.extra_verbose_generic_activity(desc))
-            } else {
-                None
-            };
+            let _timer = cgcx.prof.extra_verbose_generic_activity(
+                "LLVM_module_optimize_function_passes",
+                &module.name[..],
+            );
             llvm::LLVMRustRunFunctionPassManager(fpm, llmod);
         }
         {
-            let _timer = cgcx.prof.generic_activity("LLVM_module_optimize_module_passes");
-            let desc = &format!("llvm module passes [{}]", module_name.unwrap());
-            let _timer = if config.time_module {
-                Some(cgcx.prof.extra_verbose_generic_activity(desc))
-            } else {
-                None
-            };
+            let _timer = cgcx.prof.extra_verbose_generic_activity(
+                "LLVM_module_optimize_module_passes",
+                &module.name[..],
+            );
             llvm::LLVMRunPassManager(mpm, llmod);
         }
 
@@ -480,7 +474,7 @@ pub(crate) unsafe fn codegen(
     module: ModuleCodegen<ModuleLlvm>,
     config: &ModuleConfig,
 ) -> Result<CompiledModule, FatalError> {
-    let _timer = cgcx.prof.generic_activity("LLVM_module_codegen");
+    let _timer = cgcx.prof.generic_activity_with_arg("LLVM_module_codegen", &module.name[..]);
     {
         let llmod = module.module_llvm.llmod();
         let llcx = &*module.module_llvm.llcx;
@@ -533,26 +527,36 @@ pub(crate) unsafe fn codegen(
         let obj_out = cgcx.output_filenames.temp_path(OutputType::Object, module_name);
 
         if write_bc || config.emit_bc_compressed || config.embed_bitcode {
-            let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_make_bitcode");
+            let _timer = cgcx
+                .prof
+                .generic_activity_with_arg("LLVM_module_codegen_make_bitcode", &module.name[..]);
             let thin = ThinBuffer::new(llmod);
             let data = thin.data();
 
             if write_bc {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_emit_bitcode");
+                let _timer = cgcx.prof.generic_activity_with_arg(
+                    "LLVM_module_codegen_emit_bitcode",
+                    &module.name[..],
+                );
                 if let Err(e) = fs::write(&bc_out, data) {
                     let msg = format!("failed to write bytecode to {}: {}", bc_out.display(), e);
                     diag_handler.err(&msg);
                 }
             }
 
             if config.embed_bitcode {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_embed_bitcode");
+                let _timer = cgcx.prof.generic_activity_with_arg(
+                    "LLVM_module_codegen_embed_bitcode",
+                    &module.name[..],
+                );
                 embed_bitcode(cgcx, llcx, llmod, Some(data));
             }
 
             if config.emit_bc_compressed {
-                let _timer =
-                    cgcx.prof.generic_activity("LLVM_module_codegen_emit_compressed_bitcode");
+                let _timer = cgcx.prof.generic_activity_with_arg(
+                    "LLVM_module_codegen_emit_compressed_bitcode",
+                    &module.name[..],
+                );
                 let dst = bc_out.with_extension(RLIB_BYTECODE_EXTENSION);
                 let data = bytecode::encode(&module.name, data);
                 if let Err(e) = fs::write(&dst, data) {
@@ -565,15 +569,10 @@ pub(crate) unsafe fn codegen(
         }
 
         {
-            let desc = &format!("codegen passes [{}]", module_name.unwrap());
-            let _timer = if config.time_module {
-                Some(cgcx.prof.extra_verbose_generic_activity(desc))
-            } else {
-                None
-            };
-
             if config.emit_ir {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_emit_ir");
+                let _timer = cgcx
+                    .prof
+                    .generic_activity_with_arg("LLVM_module_codegen_emit_ir", &module.name[..]);
                 let out = cgcx.output_filenames.temp_path(OutputType::LlvmAssembly, module_name);
                 let out_c = path_to_c_string(&out);
 
@@ -618,7 +617,9 @@ pub(crate) unsafe fn codegen(
             }
 
             if config.emit_asm || asm_to_obj {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_emit_asm");
+                let _timer = cgcx
+                    .prof
+                    .generic_activity_with_arg("LLVM_module_codegen_emit_asm", &module.name[..]);
                 let path = cgcx.output_filenames.temp_path(OutputType::Assembly, module_name);
 
                 // We can't use the same module for asm and binary output, because that triggers
@@ -638,7 +639,9 @@ pub(crate) unsafe fn codegen(
             }
 
             if write_obj {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_emit_obj");
+                let _timer = cgcx
+                    .prof
+                    .generic_activity_with_arg("LLVM_module_codegen_emit_obj", &module.name[..]);
                 with_codegen(tm, llmod, config.no_builtins, |cpm| {
                     write_output_file(
                         diag_handler,
@@ -650,7 +653,9 @@ pub(crate) unsafe fn codegen(
                     )
                 })?;
             } else if asm_to_obj {
-                let _timer = cgcx.prof.generic_activity("LLVM_module_codegen_asm_to_obj");
+                let _timer = cgcx
+                    .prof
+                    .generic_activity_with_arg("LLVM_module_codegen_asm_to_obj", &module.name[..]);
                 let assembly = cgcx.output_filenames.temp_path(OutputType::Assembly, module_name);
                 run_assembler(cgcx, diag_handler, &assembly, &obj_out);
 

src/librustc_codegen_ssa/back/link.rs

@@ -1648,7 +1648,7 @@ fn add_upstream_rust_crates<'a, B: ArchiveBuilder<'a>>(
         let name = cratepath.file_name().unwrap().to_str().unwrap();
         let name = &name[3..name.len() - 5]; // chop off lib/.rlib
 
-        sess.prof.extra_verbose_generic_activity(&format!("altering {}.rlib", name)).run(|| {
+        sess.prof.generic_activity_with_arg("link_altering_rlib", name).run(|| {
             let mut archive = <B as ArchiveBuilder>::new(sess, &dst, Some(cratepath));
             archive.update_symbols();
 

src/librustc_codegen_ssa/back/write.rs

@@ -21,6 +21,7 @@ use rustc::session::Session;
 use rustc::ty::TyCtxt;
 use rustc_data_structures::fx::FxHashMap;
 use rustc_data_structures::profiling::SelfProfilerRef;
+use rustc_data_structures::profiling::TimingGuard;
 use rustc_data_structures::profiling::VerboseTimingGuard;
 use rustc_data_structures::svh::Svh;
 use rustc_data_structures::sync::Lrc;
@@ -691,11 +692,17 @@ impl<B: WriteBackendMethods> WorkItem<B> {
         }
     }
 
-    fn profiling_event_id(&self) -> &'static str {
+    fn start_profiling<'a>(&self, cgcx: &'a CodegenContext<B>) -> TimingGuard<'a> {
         match *self {
-            WorkItem::Optimize(_) => "codegen_module_optimize",
-            WorkItem::CopyPostLtoArtifacts(_) => "codegen_copy_artifacts_from_incr_cache",
-            WorkItem::LTO(_) => "codegen_module_perform_lto",
+            WorkItem::Optimize(ref m) => {
+                cgcx.prof.generic_activity_with_arg("codegen_module_optimize", &m.name[..])
+            }
+            WorkItem::CopyPostLtoArtifacts(ref m) => cgcx
+                .prof
+                .generic_activity_with_arg("codegen_copy_artifacts_from_incr_cache", &m.name[..]),
+            WorkItem::LTO(ref m) => {
+                cgcx.prof.generic_activity_with_arg("codegen_module_perform_lto", m.name())
+            }
         }
     }
 }
@@ -1520,7 +1527,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"));
+            *llvm_start_time = Some(prof.extra_verbose_generic_activity("LLVM_passes", "crate"));
         }
     }
 }
@@ -1575,7 +1582,7 @@ fn spawn_work<B: ExtraBackendMethods>(cgcx: CodegenContext<B>, work: WorkItem<B>
         // as a diagnostic was already sent off to the main thread - just
         // surface that there was an error in this worker.
         bomb.result = {
-            let _prof_timer = cgcx.prof.generic_activity(work.profiling_event_id());
+            let _prof_timer = work.start_profiling(&cgcx);
             Some(execute_work_item(&cgcx, work))
         };
     });