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

In JSON output, emit a directive after metadata is generated. #60006

Merged
merged 3 commits into from
Apr 30, 2019

Conversation

nnethercote
Copy link
Contributor

@nnethercote nnethercote commented Apr 16, 2019

To implement pipelining, Cargo needs to know when metadata generation is
finished. This is done via a new JSON "directive".

Unfortunately, metadata file writing currently occurs very late during
compilation, so pipelining won't produce a speed-up. Moving metadata
file writing earlier will be a follow-up.

r? @alexcrichton

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Apr 16, 2019
@nnethercote
Copy link
Contributor Author

@michaelwoerister You might be interested in this too.

src/libsyntax/json.rs Outdated Show resolved Hide resolved
Copy link
Member

@alexcrichton alexcrichton left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So I started writing a bunch of comments about the scheduling and costs and whatnot, but then I remembered that metadata files aren't object files! When rustc is producing the dylib crate type (not cdylib, "dylib") it is actually an object file which gets linked in. For --emit metadata, however, the contents don't get threaded through LLVM.

Instead the contents of foo.rmeta are available immediately after tcx.encode_metadata(), called from here (wow we have some confusing naming, nothing is written there). That metadata object returned is the raw bytes of metadata, and is threaded through all the way to the linking phase where we finally emit it to the filesystem here.

I think that we may want to move that emit_metadata function much earlier into the compilation process? Basically just after the call to write_metadata I think we can write out the rmeta file (if necessary) and not have to touch the LLVM scheduler at all.

In theory the call to encode_metadata() could be moved arbitrarily sooner in the compilation process as well and then the final metadata value is just encoded through to where we optionally create an object file for dylib crate types.

