How to log incremental build cache hit rate?

I'm invoking rustc with -Cincremental, but I didn't see any improvement in build time from that change.

My crate consists of ~100 files, and it took 20s to compile with or without the -Cincremental setting. Is there a flag to log extra info?

I've also tried -Zself-profile and it showed that most of the time was spent on type_check_crate, which I believe should also be cached. Is there a way to debug that as well?

Thanks!

What build command are you using exactly? The incremental flag should be given a folder name as an argument, and cached files are stored there. What's in that folder?

rustc 
<redacted>/lib.rs
--crate-name=<redacted>
--crate-type=rlib
--error-format=human
--codegen=metadata=-3754067897
--codegen=extra-filename=-3754067897
--out-dir=bazel-out/darwin_arm64-fastbuild/bin/<redacted>
--codegen=opt-level=0
--codegen=debuginfo=0
--codegen=strip=none
--remap-path-prefix=${pwd}=
--emit=dep-info,link
--color=always
--target=aarch64-apple-darwin
-L
bazel-out/darwin_arm64-fastbuild/bin/external/rust_darwin_aarch64__aarch64-apple-darwin__nightly_tools/rust_toolchain/lib/rustlib/aarch64-apple-darwin/lib
-Cincremental=/Volumes/buildcache/rustc
-Ccodegen-units=256
-Zquery-dep-graph
-Zdump-dep-graph
-Zincremental_info
-Zself-profile=/Volumes/buildcache/rustc-profiles
-Zself-profile-events=default,args
--edition=2021
--extern=<redacted>=bazel-out/darwin_arm64-fastbuild/<redacted>.rlib
-Ldependency=<redacted>
--sysroot=bazel-out/darwin_arm64-fastbuild/bin/external/rust_darwin_aarch64__aarch64-apple-darwin__nightly_tools/rust_toolchain
-Cdebuginfo=2

log from rustc

DEBUG rustc_incremental::persist::fs prepare_session_directory
DEBUG rustc_incremental::persist::fs crate-dir: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi
DEBUG rustc_incremental::persist::fs crate directory created successfully
DEBUG rustc_incremental::persist::fs generate_session_dir_path: timestamp = h13u16xhkw
DEBUG rustc_incremental::persist::fs generate_session_dir_path: random_number = 3849889860
DEBUG rustc_incremental::persist::fs generate_session_dir_path: directory_name = s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs generate_session_dir_path: directory_path = /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs session-dir: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs lock_directory() - lock_file: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10.lock
DEBUG rustc_incremental::persist::fs session directory created successfully
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - inspecting `/Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic`
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - inspecting `/Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo.lock`
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - ignoring
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - inspecting `/Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10.lock`
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - ignoring
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - inspecting `/Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working`
DEBUG rustc_incremental::persist::fs find_source_directory_in_iter - ignoring
DEBUG rustc_incremental::persist::fs attempting to copy data from source: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs copying into session dir: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic/4enqo360davarw5r.o
...
DEBUG rustc_incremental::persist::fs copying into session dir: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic/44z3d48495be7cr.o
[incremental] session directory: 259 files hard-linked
[incremental] session directory: 0 files copied
DEBUG rustc_incremental::persist::fs successfully copied data from: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::load reconcile_work_products: all files for SerializedWorkProduct { id: WorkProductId { hash: Fingerprint(17296380767295142947, 3346606510128134118) }, work_product: WorkProduct { cgu_name: "10b1mvnln4wv5w3u", saved_files: UnordMap { inner: {"o": "10b1mvnln4wv5w3u.o"} } } } exist
...
DEBUG rustc_incremental::persist::load reconcile_work_products: all files for SerializedWorkProduct { id: WorkProductId { hash: Fingerprint(10867519834341061362, 14566736545293184855) }, work_product: WorkProduct { cgu_name: "zwpwtf7q99ulimw", saved_files: UnordMap { inner: {"o": "zwpwtf7q99ulimw.o"} } } } exist
[incremental] completely ignoring cache because of differing commandline arguments
DEBUG rustc_incremental::persist::load load_dep_graph_new: differing commandline arg hashes
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - begin
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - session directory: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - crate directory: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - inspecting: s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - successfully acquired lock
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - adding deletion candidate: s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - inspecting: s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - not finalized, not old enough
DEBUG rustc_incremental::persist::save save_dep_graph()
DEBUG rustc_incremental::assert_dep_graph n=Null s="Null"
...
DEBUG rustc_incremental::assert_dep_graph n=specialization_graph_of s="specialization_graph_of"
[incremental]
[incremental] DepGraph Statistics
[incremental] ------------------------------------------------------------------------------------------
[incremental]
[incremental] Total Node Count: 1128638
[incremental] Total Edge Count: 11429221
[incremental] Total Edge Reads: 55367369
[incremental] Total Duplicate Edge Reads: 43412130
[incremental]
[incremental]  Node Kind                           | Node Frequency   | Node Count  | Avg. Edge Count  |
[incremental] ------------------------------------------------------------------------------------------
[incremental]  layout_of                           |             6.2% |       69700 |              2.4 |
[incremental]  fn_abi_of_instance                  |             4.9% |       55682 |             12.0 |
[incremental]  symbol_name                         |             4.8% |       54727 |             14.7 |
[incremental]  impl_trait_header                   |             4.1% |       46027 |              1.1 |
[incremental]  impl_parent                         |             3.9% |       44565 |              1.0 |
[incremental]  TraitSelect                         |             3.8% |       43079 |             15.0 |
[incremental]  implementations_of_trait            |             3.7% |       41316 |              1.0 |
[incremental]  resolve_instance                    |             3.4% |       38870 |              6.5 |
[incremental]  evaluate_obligation                 |             3.0% |       33375 |              2.2 |
[incremental]  def_kind                            |             2.4% |       26977 |              1.0 |
[incremental]  def_span                            |             2.1% |       23624 |              1.9 |
[incremental]  generics_of                         |             2.0% |       22807 |              3.0 |
[incremental]  explicit_predicates_of              |             2.0% |       22237 |              4.0 |
[incremental]  inferred_outlives_of                |             2.0% |       22237 |              1.0 |
[incremental]  predicates_of                       |             2.0% |       22017 |              2.0 |
[incremental]  predicates_defined_on               |             2.0% |       22017 |              2.0 |
[incremental]  def_ident_span                      |             1.8% |       20876 |              1.9 |
[incremental]  visibility                          |             1.8% |       20403 |              1.0 |
[incremental]  local_def_id_to_hir_id              |             1.7% |       19403 |              1.0 |
[incremental]  param_env                           |             1.7% |       18982 |              4.0 |
[incremental]  type_op_prove_predicate             |             1.5% |       17344 |              9.0 |
[incremental]  type_of                             |             1.4% |       15870 |              3.2 |
[incremental]  is_copy_raw                         |             1.3% |       14642 |              4.0 |
[incremental]  source_span                         |             1.3% |       14344 |              0.0 |
[incremental]  needs_drop_raw                      |             1.2% |       13600 |              3.9 |
[incremental]  opt_hir_owner_nodes                 |             1.2% |       13355 |              1.0 |
[incremental]  hir_attrs                           |             1.2% |       13355 |              1.0 |
[incremental]  check_well_formed                   |             1.2% |       13350 |             15.4 |
[incremental]  hir_owner_parent                    |             1.2% |       13306 |              2.0 |
[incremental]  inhabited_predicate_type            |             1.2% |       13285 |              1.3 |
[incremental]  codegen_select_candidate            |             1.2% |       13168 |             17.4 |
[incremental]  shallow_lint_levels_on              |             1.1% |       12653 |              6.8 |
...
[incremental] ------------------------------------------------------------------------------------------
[incremental]
DEBUG rustc_incremental::persist::file_format save: storing data in /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working/query-cache.bin
DEBUG rustc_incremental::persist::file_format save: data written to disk successfully
DEBUG rustc_incremental::persist::work_product cgu_name="10b1mvnln4wv5w3u", files=[("o", "bazel-out/darwin_arm64-fastbuild/bin/<redacted>/<redacted>-3754067897.10b1mvnln4wv5w3u.rcgu.o")]
DEBUG rustc_incremental::persist::work_product work_product=WorkProduct { cgu_name: "10b1mvnln4wv5w3u", saved_files: UnordMap { inner: {"o": "10b1mvnln4wv5w3u.o"} } }
...
DEBUG rustc_incremental::persist::work_product cgu_name="zwpwtf7q99ulimw", files=[("o", "bazel-out/darwin_arm64-fastbuild/bin/<redacted>/<redacted>-3754067897.zwpwtf7q99ulimw.rcgu.o")]
DEBUG rustc_incremental::persist::work_product work_product=WorkProduct { cgu_name: "zwpwtf7q99ulimw", saved_files: UnordMap { inner: {"o": "zwpwtf7q99ulimw.o"} } }
DEBUG rustc_incremental::persist::save save_work_product_index()
DEBUG rustc_incremental::persist::file_format save: storing data in /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working/work-products.bin
DEBUG rustc_incremental::persist::file_format save: data written to disk successfully
DEBUG rustc_incremental::persist::fs finalize_session_directory() - session directory: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-working
DEBUG rustc_incremental::persist::fs finalize_session_directory() - new path: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs finalize_session_directory() - directory renamed successfully
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - begin
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - session directory: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h13u16xhkw-1ro4i10-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - crate directory: /Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - inspecting: s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - successfully acquired lock
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - adding deletion candidate: s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - inspecting: s-h13u16xhkw-1ro4i10-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - successfully acquired lock
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - adding deletion candidate: s-h13u16xhkw-1ro4i10-9tazx8khw630agw3szgvjjlic
DEBUG rustc_incremental::persist::fs garbage_collect_session_directories() - deleting `/Volumes/buildcache/rustc/<redacted>-274bbz4wt5uvi/s-h12ob8dtfr-r6a1fo-9tazx8khw630agw3szgvjjlic`