Profiling the compiler

Are there any tools for seeing what the compiler is spending most of its time on for a particular build?

Use cargo rustc -- -Z time-passes.

This can generate a fair amount of output, so you may want to pipe it into less or a file...

Example running cargo rustc -- -Z time-passes on the anpp crate
$ cd ~/Documents/anpp
$ cargo rustc -- -Z time-passes

  time: 0.016; rss: 50MB	parsing
  time: 0.000; rss: 50MB	attributes injection
  time: 0.000; rss: 50MB	garbage collect incremental cache directory
  time: 0.000; rss: 50MB	recursion limit
  time: 0.000; rss: 50MB	crate injection
  time: 0.000; rss: 50MB	plugin loading
  time: 0.000; rss: 50MB	plugin registration
  time: 0.000; rss: 50MB	background load prev dep-graph
  time: 0.001; rss: 50MB	pre ast expansion lint checks
    time: 0.048; rss: 68MB	expand crate
    time: 0.000; rss: 68MB	check unused macros
  time: 0.048; rss: 68MB	expansion
  time: 0.000; rss: 68MB	maybe building test harness
  time: 0.000; rss: 68MB	AST validation
  time: 0.000; rss: 68MB	maybe creating a macro crate
  time: 0.006; rss: 70MB	name resolution
  time: 0.002; rss: 70MB	complete gated feature checking
  time: 0.000; rss: 70MB	blocked while dep-graph loading finishes
  time: 0.006; rss: 72MB	lowering ast -> hir
  time: 0.001; rss: 72MB	early lint checks
    time: 0.001; rss: 72MB	validate hir map
  time: 0.007; rss: 72MB	indexing hir
  time: 0.000; rss: 72MB	load query result cache
  time: 0.000; rss: 77MB	dep graph tcx init
    time: 0.000; rss: 77MB	looking for entry point
    time: 0.000; rss: 77MB	looking for plugin registrar
    time: 0.000; rss: 77MB	looking for derive registrar
  time: 0.005; rss: 79MB	misc checking 1
  time: 0.012; rss: 82MB	type collecting
  time: 0.001; rss: 82MB	impl wf inference
    time: 0.000; rss: 103MB	unsafety checking
    time: 0.000; rss: 103MB	orphan checking
  time: 0.115; rss: 103MB	coherence checking
  time: 0.058; rss: 117MB	wf checking
  time: 0.016; rss: 117MB	item-types checking
  time: 0.134; rss: 120MB	item-bodies checking
    time: 0.016; rss: 120MB	rvalue promotion + match checking
    time: 0.002; rss: 120MB	liveness checking + intrinsic checking
  time: 0.018; rss: 120MB	misc checking 2
  time: 0.000; rss: 120MB	borrow checking
  time: 0.127; rss: 123MB	MIR borrow checking
  time: 0.000; rss: 123MB	dumping chalk-like clauses
  time: 0.000; rss: 123MB	MIR effect checking
  time: 0.000; rss: 123MB	layout testing
    time: 0.001; rss: 123MB	privacy access levels
    time: 0.001; rss: 123MB	private in public
    time: 0.001; rss: 123MB	death checking
    time: 0.000; rss: 123MB	unused lib feature checking
      time: 0.007; rss: 126MB	crate lints
      time: 0.001; rss: 126MB	module lints
    time: 0.009; rss: 126MB	lint checking
    time: 0.004; rss: 126MB	privacy checking modules
  time: 0.016; rss: 126MB	misc checking 3
  time: 0.000; rss: 126MB	resolving dependency formats
      time: 0.000; rss: 126MB	collecting roots
      time: 0.080; rss: 128MB	collecting mono items
    time: 0.081; rss: 128MB	monomorphization collection
    time: 0.003; rss: 128MB	codegen unit partitioning
  time: 0.105; rss: 129MB	metadata encoding and writing
    time: 0.000; rss: 131MB	llvm function passes [2fubfh2d4ufjh5cb]
    time: 0.002; rss: 131MB	llvm module passes [2fubfh2d4ufjh5cb]
    time: 0.000; rss: 134MB	llvm function passes [4egdn4q35duq2l33]
    time: 0.001; rss: 134MB	llvm module passes [4egdn4q35duq2l33]
    time: 0.000; rss: 140MB	llvm function passes [2mddrdg1xsksz3em]
    time: 0.001; rss: 140MB	llvm module passes [2mddrdg1xsksz3em]
    time: 0.000; rss: 141MB	llvm function passes [rdyc1t3d5v4q9xm]
    time: 0.001; rss: 141MB	llvm module passes [rdyc1t3d5v4q9xm]
    time: 0.032; rss: 142MB	codegen passes [4egdn4q35duq2l33]
    time: 0.000; rss: 142MB	llvm function passes [33qbvctref6inkoz]
    time: 0.000; rss: 142MB	llvm module passes [33qbvctref6inkoz]
    time: 0.062; rss: 144MB	codegen passes [2fubfh2d4ufjh5cb]
    time: 0.000; rss: 144MB	llvm function passes [4qqt9abhrmxygmka]
    time: 0.000; rss: 144MB	llvm module passes [4qqt9abhrmxygmka]
    time: 0.000; rss: 144MB	llvm function passes [lwgzdca81wr3sip]
    time: 0.002; rss: 144MB	llvm module passes [lwgzdca81wr3sip]
    time: 0.026; rss: 145MB	codegen passes [33qbvctref6inkoz]
    time: 0.048; rss: 145MB	codegen passes [2mddrdg1xsksz3em]
    time: 0.000; rss: 145MB	llvm function passes [5a45kmnikzvwi54b]
    time: 0.000; rss: 145MB	llvm module passes [5a45kmnikzvwi54b]
    time: 0.000; rss: 145MB	llvm function passes [ionsncebgdc5qb9]
    time: 0.000; rss: 145MB	llvm module passes [ionsncebgdc5qb9]
    time: 0.038; rss: 145MB	codegen passes [rdyc1t3d5v4q9xm]
    time: 0.026; rss: 146MB	codegen passes [4qqt9abhrmxygmka]
    time: 0.000; rss: 146MB	llvm function passes [1z2ek9zab7pttz7p]
    time: 0.000; rss: 146MB	llvm module passes [1z2ek9zab7pttz7p]
    time: 0.011; rss: 146MB	codegen passes [ionsncebgdc5qb9]
    time: 0.000; rss: 146MB	llvm function passes [4x5n0kok5gjq9qgq]
    time: 0.000; rss: 146MB	llvm module passes [4x5n0kok5gjq9qgq]
    time: 0.000; rss: 146MB	llvm function passes [1sjox6pa6wrum3ur]
    time: 0.028; rss: 146MB	codegen passes [lwgzdca81wr3sip]
    time: 0.001; rss: 146MB	llvm module passes [1sjox6pa6wrum3ur]
    time: 0.023; rss: 147MB	codegen passes [5a45kmnikzvwi54b]
    time: 0.000; rss: 147MB	llvm function passes [2gd5u7skaeyijktg]
    time: 0.000; rss: 147MB	llvm module passes [2gd5u7skaeyijktg]
    time: 0.000; rss: 147MB	llvm function passes [5cx3s2d27e6a5l5c]
    time: 0.000; rss: 147MB	llvm module passes [5cx3s2d27e6a5l5c]
    time: 0.012; rss: 147MB	codegen passes [1sjox6pa6wrum3ur]
    time: 0.007; rss: 147MB	codegen passes [2gd5u7skaeyijktg]
    time: 0.000; rss: 147MB	llvm function passes [2zyabubunmx4a1j5]
    time: 0.000; rss: 147MB	llvm module passes [2zyabubunmx4a1j5]
    time: 0.000; rss: 148MB	llvm function passes [1ybl4sslvuwzhyvh]
    time: 0.000; rss: 148MB	llvm module passes [1ybl4sslvuwzhyvh]
    time: 0.017; rss: 148MB	codegen passes [4x5n0kok5gjq9qgq]
    time: 0.000; rss: 148MB	llvm function passes [2e6v4rz6yle2wv8g]
    time: 0.000; rss: 148MB	llvm module passes [2e6v4rz6yle2wv8g]
    time: 0.029; rss: 148MB	codegen passes [1z2ek9zab7pttz7p]
    time: 0.014; rss: 148MB	codegen passes [5cx3s2d27e6a5l5c]
    time: 0.000; rss: 148MB	llvm function passes [2rqt3obaxbnerx61]
    time: 0.000; rss: 148MB	llvm module passes [2rqt3obaxbnerx61]
    time: 0.006; rss: 148MB	codegen passes [1ybl4sslvuwzhyvh]
    time: 0.000; rss: 149MB	llvm function passes [50x7c0qty43jml74]
    time: 0.008; rss: 149MB	codegen passes [2zyabubunmx4a1j5]
    time: 0.000; rss: 149MB	llvm module passes [50x7c0qty43jml74]
    time: 0.006; rss: 149MB	codegen passes [2e6v4rz6yle2wv8g]
    time: 0.000; rss: 149MB	llvm function passes [l4wgi8ipykoj791]
    time: 0.000; rss: 149MB	llvm module passes [l4wgi8ipykoj791]
    time: 0.005; rss: 149MB	codegen passes [50x7c0qty43jml74]
    time: 0.000; rss: 149MB	llvm function passes [q23j2wik01hzq5b]
    time: 0.000; rss: 149MB	llvm module passes [q23j2wik01hzq5b]
    time: 0.009; rss: 149MB	codegen passes [2rqt3obaxbnerx61]
    time: 0.000; rss: 149MB	llvm function passes [2f9k53zyo88xe0j]
    time: 0.000; rss: 149MB	llvm module passes [2f9k53zyo88xe0j]
    time: 0.000; rss: 149MB	llvm function passes [1uacq4wseaa1jlwz]
    time: 0.000; rss: 149MB	llvm function passes [2sq0zddu1b1emmil]
    time: 0.000; rss: 149MB	llvm module passes [2sq0zddu1b1emmil]
    time: 0.007; rss: 149MB	codegen passes [l4wgi8ipykoj791]
    time: 0.002; rss: 149MB	llvm module passes [1uacq4wseaa1jlwz]
    time: 0.000; rss: 149MB	llvm function passes [4i4wb3no5t7x070n]
    time: 0.000; rss: 149MB	llvm module passes [4i4wb3no5t7x070n]
    time: 0.006; rss: 149MB	codegen passes [q23j2wik01hzq5b]
    time: 0.005; rss: 149MB	codegen passes [2f9k53zyo88xe0j]
    time: 0.005; rss: 149MB	codegen passes [2sq0zddu1b1emmil]
    time: 0.004; rss: 149MB	codegen passes [4i4wb3no5t7x070n]
    time: 0.000; rss: 149MB	llvm function passes [5555lip13vzv8z38]
    time: 0.000; rss: 149MB	llvm module passes [5555lip13vzv8z38]
    time: 0.005; rss: 149MB	codegen passes [1uacq4wseaa1jlwz]
    time: 0.000; rss: 149MB	llvm function passes [28idhrlrwwqpqw2q]
    time: 0.000; rss: 149MB	llvm module passes [28idhrlrwwqpqw2q]
    time: 0.000; rss: 149MB	llvm function passes [1gqcf1bw5qb8msr3]
    time: 0.000; rss: 149MB	llvm module passes [1gqcf1bw5qb8msr3]
    time: 0.000; rss: 149MB	llvm function passes [2gbttgogxnfvcv6u]
    time: 0.000; rss: 149MB	llvm module passes [2gbttgogxnfvcv6u]
    time: 0.210; rss: 149MB	codegen to LLVM IR
    time: 0.000; rss: 149MB	assert dep graph
            time: 0.000; rss: 149MB	encode_query_results for rustc::ty::query::queries::type_of
            time: 0.000; rss: 149MB	encode_query_results for rustc::ty::query::queries::generics_of
            time: 0.000; rss: 149MB	encode_query_results for rustc::ty::query::queries::predicates_of
            time: 0.000; rss: 149MB	encode_query_results for rustc::ty::query::queries::mir_const_qualif
    time: 0.000; rss: 149MB	llvm function passes [4s7dzuygkvvu437b]
    time: 0.000; rss: 149MB	llvm module passes [4s7dzuygkvvu437b]
    time: 0.004; rss: 149MB	codegen passes [28idhrlrwwqpqw2q]
    time: 0.004; rss: 149MB	codegen passes [1gqcf1bw5qb8msr3]
    time: 0.003; rss: 149MB	codegen passes [2gbttgogxnfvcv6u]
            time: 0.004; rss: 150MB	encode_query_results for rustc::ty::query::queries::optimized_mir
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::unsafety_check_result
    time: 0.004; rss: 150MB	codegen passes [4s7dzuygkvvu437b]
            time: 0.001; rss: 150MB	encode_query_results for rustc::ty::query::queries::typeck_tables_of
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::used_trait_imports
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::borrowck
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::mir_borrowck
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::const_eval
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::check_match
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::symbol_name
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::codegen_fn_attrs
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::const_is_rvalue_promotable_to_static
            time: 0.000; rss: 150MB	encode_query_results for rustc::ty::query::queries::codegen_fulfill_obligation
            time: 0.003; rss: 150MB	encode_query_results for rustc::ty::query::queries::specialization_graph_of
          time: 0.010; rss: 150MB	encode query results
        time: 0.014; rss: 150MB	serialize query result cache
    time: 0.012; rss: 150MB	codegen passes [5555lip13vzv8z38]
      time: 0.015; rss: 150MB	persist query result cache
  time: 0.197; rss: 150MB	LLVM passes
          time: 0.005; rss: 152MB	getting serialized graph
          time: 0.010; rss: 154MB	encoding serialized graph
        time: 0.015; rss: 154MB	encode dep-graph
      time: 0.018; rss: 154MB	persist dep-graph
    time: 0.033; rss: 154MB	serialize dep graph
  time: 0.249; rss: 154MB	codegen
  time: 0.000; rss: 154MB	serialize work products
  time: 0.007; rss: 154MB	linking
time: 1.032; rss: 126MB		total
2 Likes

another useful tool in this space is https://github.com/RazrFalcon/cargo-bloat

2 Likes

To clarify, cargo bloat is useful for compiler profiling because areas of a program that generate a lot of code also often take a while to compile.