search

rust-lang / rust

Empowering everyone to build reliable and efficient software.
https://www.rust-lang.org
Other
97.96k stars 12.69k forks source link

Ztime-passes: columns not always seperated #73263

Open matthiaskrgr opened 4 years ago

matthiaskrgr commented 4 years ago

Sometimes when compiling code with -Ztime-passes, there is no space between rss column and the pass-name column:

time: 0.001; rss: 110MB match_checking
time: 0.000; rss: 110MB liveness_and_intrinsic_checking
time: 0.002; rss: 110MB misc_checking_2
time: 0.016; rss: 117MB MIR_borrow_checking
time: 0.000; rss: 117MB MIR_effect_checking
time: 0.000; rss: 117MB layout_testing
time: 0.000; rss: 117MB death_checking
time: 0.000; rss: 117MB unused_lib_feature_checking
time: 0.000; rss: 117MB crate_lints
time: 0.000; rss: 117MB module_lints
time: 0.001; rss: 117MB lint_checking
time: 0.000; rss: 117MB privacy_checking_modules
time: 0.003; rss: 117MB misc_checking_3
time: 0.000; rss: 117MB monomorphization_collector_root_collections
time: 0.000; rss: 51MBparse_crate
time: 0.000; rss: 51MBattributes_injection
time: 0.000; rss: 54MBrecursion_limit
time: 0.000; rss: 54MBplugin_loading
time: 0.000; rss: 54MBplugin_registration
time: 0.000; rss: 54MBpre_AST_expansion_lint_checks
time: 0.000; rss: 54MBcrate_injection
time: 0.009; rss: 67MBexpand_crate
time: 0.000; rss: 67MBcheck_unused_macros
time: 0.010; rss: 67MBmacro_expand_crate
time: 0.000; rss: 67MBmaybe_building_test_harness
time: 0.000; rss: 67MBAST_validation
time: 0.000; rss: 67MBmaybe_create_a_macro_crate
time: 0.000; rss: 67MBcomplete_gated_feature_checking
time: 0.011; rss: 67MBconfigure_and_expand
time: 0.001; rss: 67MBprepare_outputs
time: 0.000; rss: 67MBhir_lowering
time: 0.000; rss: 67MBearly_lint_checks
time: 0.000; rss: 70MBsetup_global_ctxt
time: 0.000; rss: 70MBdep_graph_tcx_init
time: 0.001; rss: 70MBcreate_global_ctxt
time: 0.000; rss: 72MBlooking_for_entry_point
time: 0.000; rss: 72MBlooking_for_plugin_registrar
time: 0.000; rss: 72MBlooking_for_derive_registrar

rustc 1.46.0-nightly (feb3536eb 2020-06-09) binary: rustc commit-hash: feb3536eba10c2e4585d066629598f03d5ddc7c6 commit-date: 2020-06-09 host: x86_64-unknown-linux-gnu release: 1.46.0-nightly LLVM version: 10.0

ayushmishra2005 commented 4 years ago

@matthiaskrgr Can you please share the same snippet for reproducing this bug? I am not able to reproduce this. According to https://github.com/rust-lang/rust/blob/master/src/librustc_data_structures/profiling.rs#L597, this should not be the case.

matthiaskrgr commented 4 years ago

When building cargo with RUSTFLAGS="-Ztime-passes" cargo build -j 1, some of the deps miss the space.

ayushmishra2005 commented 4 years ago

I tried using above command. But still I am not able to reproduce it.