src/librustc_errors/emitter.rs Outdated Show resolved Hide resolved
src/librustc_errors/emitter.rs Outdated Show resolved Hide resolved
src/librustc_errors/emitter.rs Outdated Show resolved Hide resolved
// I couldn't find where the file writing occurs.
if let WorkItem::Optimize(
ModuleCodegen { name, kind: ModuleKind::Metadata, .. }) = &llvm_work_item {
cgcx.diag_emitter.emit_directive(format!("metadata done for {}", name));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should emit a message for all artifacts, with a path to the artifact, and let Cargo pick out what it cares out of that.
Something like sccache, for example, might care more about other files.
And it's less tied to pipelining, just another general thing rustc does.

@bors
Copy link
Contributor

bors commented Apr 17, 2019

☔ The latest upstream changes (presumably #60030) made this pull request unmergeable. Please resolve the merge conflicts.

@nnethercote
Copy link
Contributor Author

Instead the contents of foo.rmeta are available immediately after tcx.encode_metadata(), called from here (wow we have some confusing naming, nothing is written there). That metadata object returned is the raw bytes of metadata, and is threaded through all the way to the linking phase where we finally emit it to the filesystem here.

I had a suspicion this might be true, thanks for clarifying!

My next question is this: what is the metadata stuff that is happening during codegen? E.g. what are this and this for?

@alexcrichton
Copy link
Member

what is this

That... is a really good question! I think that may actually be legitimately dead code that can be deleted. AFAIK that just generates an empty object file which is always deleted. If a test starts failing though I could probably rationalize from the test why we need it :)

what is this

Ah so that's actually needed for the dylib crate type. For anything that doesn't produce a dylib I think it's dead code. If we're producing a dylib we compress the rmeta file, shove it into a section in the LLVM module, and then link it into the dylib itself. If we're not producing a dylib I think that's an empty LLVM module which produces an empty object file which we end up just deleting (it'd only get passed to the linker for a dylib anyway).

So... I think in general those two blocks are largely dead code and/or historical artifacts! As I'm sure you've noticed, the backend here, especially the parallel part, could use with some cleanup at some point (ideally with all the new parallel query infrastructure!)

@nnethercote
Copy link
Contributor Author

@alexcrichton: I tried removing the ongoing_codegen.submit_pre_codegened_module_to_llvm(tcx, metadata_module) line here and I got lots of panics here.

@alexcrichton
Copy link
Member

Heh that'd make sense :)

I suspect though that .expect() should be removed and we could basically thread through a None to whatever eventually expects that module to exist. (it should be Some for dylib crate types, but None for all others)

Centril added a commit to Centril/rust that referenced this pull request Apr 24, 2019
Centril added a commit to Centril/rust that referenced this pull request Apr 24, 2019
@nnethercote
Copy link
Contributor Author

I think that we may want to move that emit_metadata function much earlier into the compilation process? Basically just after the call to write_metadata I think we can write out the rmeta file (if necessary) and not have to touch the LLVM scheduler at all.

AIUI, metadata generation happens at the start of code generation, which happens under Compiler::ongoing_codegen. And then metadata writing occurs under Compiler::link. So I want to introduce a third method, Compiler::generate_and_write_metadata that does both metadata generation and writing, and run that before Compiler::ongoing_codegen.

Does that sound right? The complication is that there's a fair amount of complicated code under those methods, and disentangling the metadata parts is difficult.

@nnethercote
Copy link
Contributor Author

@alexcrichton: New draft code is up. It still has some eprintln and "njn:" comments, but otherwise should be reasonable. It emits the JSON directive in the correct place now, but has not moved metadata file writing earlier. It might be better to do that in a follow-up PR, because it'll be fiddly. Landing this sooner will let you test the Cargo side.

@nnethercote
Copy link
Contributor Author

I still have to get the tests working, too. I am currently battling through tools/compiletest/src/json.rs to make it accept diagnostics and directives.

src/librustc_codegen_ssa/back/link.rs Outdated Show resolved Hide resolved
src/librustc/session/mod.rs Show resolved Hide resolved
src/libsyntax/json.rs Show resolved Hide resolved
Copy link
Member

@alexcrichton alexcrichton left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does that sound right? The complication is that there's a fair amount of complicated code under those methods, and disentangling the metadata parts is difficult.

This sounds about right yeah, but I think that a better fix might be to decouple metadata generation from all this back-end-related code. For example the dep-info output type has a check at some point (very early on) of "if enabled do it right now and maybe exit afterwards". I suspect a similar check would suffice for metadata in the sense that the only thing necessary for generating metadata contents is tcx, and after that it looks like tcx.encode_metadata() is all that's necessary.

I suspect we may even be able to practically sequence this just after tcx creation for maximal parallelism. Something like just before this line or around there (maybe inside analysis? unsure) would be fine.

In any case, separation out and detangling from everything else going on in the linking phase is probably the best bet to sequence this earlier. And this can of course always happen later, no need to finish it in this PR!

It might be better to do that in a follow-up PR, because it'll be fiddly. Landing this sooner will let you test the Cargo side.

Sounds fine by me! I'm up for whatever you find most convenient :)

src/librustc_codegen_ssa/back/link.rs Outdated Show resolved Hide resolved
@nnethercote
Copy link
Contributor Author

@alexcrichton: new code is up. It's now in a state that could be acceptable for landing: tests pass, and there are no eprintln! statements or "njn:" comments left. Things still to consider:

  • Does this need marking as unstable in some way, as @bjorn3 suggests?
  • Should there be tests for this? I'm not sure what they'd look like.

@alexcrichton
Copy link
Member

This currently unconditionally emits the directive, I think? I think we'll probably still want to have it off by default (something required to opt-in on the CLI), and I agree that for now it's probably best to put it behind -Z unstable-options.

To that end I'd recommend adding a new unstable flag --emit-directives or something like that which, as unstable, would require -Z unstable-options. You could also add something like -Z emit-directives and that'd also be fine and would require unstable.

@alexcrichton
Copy link
Member

Oh and for a test I think actually src/test/ui might work well? That way we'd have a sample output as well as an assertion about what the output should be. Just a simple smoke test for this I think should suffice.

@nnethercote
Copy link
Contributor Author

@alexcrichton: I added -Z emit-directives and a ui test. Both steps were easier than I expected, which is nice.

Copy link
Member

@alexcrichton alexcrichton left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a few questions about the test, but otherwise r=me when you're comfortable they've been answered!

src/test/ui/emit-directives.rs Show resolved Hide resolved
src/test/ui/emit-directives.stderr Outdated Show resolved Hide resolved
@nnethercote
Copy link
Contributor Author

I switched to using output normalization to account for the path and filename differences on different platforms. Let's try again...

@bors r=alexcrichton

@bors
Copy link
Contributor

bors commented Apr 29, 2019

📌 Commit f96c96414aef2d57107096f8055236af0c9839ba has been approved by alexcrichton

@bors bors 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 Apr 29, 2019
@bors
Copy link
Contributor

bors commented Apr 29, 2019

⌛ Testing commit f96c96414aef2d57107096f8055236af0c9839ba with merge e407efcd2f5bdbf225485e0913dc99cfdedab64b...

@bors
Copy link
Contributor

bors commented Apr 29, 2019

💔 Test failed - checks-travis

@bors bors added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. and removed S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. labels Apr 29, 2019
@rust-highfive
Copy link
Collaborator

The job x86_64-gnu-nopt of your PR failed on Travis (raw log). Through arcane magic we have determined that the following fragments from the build log may contain information about the problem.

Click to expand the log.
[01:34:54] 
[01:34:54] ---- [ui (nll)] ui/emit-directives.rs stdout ----
[01:34:54] diff of stderr:
[01:34:54] 
[01:34:54] - {"directive":"metadata file written: .../emit-directives/a"}
[01:34:54] + {"directive":"metadata file written: .../emit-directives.nll/a"}
[01:34:54] 
[01:34:54] 
[01:34:54] The actual stderr differed from the expected stderr.
[01:34:54] The actual stderr differed from the expected stderr.
[01:34:54] Actual stderr saved to /checkout/obj/build/x86_64-unknown-linux-gnu/test/ui/emit-directives.nll/emit-directives.nll.stderr
[01:34:54] To update references, rerun the tests and pass the `--bless` flag
[01:34:54] To only update this specific test, also pass `--test-args emit-directives.rs`
[01:34:54] error: 1 errors occurred comparing output.
[01:34:54] status: exit code: 0
[01:34:54] status: exit code: 0
[01:34:54] command: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/rustc" "/checkout/src/test/ui/emit-directives.rs" "-Zthreads=1" "--target=x86_64-unknown-linux-gnu" "-Zui-testing" "-C" "prefer-dynamic" "-o" "/checkout/obj/build/x86_64-unknown-linux-gnu/test/ui/emit-directives.nll/a" "-Zborrowck=migrate" "-Crpath" "-Zunstable-options" "-Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--emit=metadata" "--error-format=json" "-Z" "emit-directives" "-L" "/checkout/obj/build/x86_64-unknown-linux-gnu/test/ui/emit-directives.nll/auxiliary" "-A" "unused"
[01:34:54] ------------------------------------------
[01:34:54] 
[01:34:54] ------------------------------------------
[01:34:54] stderr:
---
[01:34:54] thread 'main' panicked at 'Some tests failed', src/tools/compiletest/src/main.rs:517:22
[01:34:54] note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
[01:34:54] 
[01:34:54] 
[01:34:54] command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-tools-bin/compiletest" "--compile-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib" "--run-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/x86_64-unknown-linux-gnu/lib" "--rustc-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/rustc" "--src-base" "/checkout/src/test/ui" "--build-base" "/checkout/obj/build/x86_64-unknown-linux-gnu/test/ui" "--stage-id" "stage2-x86_64-unknown-linux-gnu" "--mode" "ui" "--target" "x86_64-unknown-linux-gnu" "--host" "x86_64-unknown-linux-gnu" "--llvm-filecheck" "/checkout/obj/build/x86_64-unknown-linux-gnu/llvm/build/bin/FileCheck" "--host-rustcflags" "-Crpath -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--target-rustcflags" "-Crpath -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--docck-python" "/usr/bin/python2.7" "--lldb-python" "/usr/bin/python2.7" "--gdb" "/usr/bin/gdb" "--llvm-version" "8.0.0-rust-1.36.0-dev\n" "--cc" "" "--cxx" "" "--cflags" "" "--llvm-components" "" "--llvm-cxxflags" "" "--adb-path" "adb" "--adb-test-dir" "/data/tmp/work" "--android-cross-path" "" "--color" "always" "--compare-mode" "nll"
[01:34:54] 
[01:34:54] 
[01:34:54] failed to run: /checkout/obj/build/bootstrap/debug/bootstrap test
[01:34:54] Build completed unsuccessfully in 0:08:58
[01:34:54] Build completed unsuccessfully in 0:08:58
[01:34:54] make: *** [check] Error 1
[01:34:54] Makefile:48: recipe for target 'check' failed
The command "stamp sh -x -c "$RUN_SCRIPT"" exited with 2.
travis_time:start:075a1b26
$ date && (curl -fs --head https://google.com | grep ^Date: | sed 's/Date: //g' || true)
Mon Apr 29 09:47:17 UTC 2019
---
travis_time:end:02a6da16:start=1556531239736401888,finish=1556531239743397335,duration=6995447
travis_fold:end:after_failure.3
travis_fold:start:after_failure.4
travis_time:start:001c8519
$ ln -s . checkout && for CORE in obj/cores/core.*; do EXE=$(echo $CORE | sed 's|obj/cores/core\.[0-9]*\.!checkout!\(.*\)|\1|;y|!|/|'); if [ -f "$EXE" ]; then printf travis_fold":start:crashlog\n\033[31;1m%s\033[0m\n" "$CORE"; gdb --batch -q -c "$CORE" "$EXE" -iex 'set auto-load off' -iex 'dir src/' -iex 'set sysroot .' -ex bt -ex q; echo travis_fold":"end:crashlog; fi; done || true
travis_fold:end:after_failure.4
travis_fold:start:after_failure.5
travis_time:start:121fe424
travis_time:start:121fe424
$ cat ./obj/build/x86_64-unknown-linux-gnu/native/asan/build/lib/asan/clang_rt.asan-dynamic-i386.vers || true
cat: ./obj/build/x86_64-unknown-linux-gnu/native/asan/build/lib/asan/clang_rt.asan-dynamic-i386.vers: No such file or directory
travis_fold:end:after_failure.5
travis_fold:start:after_failure.6
travis_time:start:0a30b332
$ dmesg | grep -i kill

I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact @TimNN. (Feature Requests)

To implement pipelining, Cargo needs to know when metadata generation is
finished. This commit adds code to do that. Unfortunately, metadata file
writing currently occurs very late during compilation, so pipelining
won't produce a speed-up. Moving metadata file writing earlier will be a
follow-up.

The change involves splitting the existing `Emitter::emit` method in
two: `Emitter::emit_diagnostic` and `Emitter::emit_directive`.

The JSON directives look like this:
```
{"directive":"metadata file written: liba.rmeta"}
```
The functionality is behind the `-Z emit-directives` option, and also
requires `--error-format=json`.
@nnethercote
Copy link
Contributor Author

Once more with feeling!

@bors r=alexcrichton

@bors
Copy link
Contributor

bors commented Apr 29, 2019

📌 Commit 7bcb0cf has been approved by alexcrichton

@bors bors 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 Apr 29, 2019
bors added a commit that referenced this pull request Apr 29, 2019
In JSON output, emit a directive after metadata is generated.

To implement pipelining, Cargo needs to know when metadata generation is
finished. This is done via a new JSON "directive".

Unfortunately, metadata file writing currently occurs very late during
compilation, so pipelining won't produce a speed-up. Moving metadata
file writing earlier will be a follow-up.

r? @alexcrichton
@bors
Copy link
Contributor

bors commented Apr 29, 2019

⌛ Testing commit 7bcb0cf with merge 03122e1...

@bors
Copy link
Contributor

bors commented Apr 30, 2019

☀️ Test successful - checks-travis, status-appveyor
Approved by: alexcrichton
Pushing 03122e1 to master...

@bors bors added the merged-by-bors This PR was explicitly merged by bors. label Apr 30, 2019
@bors bors merged commit 7bcb0cf into rust-lang:master Apr 30, 2019
@nnethercote nnethercote deleted the json-for-pipelining branch April 30, 2019 03:03
bors added a commit that referenced this pull request May 7, 2019
…ichton

rustc: rename -Z emit-directives to -Z emit-artifact-notifications and simplify the output.

This is my take on #60006 / #60419 (see #60006 (comment)).
I'm not too attached the "notifications" part, it's pretty much bikeshed material.
**EDIT**: for "artifact", @matklad pointed out Cargo already uses it (in #60464 (comment))

The first two commits are fixes that could be landed independently, especially the `compiletest` one, which removes the need for any of the normalization added in #60006 to land the test.

The last commit enables the emission for all outputs, which was my main suggestion for #60006, mostly to show that it's minimal and not really a "scope creep" (as suggested in #60006 (comment)).

cc @alexcrichton @nnethercote
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
merged-by-bors This PR was explicitly merged by bors. S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants