Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

rustbuild: Fix copying duplicate crates into the sysroot #42263

Merged
merged 1 commit into from
Jun 1, 2017

Conversation

alexcrichton
Copy link
Member

@alexcrichton alexcrichton commented May 27, 2017

After compiling a project (e.g. libstd, libtest, or librustc) rustbuild needs to
copy over all artifacts into the sysroot of the compiler it's assembling.
Unfortunately rustbuild doesn't know precisely what files to copy! Today it has
a heuristic where it just looks at the most recent version of all files that
look like rlibs/dylibs and copies those over. This unfortunately leads to bugs
with different versions of the same crate as seen in #42261.

This commit updates rustbuild's strategy of copying artifacts to work off the
list of artifacts produced by cargo build --message-format=json. The build
system will now parse json messages coming out of Cargo to watch for files being
generated, and then it'll only copy over those precise files.

Note that there's still a bit of weird logic where Cargo prints that it's
creating libstd.rlib where we actually want libstd-xxxxx.rlib, so we still
do a bit of "most recent file" probing for those. This commit should take care
of the crates.io dependency issues, however, as they're all copied over
precisely.

Closes #42261

@rust-highfive
Copy link
Collaborator

r? @nikomatsakis

(rust_highfive has picked a reviewer for you, use r? to override)

@Mark-Simulacrum Mark-Simulacrum added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label May 28, 2017
@Mark-Simulacrum
Copy link
Member

Changes look good to me. Giving slight priority since this unblocks other work.

@bors r+ p=1

@bors
Copy link
Contributor

bors commented May 28, 2017

📌 Commit 684e33a has been approved by Mark-Simulacrum

@Mark-Simulacrum Mark-Simulacrum added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels May 28, 2017
@bors
Copy link
Contributor

bors commented May 28, 2017

⌛ Testing commit 684e33a with merge f212c5d...

@bors
Copy link
Contributor

bors commented May 28, 2017

💔 Test failed - status-appveyor

@Mark-Simulacrum
Copy link
Member

Failure seems potentially non-spurious/related, but not sure:

error: Could not compile `getopts`.
Build failed, waiting for other jobs to finish...
error: build failed
thread 'main' panicked at 'command did not execute successfully: "C:\\projects\\rust\\build\\x86_64-pc-windows-msvc\\stage0/bin\\cargo.exe" "build" "-j" "2" "--target" "x86_64-pc-windows-msvc" "--release" "--locked" "--manifest-path" "C:\\projects\\rust\\src/libtest/Cargo.toml" "--message-format" "json"
expected success, got: exit code: 101', src\bootstrap\compile.rs:547
note: Run with `RUST_BACKTRACE=1` for a backtrace.
failed to run: C:\projects\rust\build\bootstrap/debug/bootstrap dist

@Mark-Simulacrum Mark-Simulacrum added S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. and removed S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. labels May 28, 2017
@alexcrichton
Copy link
Member Author

Hm I got that once when working on this and brushed it off, I'll have to investigate again what's up

@alexcrichton alexcrichton force-pushed the fix-copies branch 2 times, most recently from 75755c7 to e925003 Compare May 28, 2017 17:40
@alexcrichton
Copy link
Member Author

@bors: r=Mark-Simulacrum

@bors
Copy link
Contributor

bors commented May 28, 2017

📌 Commit e925003 has been approved by Mark-Simulacrum

@bors
Copy link
Contributor

bors commented May 28, 2017

⌛ Testing commit e925003 with merge faa233c...

@bors
Copy link
Contributor

bors commented May 28, 2017

💔 Test failed - status-travis

@Mark-Simulacrum
Copy link
Member

@bors retry

Presumably spurious timeout; it's not entirely clear what happened though. Raw log is empty, but the actual build log does show results. https://travis-ci.org/rust-lang/rust/jobs/236953993

@bors
Copy link
Contributor

bors commented May 29, 2017

⌛ Testing commit e925003 with merge 8dcf95c...

@bors
Copy link
Contributor

bors commented May 29, 2017

💔 Test failed - status-travis

@Mark-Simulacrum
Copy link
Member

@bors retry

  • another timeout?