time: 0.001; rss: 51MB parse_crate time: 0.000; rss: 51MB attributes_injection time: 0.002; rss: 51MB incr_comp_prepare_session_directory time: 0.000; rss: 51MB incr_comp_garbage_collect_session_directories time: 0.000; rss: 51MB recursion_limit time: 0.000; rss: 51MB plugin_loading time: 0.000; rss: 51MB plugin_registration time: 0.000; rss: 54MB pre_AST_expansion_lint_checks time: 0.000; rss: 54MB crate_injection time: 0.032; rss: 76MB expand_crate time: 0.000; rss: 76MB check_unused_macros time: 0.032; rss: 76MB macro_expand_crate time: 0.000; rss: 76MB maybe_building_test_harness time: 0.000; rss: 76MB AST_validation time: 0.000; rss: 76MB maybe_create_a_macro_crate time: 0.000; rss: 79MB complete_gated_feature_checking time: 0.033; rss: 79MB configure_and_expand time: 0.000; rss: 79MB prepare_outputs time: 0.000; rss: 79MB blocked_on_dep_graph_loading time: 0.000; rss: 80MB hir_lowering time: 0.000; rss: 80MB early_lint_checks time: 0.004; rss: 87MB setup_global_ctxt time: 0.000; rss: 88MB dep_graph_tcx_init time: 0.005; rss: 88MB create_global_ctxt time: 0.000; rss: 88MB looking_for_entry_point time: 0.000; rss: 88MB looking_for_plugin_registrar time: 0.000; rss: 88MB looking_for_derive_registrar time: 0.000; rss: 92MB misc_checking_1 time: 0.000; rss: 92MB type_collecting time: 0.000; rss: 92MB impl_wf_inference time: 0.000; rss: 92MB unsafety_checking time: 0.000; rss: 92MB orphan_checking time: 0.000; rss: 92MB coherence_checking time: 0.000; rss: 92MB wf_checking time: 0.000; rss: 92MB item_types_checking time: 0.001; rss: 95MB item_bodies_checking time: 0.002; rss: 96MB type_check_crate time: 0.000; rss: 96MB match_checking time: 0.000; rss: 96MB liveness_and_intrinsic_checking time: 0.000; rss: 96MB misc_checking_2 time: 0.000; rss: 96MB MIR_borrow_checking time: 0.000; rss: 98MB MIR_effect_checking time: 0.000; rss: 98MB layout_testing time: 0.000; rss: 98MB death_checking time: 0.000; rss: 98MB unused_lib_feature_checking time: 0.000; rss: 101MB crate_lints time: 0.000; rss: 101MB module_lints time: 0.000; rss: 101MB lint_checking time: 0.000; rss: 101MB privacy_checking_modules time: 0.001; rss: 101MB misc_checking_3 time: 0.000; rss: 101MB monomorphization_collector_root_collections time: 0.015; rss: 122MB monomorphization_collector_graph_walk time: 0.001; rss: 123MB partition_and_assert_distinct_symbols time: 0.000; rss: 125MB write_allocator_module time: 0.000; rss: 125MB find_cgu_reuse time: 0.000; rss: 129MB codegen_to_LLVM_IR time: 0.000; rss: 129MB assert_dep_graph time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::type_of) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::generics_of) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::predicates_of) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::mir_const_qualif) time: 0.005; rss: 129MB LLVM_passes(crate) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::optimized_mir) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::coverage_data) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::promoted_mir) time: 0.000; rss: 129MB encode_query_results_for(rustc_middle::ty::query::queries::unsafety_check_result) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::typeck_tables_of) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::diagnostic_only_typeck_tables_of) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::used_trait_imports) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::mir_borrowck) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::const_eval_validated) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::check_match) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::symbol_name) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::codegen_fn_attrs) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::codegen_fulfill_obligation) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::specialization_graph_of) time: 0.000; rss: 130MB encode_query_results_for(rustc_middle::ty::query::queries::adt_drop_tys) time: 0.001; rss: 130MB encode_query_results time: 0.002; rss: 130MB incr_comp_serialize_result_cache time: 0.002; rss: 130MB incr_comp_persist_result_cache time: 0.001; rss: 130MB incr_comp_serialize_dep_graph time: 0.001; rss: 131MB incr_comp_encode_serialized_dep_graph time: 0.002; rss: 131MB incr_comp_encode_dep_graph time: 0.002; rss: 131MB incr_comp_persist_dep_graph time: 0.004; rss: 131MB serialize_dep_graph time: 0.030; rss: 131MB codegen_crate time: 0.001; rss: 109MB free_global_ctxt time: 0.000; rss: 109MB join_worker_thread time: 0.000; rss: 109MB copy_all_cgu_workproducts_to_incr_comp_cache_dir time: 0.000; rss: 109MB finish_ongoing_codegen time: 0.000; rss: 109MB serialize_work_products time: 0.000; rss: 109MB link_binary_check_files_are_writeable time: 0.105; rss: 109MB run_linker time: 0.000; rss: 109MB link_binary_remove_temps time: 0.106; rss: 109MB link_binary time: 0.106; rss: 109MB link_crate time: 0.000; rss: 109MB incr_comp_finalize_session_directory time: 0.000; rss: 109MB llvm_dump_timing_file time: 0.107; rss: 109MB link

Enselic commented 1 year ago

@rustbot label A-self-profile