mir-opt tests extremely slow.

[eddyb]

test [mir-opt] mir-opt/combine_array_len.rs has been running for over 60 seconds
test [mir-opt] mir-opt/inline-closure-borrows-arg.rs has been running for over 60 seconds
test [mir-opt] mir-opt/inline-closure.rs has been running for over 60 seconds
test [mir-opt] mir-opt/inline-trait-method.rs has been running for over 60 seconds
test [mir-opt] mir-opt/inline-trait-method_2.rs has been running for over 60 seconds
test [mir-opt] mir-opt/issue-38669.rs has been running for over 60 seconds
test [mir-opt] mir-opt/issue-41110.rs has been running for over 60 seconds
test [mir-opt] mir-opt/issue-41697.rs has been running for over 60 seconds

@Mark-Simulacrum is it possible this is all time spent in compiletest processing the output?

cc @rust-lang/compiler @RalfJung

[eddyb]

I can't reproduce anymore, but I've seen this before (usually just one message).

[RalfJung]

Maybe #58103 made emitting all this MIR really slow?

[Zoxc]

I think these have been slow for quite a while though.

[eddyb]

mir-opt is now my main bottleneck in running the tests (if not for #54712 (comment), it would be the only bottleneck in the entire build+test process), these are the numbers:

Suite	Time (seconds)
mir-opt	76.182
codegen	2.291
codegen-units	0.531
incremental	7.362
pretty	0.823
ui	33.044
compile-fail	0.640
run-make	0.638
run-fail	2.130
run-pass	58.316

Bonus: I get these messages (which hint to the slowest of all mir-opt tests, although perhaps I would want the message to be configurable, I consider tests that take over 10 seconds "effectively broken"):

test [mir-opt] mir-opt/lower_128bit_debug_test.rs has been running for over 60 seconds
test [mir-opt] mir-opt/lower_128bit_test.rs has been running for over 60 seconds

[eddyb]

Nominating for discussion (specifically, investigating this) at the next @rust-lang/compiler team meeting.

[eddyb]

I wanted to try get warnings for 10s instead of 60s, but sadly, it's hardcoded into libtest:

rust/src/libtest/lib.rs

Line 75 in 3bee49f

const TEST_WARN_TIMEOUT_S: u64 = 60;

And because we build compiletest against downloaded libtest, I had to add (to compiletest's Cargo.toml) test = { path = "../../libtest" }, and comment out extern crate test;.

---

Here are the warnings for mir-opt (click to open)

test [mir-opt] mir-opt/basic_assignment.rs has been running for over 10 seconds
test [mir-opt] mir-opt/array-index-is-temporary.rs has been running for over 10 seconds
test [mir-opt] mir-opt/box_expr.rs has been running for over 10 seconds
test [mir-opt] mir-opt/combine_array_len.rs has been running for over 10 seconds
test [mir-opt] mir-opt/copy_propagation_arg.rs has been running for over 10 seconds
test [mir-opt] mir-opt/deaggregator_test.rs has been running for over 10 seconds
test [mir-opt] mir-opt/deaggregator_test_enum.rs has been running for over 10 seconds
test [mir-opt] mir-opt/deaggregator_test_enum_2.rs has been running for over 10 seconds
test [mir-opt] mir-opt/deaggregator_test_multiple.rs has been running for over 10 seconds
test [mir-opt] mir-opt/generator-drop-cleanup.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-closure-borrows-arg.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-any-operand.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-retag.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-closure.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-trait-method.rs has been running for over 10 seconds
test [mir-opt] mir-opt/inline-trait-method_2.rs has been running for over 10 seconds
test [mir-opt] mir-opt/issue-41110.rs has been running for over 10 seconds
test [mir-opt] mir-opt/issue-41888.rs has been running for over 10 seconds
test [mir-opt] mir-opt/issue-41697.rs has been running for over 10 seconds
test [mir-opt] mir-opt/issue-49232.rs has been running for over 10 seconds
test [mir-opt] mir-opt/lower_128bit_test.rs has been running for over 10 seconds
test [mir-opt] mir-opt/lower_128bit_debug_test.rs has been running for over 10 seconds
test [mir-opt] mir-opt/match_false_edges.rs has been running for over 10 seconds
test [mir-opt] mir-opt/match_test.rs has been running for over 10 seconds
test [mir-opt] mir-opt/nll/region-subtyping-basic.rs has been running for over 10 seconds
test [mir-opt] mir-opt/remove_fake_borrows.rs has been running for over 10 seconds
test [mir-opt] mir-opt/packed-struct-drop-aligned.rs has been running for over 10 seconds
test [mir-opt] mir-opt/retag.rs has been running for over 10 seconds
test [mir-opt] mir-opt/simplify_if.rs has been running for over 10 seconds
test [mir-opt] mir-opt/simplify_match.rs has been running for over 10 seconds
test [mir-opt] mir-opt/storage_live_dead_in_statics.rs has been running for over 10 seconds
test [mir-opt] mir-opt/uniform_array_move_out.rs has been running for over 10 seconds
test [mir-opt] mir-opt/unusual-item-types.rs has been running for over 10 seconds

This is terrible: 33 out of 42 mir-opt tests take longer than 10 seconds.
And we haven't really noticed because of our (huge) minute-long warning delay.

The only other test suite that gets *any* warnings is run-pass (click to open)

test [run-pass] run-pass/issues/issue-29227.rs has been running for over 10 seconds
test [run-pass] run-pass/issues/issue-50811.rs has been running for over 10 seconds
test [run-pass] run-pass/mpsc_stress.rs has been running for over 10 seconds
test [run-pass] run-pass/numbers-arithmetic/saturating-float-casts.rs has been running for over 10 seconds
test [run-pass] run-pass/panic-runtime/lto-unwind.rs has been running for over 10 seconds
test [run-pass] run-pass/rustc-rust-log.rs has been running for over 10 seconds
test [run-pass] run-pass/stack-probes-lto.rs has been running for over 10 seconds

That's only 7 out of 2957, and some (all?) of those are intentional stress tests.

[RalfJung]

Wow, how do you get such times? run-pass takes many minutes for me, that's like 3k tests or so?

[eddyb]

As I mentioned in #54712 (comment), this is a -j48 machine.

[eddyb]

One solution @oli-obk and I are considering is adding an analogue of LLVM's -print-{before,after}, but for MIR, and as an alternative to -Z dump-mir (which creates a directory with many files).
Then, we can mostly use UI tests instead of mir-opt.

[pnkfelix]

triage: It would be great to resolve this. It would also be great if all of our rustc developers had a -j48 machine so that we would all share the same problem here.

however, I think given the reality of our common-case hardware, I do not think this falls into the P-high prioritization bucket. (Again, I do want to resolve it. but I don't want to revisit it's status every week.)

So I'm going to assign this P-medium priority for now. (And leave it nominated for discussion at the meeting.)