@bors
Copy link
Contributor

bors commented May 29, 2017

⌛ Testing commit e925003 with merge 7ca8f09...

@bors
Copy link
Contributor

bors commented May 29, 2017

💔 Test failed - status-travis

@kennytm
Copy link
Member

kennytm commented May 29, 2017

macOS timed out after 3 hours.

[02:54:39] Testing libstd stage2 (x86_64-apple-darwin -> x86_64-apple-darwin)
[02:54:48]    Compiling alloc v0.0.0 (file:///Users/travis/build/rust-lang/rust/src/liballoc)
[02:54:48]    Compiling rand v0.0.0 (file:///Users/travis/build/rust-lang/rust/src/librand)
[02:54:55]    Compiling core v0.0.0 (file:///Users/travis/build/rust-lang/rust/src/libcore)
[02:54:55]    Compiling collections v0.0.0 (file:///Users/travis/build/rust-lang/rust/src/libcollections)

The job exceeded the maximum time limit for jobs, and has been terminated.

@Mark-Simulacrum
Copy link
Member

Hm... well, seeing as other platforms are fine, I'm going to assume just macs being flaky as usual.

@bors retry

@bors
Copy link
Contributor

bors commented May 29, 2017

⌛ Testing commit e925003 with merge a67e171...

bors added a commit that referenced this pull request May 29, 2017
rustbuild: Fix copying duplicate crates into the sysroot

After compiling a project (e.g. libstd, libtest, or librustc) rustbuild needs to
copy over all artifacts into the sysroot of the compiler it's assembling.
Unfortunately rustbuild doesn't know precisely what files to copy! Today it has
a heuristic where it just looks at the most recent version of all files that
look like rlibs/dylibs and copies those over. This unfortunately leads to bugs
with different versions of the same craet as seen in #42261.

This commit updates rustbuild's strategy of copying artifacts to work off the
list of artifacts produced by `cargo build --message-format=json`. The build
system will now parse json messages coming out of Cargo to watch for files being
generated, and then it'll only copy over those precise files.

Note that there's still a bit of weird logic where Cargo prints that it's
creating `libstd.rlib` where we actually want `libstd-xxxxx.rlib`, so we still
do a bit of "most recent file" probing for those. This commit should take care
of the crates.io dependency issues, however, as they're all copied over
precisely.

Closes #42261
@bors
Copy link
Contributor

bors commented May 29, 2017

💔 Test failed - status-travis

@kennytm
Copy link
Member

kennytm commented May 29, 2017

Same issue... (3 out of 5 macOS jobs timed out after three hours)

@Mark-Simulacrum
Copy link
Member

@alexcrichton will investigate tomorrow. Not retrying until then.

@kennytm
Copy link
Member

kennytm commented May 29, 2017

Comparing time spent for Job 53342.36 "macOS x86_64 check" (timed out), with Job 53342.28 "Linux x86_64" (finished in ~1.5 hours).

Why is the compiler rebuilt five times on macOS?!

macOS Linux action
5m 56s 55s init_repo
3m 19s 1m 43s make prepare
1m 47s - make tidy
7m 39s 4m 30s build LLVM
1m 06s 53s build stage0-std
17s 14s build stage0-test
18m 21s 16m 15s build stage0-rustc
3m 22s 2m 04s build stage1-std
22s 24s build stage1-test
24m 11s 24m 55s build stage1-rustc
17m 53s - build stage0-rustc again, why? (line 5388)
1m 02s - build stage1-std again
19s - build stage1-test again
23m 28s - build stage1-rustc again
24m 07s - build stage1-rustc the third time (line 5628)
5m 42s 2m 35s test compile-fail
1m 23s 1m 02s test compile-fail-fulldeps
2m 41s 20s test debuginfo
6m 27s 3m 44s test doc tests
1m 40s 1m 00s test error index
49s 26s test incremental
2m 03s 1m 43s build tool rustbook
2m 04s 1m 06s test run-make
timed out 7m 55s test run-pass
... 3m 04s test run-pass-fulldeps

The last good build on auto branch 53337.36 (for 03bed65) also built rustc three times:

  • line 5216 (stage0)
  • line 5302 (stage1)
  • line 5366 (stage0) ← this one is abnormal
  • (the rest, lines 5431 (stage1), 5483 (stage0), 5499 (stage1) reused the built artifact so no time is spent)

@alexcrichton
Copy link
Member Author

Thanks for the analysis @kennytm! Definitely looks like a bug in the rebuilding logic.

After compiling a project (e.g. libstd, libtest, or librustc) rustbuild needs to
copy over all artifacts into the sysroot of the compiler it's assembling.
Unfortunately rustbuild doesn't know precisely what files to copy! Today it has
a heuristic where it just looks at the most recent version of all files that
look like rlibs/dylibs and copies those over. This unfortunately leads to bugs
with different versions of the same craet as seen in rust-lang#42261.

This commit updates rustbuild's strategy of copying artifacts to work off the
list of artifacts produced by `cargo build --message-format=json`. The build
system will now parse json messages coming out of Cargo to watch for files being
generated, and then it'll only copy over those precise files.

Note that there's still a bit of weird logic where Cargo prints that it's
creating `libstd.rlib` where we actually want `libstd-xxxxx.rlib`, so we still
do a bit of "most recent file" probing for those. This commit should take care
of the crates.io dependency issues, however, as they're all copied over
precisely.

Closes rust-lang#42261
@alexcrichton
Copy link
Member Author

@bors: r=Mark-Simulacrum

@bors
Copy link
Contributor

bors commented May 30, 2017

📌 Commit 2dab1e2 has been approved by Mark-Simulacrum

@bors
Copy link
Contributor

bors commented May 30, 2017

⌛ Testing commit 2dab1e2 with merge 42dc068...

@bors
Copy link
Contributor

bors commented May 31, 2017

💥 Test timed out

@kennytm
Copy link
Member

kennytm commented May 31, 2017

Actually it is running normally (I've checked that the stageN-rustc are built only twice, correctly). Bors created the commit at 2144Z (as seen on AppVeyor) but due to incident in Travis the build only started 9 hours after the merge (around 0600Z), and then bors canceled it at 0838Z.

@ishitatsuyuki
Copy link
Contributor

@alexcrichton as the test failed, mind amending the typo?

... This unfortunately leads to bugs
with different versions of the same craet as seen in ...

@Mark-Simulacrum
Copy link
Member

@bors retry

Travis incident, which I don't think is resolved yet, but let's populate the queue, doesn't hurt in this case - not fast at timing out.

@bors
Copy link
Contributor

bors commented May 31, 2017

⌛ Testing commit 2dab1e2 with merge 318f966...

@bors
Copy link
Contributor

bors commented May 31, 2017

💔 Test failed - status-travis

@Mark-Simulacrum
Copy link
Member

@alexcrichton Will investigate; this was a timeout.

@alexcrichton
Copy link
Member Author

@bors: retry

All logs have our builds finishing in under three hours, so I guess a travis bug?

@kennytm
Copy link
Member

kennytm commented Jun 1, 2017

The program is run twice simultaneously in the same job (e.g. https://travis-ci.org/rust-lang/rust/jobs/237985910), halving the build speed. It is strange the cancel happens 5 hours later, not the usual 3 hours. This has to be Travis bug because the symptom is right at the beginning of the log (worker info printed twice):

travis_fold:start:worker_info
�[0K�[33;1mWorker information�[0m
hostname: wjb-2:0a954c18-fd84-4399-8914-bab0daeb5fb2
version: v2.6.2 https://github.com/travis-ci/worker/tree/fdccca4efd347ebc889baae641ccbf55bb871d19
instance: 2809d28e-6c12-4639-9ac7-db81803d9a7a:travis-ci-macos10.12-xcode8.2-1490755335
startup: 2m13.835358169s
travis_fold:end:worker_info
�[0Ktravis_fold:start:worker_info
�[0K�[33;1mWorker information�[0m
hostname: wjb-1.macstadium-us-se-1.travisci.net:e5b4e58b-8c24-4e5a-b100-fe091b3b9f1f
version: v2.6.2 https://github.com/travis-ci/worker/tree/fdccca4efd347ebc889baae641ccbf55bb871d19
instance: 1a86efaf-69af-457c-ac70-3c08a88b3e6b:travis-ci-macos10.12-xcode8.2-1490755335
startup: 1m18.758866214s
travis_fold:end:worker_info
�[0Ktravis_fold:start:system_info
�[0K�[33;1mBuild system information�[0m

and we can see interleaving timestamps like

[00:10:32] [ 38%] Building CXX object lib/Transforms/IPO/CMakeFiles/LLVMipo.dir/InferFunctionAttrs.cpp.o
[00:11:18] [ 28%] Built target LLVMMIRParser
[00:11:18] Scanning dependencies of target LLVMGlobalISel
[00:11:18] [ 28%] Building CXX object lib/CodeGen/GlobalISel/CMakeFiles/LLVMGlobalISel.dir/GlobalISel.cpp.o
[00:11:18] [ 29%] Building CXX object lib/CodeGen/CMakeFiles/LLVMCodeGen.dir/ProcessImplicitDefs.cpp.o
[00:11:18] [ 29%] Linking CXX static library ../../libLLVMGlobalISel.a
[00:11:18] [ 29%] Built target LLVMGlobalISel
[00:10:32] [ 38%] Building CXX object lib/Transforms/Scalar/CMakeFiles/LLVMScalarOpts.dir/LICM.cpp.o
[00:10:32] [ 38%] Building CXX object lib/Transforms/IPO/CMakeFiles/LLVMipo.dir/InlineSimple.cpp.o
[00:10:33] [ 38%] Building CXX object lib/Transforms/Scalar/CMakeFiles/LLVMScalarOpts.dir/LoopAccessAnalysisPrinter.cpp.o
[00:10:33] [ 38%] Building CXX object lib/Transforms/IPO/CMakeFiles/LLVMipo.dir/Inliner.cpp.o
[00:11:18] [ 29%] Building CXX object lib/CodeGen/CMakeFiles/LLVMCodeGen.dir/PrologEpilogInserter.cpp.o
[00:11:19] [ 29%] Building CXX object lib/CodeGen/CMakeFiles/LLVMCodeGen.dir/PseudoSourceValue.cpp.o

The Travis Status Page is currently all-green, probably a retry could make it disappear.

@bors
Copy link
Contributor

bors commented Jun 1, 2017

⌛ Testing commit 2dab1e2 with merge afd4b81...

bors added a commit that referenced this pull request Jun 1, 2017
rustbuild: Fix copying duplicate crates into the sysroot

After compiling a project (e.g. libstd, libtest, or librustc) rustbuild needs to
copy over all artifacts into the sysroot of the compiler it's assembling.
Unfortunately rustbuild doesn't know precisely what files to copy! Today it has
a heuristic where it just looks at the most recent version of all files that
look like rlibs/dylibs and copies those over. This unfortunately leads to bugs
with different versions of the same crate as seen in #42261.

This commit updates rustbuild's strategy of copying artifacts to work off the
list of artifacts produced by `cargo build --message-format=json`. The build
system will now parse json messages coming out of Cargo to watch for files being
generated, and then it'll only copy over those precise files.

Note that there's still a bit of weird logic where Cargo prints that it's
creating `libstd.rlib` where we actually want `libstd-xxxxx.rlib`, so we still
do a bit of "most recent file" probing for those. This commit should take care
of the crates.io dependency issues, however, as they're all copied over
precisely.

Closes #42261
@bors
Copy link
Contributor

bors commented Jun 1, 2017

☀️ Test successful - status-appveyor, status-travis
Approved by: Mark-Simulacrum
Pushing afd4b81 to master...

@bors bors merged commit 2dab1e2 into rust-lang:master Jun 1, 2017
@alexcrichton alexcrichton deleted the fix-copies branch June 14, 2017 18:40
@ishitatsuyuki
Copy link
Contributor

While it's not actually rebuilt, rustbuild attempts to build everything 2-4 times, which generates logs that are extremely hard to read. I have confirmed this in at least all PR build, of course including this PR.

@alexcrichton is this an intended behavior?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants