Why does parsing 1 line take 0.43 s?

Code:

ls ; cat lib.rs

lib.rs
extern crate r_main;

There is only 1 file, and it contains only the line extern crate r_main .

There is no build.rs.

The build time takes 0.43s.

The only "special" thing is this is the "root crate" (which includes everything else as a dependency).

Any idea what is causing this and how to speed this up? This would reduce compile time by ~15%.

Is it spending a lot of time in the linker? Which linker are you using?

Does it take that long when running cargo check? If not, then it's a problem with codegen or linking, not parsing.

Here is the output of

cargo check --target=wasm32-unknown-unknown --release --timings

  1. I am not sure why it went from 75 crates to 76 crates.

  2. It appears to have dropped from 0.43s to 0.19s

  3. I would love to use mold/gold , but I don't think either of those works with --target=wasm32-unknown-unknown

  4. I am wondering if there is a bunch of wasm_bindgen stuff that other crates are handling "lazily" , which then all gets dumped/blamed on the "final/root" crate in the runtime analysis.

Here is Cargo.toml in case it matters:

[package]
name = "client_w"
version = "0.1.0"
edition = "2021"

[lib]
crate-type = ["cdylib", "rlib"]

[features]

[dependencies]
r_main = { path = "..." }

[profile.release]
debug=false
opt-level = 3
lto="fat"
incremental = false
codegen-units = 16

Can you try rustup run stable cargo build. That should avoid the startup time of rustup showing in the graph. This is a fixed cost for every rustc invocation when rustup is used as wrapper to choose the right toolchain. Also try cargo +nightly rustc -- -Ztime-passes to show where exactly rustc spends time.

Sure. Let me know if there are other cmds to try.

cmd3

rustup run stable cargo build --release --timings

resulting in:

Commentary: wtf? This is now 1s?

cmd4

cargo +nightly rustc --release -- -Ztime-passes &> cmd4_res

results

[.. junk removed ..]

time:   0.000; rss:   33MB ->   35MB (   +2MB)	setup_global_ctxt
time:   0.044; rss:   35MB ->   85MB (  +50MB)	expand_crate
time:   0.044; rss:   35MB ->   85MB (  +50MB)	macro_expand_crate
time:   0.000; rss:   85MB ->   88MB (   +3MB)	looking_for_derive_registrar
time:   0.000; rss:   85MB ->   88MB (   +3MB)	misc_checking_1
time:   0.001; rss:   88MB ->   91MB (   +3MB)	generate_crate_metadata
time:   0.000; rss:   98MB ->   99MB (   +1MB)	write_allocator_module
time:   0.003; rss:   91MB ->   99MB (   +8MB)	codegen_crate
time:   0.003; rss:   99MB ->   59MB (  -40MB)	free_global_ctxt
time:   0.006; rss:   99MB ->   62MB (  -37MB)	LLVM_passes
time:   0.000; rss:   62MB ->   62MB (   +0MB)	join_worker_thread
time:   0.003; rss:   59MB ->   62MB (   +3MB)	finish_ongoing_codegen
time:   0.737; rss:   62MB ->   63MB (   +1MB)	run_linker
time:   0.742; rss:   62MB ->   63MB (   +1MB)	link_binary
time:   0.742; rss:   62MB ->   63MB (   +1MB)	link_crate
time:   0.746; rss:   59MB ->   63MB (   +4MB)	link
time:   0.804; rss:   26MB ->   60MB (  +34MB)	total

So the bulk of the work is the linker? I.e. the cyan green above is NOT parsing/type-checking, but linking instead ? That'd make sense.

Note that in the cargo timings chart, Rust library crates get split into two spans, one light blue for the parsing, type checking, etc, and one purple for code generation (going from intermediate representation to machine code); but binary (and cdylib) crates display all the time in blue. So, the time being shown is parsing, checking, code generation, and linking — no distinction is made.

This is largely an accident: the reason it can produce the distinction for libraries is because of “pipelined” compilation where rustc tells cargo as soon as the crate metadata is available and downstream crates can start being compiled, but for binaries and cdylibs there are no such intermediate outputs, so Cargo has no timing information about stages of that compilation. In order to have that information, someone would need to invent a protocol for rustc to produce it in a machine-readable way for Cargo to copy into the chart.

1 Like

This makes complete sense. I do not recall ever seeing purple in the final/binary crate.

Or merge Report codegen timings for binary crates by bjorn3 · Pull Request #10960 · rust-lang/cargo · GitHub which unconditionally adds --emit metadata even though it produces empty files for binaries. It is blocked on keeping the output-tracking code in sync though.

1 Like