rust-lang/miri

-Zmiri-disable-isolation slows down tests significantly

Kestrer opened this issue · 6 comments

When running the command RUSTFLAGS="-Zmiri-disable-isolation" cargo +nightly miri test on any crate, Miri hangs for about twelve seconds after printing Running target/... and before running the actual tests. (Without the flag, Miri hangs for just a second, and without Miri at all there's no hang.)

I am running Miri de0800e 2021-01-25 on x86_64-unknown-linux-gnu.

Thanks for reporting this! I have seen the same problem in the past but never investigated it.

My current theory is that forwarding environment variables means the test runner does a lot of extra work somewhere, and that causes the slowdown. But it would be good to nail this down.

(The short hang with default settings is likely due to the test runner collecting the tests in a map or list of some sort -- in my experience this takes longer the more tests there are, so this is just the "normal" effect of Miri being slow.)

pvdrz commented

what if we forward the env variables directly instead of using the intermediate map when isolation is disabled?

I doubt that will make any difference.
#1791 could help, once it landed.

pvdrz commented

You're right, I don't know why I thought that this was fault of collecting the environment variables in a hashmap.

Using the new -Zmiri-measureme feature, I ran cargo miri test on a newly created package (with no tests). The generated chrome_profile.json shows 12 seconds being spent in term::stdout, which is used by the standard library test crate to determine whether or not to pretty-print the test output. This involves reading the TERM environment variable, and searching various system paths for a terminfo file: https://github.com/Stebalien/term/blob/8d1259b21b25b00974122f6660ea8b9866a4dae6/src/terminfo/searcher.rs#L22. Neither of these will work with isolation enabled.

8 seconds of the total time is spent in std::io::BufReader::<std::fs::File>::buffer (which is called as a result of parsing the terminfo file read from disk): https://doc.rust-lang.org/src/std/io/buffered/bufreader.rs.html#173-175

This method just slices a Box<[u8]>. It appears that the overhead is coming from Stacked Borrows - running MIRIFLAGS="-Zmiri-disable-isolation -Zmiri-disable-stacked-borrows" cargo miri test takes around 2 seconds on my machine (compared to around 11 seconds for MIRIFLAGS="-Zmiri-disable-isolation" cargo miri test)

Given this result, I wonder if it would make sense to exclude the TERM variable by default on all platforms? (We currently exclude it by default on Windows only.)

Meanwhile, -Zmiri-env-exclude=TERM successfully works around the slowdown.