Rust macro extremely slow and with high disk usage

help
1

I have a crate that generate code with macros using quote and proc_macro2::TokenStream.
When the size of the generated code increase a little, the compilation time explodes exponentially, and the disk usage of my SSD stays at 100% for a few minutes.

What advice should I follow to keep the compilation time reasonable?

What could explain the unreasonable disk usage by rustc when the code produce by the macro grows? (only half of my 16gb of ram was used)

2

Do you have a reproducer?

3

I've set-up two branches to reproduce: macro1 and macro2 in GitHub - tdelmas/floats

The diff between the two: Comparing macro1...macro2 · tdelmas/floats · GitHub

:warning: DO NOT open the branch macro2 on vscode, between the background build that takes 15 minutes (with 100% disk usage on the end) and rust-analyzer, it will be hard to work.

To reproduce:

(all those steps were done on a terminal, with vscode - and rust-analyzer - closed)

The slow macro is only called in the code that generate test, so we can pre-build the app (and the dependencies) with cargo build first and then build the app with tests (that needs that macro to be built) with cargo test --no-run (anyway the tests are fast, less than a second)

# initialisation
git checkout https://github.com/tdelmas/floats
cd floats

Then we can prepare the build for macro1 with:

git switch macro1
# to remove any previous build
cargo clean
# dowload and build deps, the build without the impacted feature
cargo build
# build with the problematic macro
cargo test --no-run

That last command took 14 seconds on my Windows and 15 on my other computer with Linux (Ubuntu).
(slow, but reasonable)

To compare with the other branch macro2:

git switch macro2
# to remove any previous build
cargo clean
# dowload and build deps, the build without the impacted feature
cargo build
# build with the problematic macro
cargo test --no-run

And that last command, that build with the macro that is problematic, with took 15 MINUTES on my Windows and 8 minutes on my Linux.

The code between the two branches should not change in complexity, only in size. If we assume that most of the time is spent in the code where the diff is, then the build should take at most 5 times more, not 60.

Or did I make a catastrophic mistake in my code?

I use in this version:

output.extend(quote! {
  #add
  #sub
  #mul
  #div
  #rem
});

Where #add, #sub, ... are generated before with (simplifying): let add = quote! { ... },
but the previous version had one call to output.extend per var, and was as slow (I changed it to limit the number of call to output.extend, but that had apparently no impact.).

I can probably avoid the problem by generating less code with macros and adding methods on my objects to run more code at runtime is I don't understand why the build time explode, but I would really prefer not to and understand what's happening here.

More context:

The problematic macro is called here: floats/typed_floats/src/lib.rs at macro1 · tdelmas/floats · GitHub

The call to #add and 4 others is in a double loop (of 12 elements each, from get_specifications).
They all generate a similar code by calling test_op_self_rhs (which calls test_op_checks). None of those function contains any loop. They just concatenate quotes!.

These two loops generate all combinations of NonNaN,NonNaNFinite, NonZeroNonNaN, NonZeroNonNaNFinite, Positive,PositiveFinite, StrictlyPositive, StrictlyPositiveFinite, Negative,NegativeFinite, StrictlyNegative, StrictlyNegativeFinite to generate the tests that:

  • verify that the output types of the operations (like +) is not too strict
  • verify that the output type is as strict as possible

The functions XXX_result like add_result take two times as parameters, and the list of all types, and determine the resulting type if we add two number of those types. (if the result of that function is None it means that it may be NaN thus none of those types fit and f64 must be the return type for that operation)

(Cf https://crates.io/crates/typed_floats)

4

Hi, please add links to cross-posts to avoid duplicated effort by the community:

1 Like
5

@jofas You're 100% correct, I've updated the stackoverflow post to add the cross-post link, sorry for the omission.

1 Like
6

After more experimentations, here is what I found:

I expanded the macros with cargo +nightly rustc --profile=check -- -Zunpretty=expanded (and make public the test functions so they are built) and created two projects, one for each branch describe before.

I've clean/fix the generated code so it can compile.

The generated code for each branch looked like expected, the macros didn't had any bug.

When building those two projects, that are not using macros anymore, the build time was the same (15 seconds for the first one versus 15 minutes for the second one).

So the problem doesn't come from the macros at all

First project:

Second project:

(the second source file is not formatted because cargo fmt answer with thread 'main' has overflowed its stack, so it may be a little less than 57k lines of codes)

So the compilation time is due to the rust compiler, and the 100% disk usage is most probably due to the 13 GB query-cache.bin file.

I will use less macros and more runtime.

7

Using the advice given in

I turned off the incremental compilation, it did solve the disk usage problem, and reduce the compilation time by ~30% (which is still 10 minutes).