Skip to content

Avoid collecting extraneous stuff on eprintln runs. #726

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.

Sign up for GitHub

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

Merged
merged 1 commit into from
Jul 27, 2020
Merged

Avoid collecting extraneous stuff on eprintln runs. #726

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 4 additions & 3 deletions ci/check-profiling.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -76,16 +76,17 @@ RUST_BACKTRACE=1 RUST_LOG=raw_cargo_messages=trace,collector=debug,rust_sysroot=
test -f results/msout-Test-helloworld-Check-Full
grep -q "snapshot=0" results/msout-Test-helloworld-Check-Full

# eprintln.
# eprintln. The output file is empty because a vanilla rustc doesn't print
# anything to stderr.
RUST_BACKTRACE=1 RUST_LOG=raw_cargo_messages=trace,collector=debug,rust_sysroot=debug \
cargo run -p collector --bin collector -- \
profile_local eprintln $bindir/rustc Test \
--builds Check \
--cargo $bindir/cargo \
--include helloworld \
--runs Full
test -f results/eprintln-Test-helloworld-Check-Full
grep -q "Checking helloworld" results/eprintln-Test-helloworld-Check-Full
test -f results/eprintln-Test-helloworld-Check-Full
test ! -s results/eprintln-Test-helloworld-Check-Full

# llvm-lines. `Debug` not `Check` because it doesn't support `Check` builds.
RUST_BACKTRACE=1 RUST_LOG=raw_cargo_messages=trace,collector=debug,rust_sysroot=debug \
Expand Down
44 changes: 21 additions & 23 deletions collector/src/execute.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -661,7 +661,7 @@ impl<'a> Processor for ProfileProcessor<'a> {
}

// -Zself-profile produces (via rustc-fake) a data directory called
// 'Zsp' containing three files with names of the form
// `Zsp` containing three files with names of the form
// `$BENCHMARK-$PID.{events,string_data,string_index}`. We copy it
// from the temp dir to the output dir, renaming the files within
// as `Zsp.{events,string_data,string_index}` in the process, then
Expand Down Expand Up @@ -703,8 +703,7 @@ impl<'a> Processor for ProfileProcessor<'a> {
// Run `summarize`.
let mut summarize_cmd = Command::new("summarize");
summarize_cmd.arg("summarize").arg(&zsp_files_prefix);
let output = summarize_cmd.output()?;
fs::write(&summarize_file, &output.stdout)?;
fs::write(&summarize_file, &summarize_cmd.output()?.stdout)?;

// Run `flamegraph`.
let mut flamegraph_cmd = Command::new("flamegraph");
Expand All @@ -719,15 +718,16 @@ impl<'a> Processor for ProfileProcessor<'a> {
fs::rename("chrome_profiler.json", crox_file)?;
}

// -Ztime-passes writes its output to stdout. We copy that output
// into a file in the output dir.
// `-Ztime-passes` output is redirected (via rustc-fake) to a file
// called `Ztp`. We copy that output into a file in the output dir.
Profiler::TimePasses => {
let tmp_ztp_file = filepath(data.cwd.as_ref(), "Ztp");
let ztp_file = filepath(self.output_dir, &out_file("Ztp"));

fs::write(ztp_file, &output.stdout)?;
fs::copy(&tmp_ztp_file, &ztp_file)?;
}

// perf-record produces (via rustc-fake) a data file called 'perf'.
// perf-record produces (via rustc-fake) a data file called `perf`.
// We copy it from the temp dir to the output dir, giving it a new
// name in the process.
Profiler::PerfRecord => {
Expand All @@ -738,7 +738,7 @@ impl<'a> Processor for ProfileProcessor<'a> {
}

// OProfile produces (via rustc-fake) a data directory called
// 'oprofile_data'. We copy it from the temp dir to the output dir,
// `oprofile_data`. We copy it from the temp dir to the output dir,
// giving it a new name in the process, and then post-process it
// twice to produce another two data files in the output dir.
Profiler::OProfile => {
Expand All @@ -765,8 +765,7 @@ impl<'a> Processor for ProfileProcessor<'a> {
.arg("--threshold")
.arg("0.5")
.arg(&session_dir_arg);
let output = op_report_cmd.output()?;
fs::write(oprep_file, &output.stdout)?;
fs::write(oprep_file, &op_report_cmd.output()?.stdout)?;

let mut op_annotate_cmd = Command::new("opannotate");
// Other possibly useful args: --assembly
Expand All @@ -775,11 +774,10 @@ impl<'a> Processor for ProfileProcessor<'a> {
.arg("--threshold")
.arg("0.5")
.arg(&session_dir_arg);
let output = op_annotate_cmd.output()?;
fs::write(opann_file, &output.stdout)?;
fs::write(opann_file, &op_annotate_cmd.output()?.stdout)?;
}

// Cachegrind produces (via rustc-fake) a data file called 'cgout'.
// Cachegrind produces (via rustc-fake) a data file called `cgout`.
// We copy it from the temp dir to the output dir, giving it a new
// name in the process, and then post-process it to produce another
// data file in the output dir.
Expand All @@ -795,11 +793,10 @@ impl<'a> Processor for ProfileProcessor<'a> {
.arg("--auto=yes")
.arg("--show-percs=yes")
.arg(&cgout_file);
let output = cg_annotate_cmd.output()?;
fs::write(cgann_file, &output.stdout)?;
fs::write(cgann_file, &cg_annotate_cmd.output()?.stdout)?;
}

// Callgrind produces (via rustc-fake) a data file called 'clgout'.
// Callgrind produces (via rustc-fake) a data file called `clgout`.
// We copy it from the temp dir to the output dir, giving it a new
// name in the process, and then post-process it to produce another
// data file in the output dir.
Expand All @@ -815,11 +812,10 @@ impl<'a> Processor for ProfileProcessor<'a> {
.arg("--auto=yes")
.arg("--show-percs=yes")
.arg(&clgout_file);
let output = clg_annotate_cmd.output()?;
fs::write(clgann_file, &output.stdout)?;
fs::write(clgann_file, &clg_annotate_cmd.output()?.stdout)?;
}

// DHAT produces (via rustc-fake) a data file called 'dhout'. We
// DHAT produces (via rustc-fake) a data file called `dhout`. We
// copy it from the temp dir to the output dir, giving it a new
// name in the process.
Profiler::DHAT => {
Expand All @@ -829,7 +825,7 @@ impl<'a> Processor for ProfileProcessor<'a> {
fs::copy(&tmp_dhout_file, &dhout_file)?;
}

// Massif produces (via rustc-fake) a data file called 'msout'. We
// Massif produces (via rustc-fake) a data file called `msout`. We
// copy it from the temp dir to the output dir, giving it a new
// name in the process.
Profiler::Massif => {
Expand All @@ -839,12 +835,14 @@ impl<'a> Processor for ProfileProcessor<'a> {
fs::copy(&tmp_msout_file, &msout_file)?;
}

// `eprintln!` statements writes their output to stderr. We copy
// that output into a file in the output dir.
// `eprintln!` statements are redirected (via rustc-fake) to a file
// called `eprintln`. We copy it from the temp dir to the output
// dir, giving it a new name in the process.
Profiler::Eprintln => {
let tmp_eprintln_file = filepath(data.cwd.as_ref(), "eprintln");
let eprintln_file = filepath(self.output_dir, &out_file("eprintln"));

fs::write(eprintln_file, &output.stderr)?;
fs::copy(&tmp_eprintln_file, &eprintln_file)?;
}

// `cargo llvm-lines` writes its output to stdout. We copy that
Expand Down
53 changes: 43 additions & 10 deletions collector/src/rustc-fake.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,6 @@
use std::env;
use std::ffi::OsString;
use std::fs;
use std::path::Path;
use std::process::Command;
use std::time::{Duration, Instant};
Expand All @@ -21,11 +23,11 @@ fn main() {
.ok()
.and_then(|v| v.parse::<u32>().ok())
{
args.push(std::ffi::OsString::from(format!("-Zthreads={}", count)));
args.push(OsString::from(format!("-Zthreads={}", count)));
}

args.push(std::ffi::OsString::from("-Adeprecated"));
args.push(std::ffi::OsString::from("-Aunknown-lints"));
args.push(OsString::from("-Adeprecated"));
args.push(OsString::from("-Aunknown-lints"));

if let Some(pos) = args.iter().position(|arg| arg == "--wrap-rustc-with") {
// Strip out the flag and its argument, and run rustc under the wrapper
Expand Down Expand Up @@ -56,8 +58,8 @@ fn main() {
"-Zself-profile={}",
prof_out_dir.to_str().unwrap()
));
let _ = std::fs::remove_dir_all(&prof_out_dir);
let _ = std::fs::create_dir_all(&prof_out_dir);
let _ = fs::remove_dir_all(&prof_out_dir);
let _ = fs::create_dir_all(&prof_out_dir);
}

let start = Instant::now();
Expand All @@ -75,7 +77,7 @@ fn main() {
let mut prefix = None;
// We don't know the pid of rustc, and can't easily get it -- we only know the
// `perf` pid. So just blindly look in the directory to hopefully find it.
for entry in std::fs::read_dir(&prof_out_dir).unwrap() {
for entry in fs::read_dir(&prof_out_dir).unwrap() {
let entry = entry.unwrap();
if entry
.file_name()
Expand Down Expand Up @@ -109,8 +111,8 @@ fn main() {
}

"time-passes" => {
let mut cmd = Command::new(&tool);
cmd.arg("-Ztime-passes").args(&args);
args.insert(0, "-Ztime-passes".into());
let mut cmd = bash_command(tool, args, "> Ztp");

assert!(cmd.status().expect("failed to spawn").success());
}
Expand Down Expand Up @@ -203,7 +205,20 @@ fn main() {
assert!(cmd.status().expect("failed to spawn").success());
}

"eprintln" | "llvm-lines" => {
"eprintln" => {
let mut cmd = bash_command(tool, args, "2> eprintln");

assert!(cmd.status().expect("failed to spawn").success());
}

"llvm-lines" => {
// `cargo llvm-lines` writes its output to stdout. But we can't
// redirect it to a file here like we do for "time-passes" and
// "eprintln". This is because `cargo llvm-lines` invokes rustc
// as part of its processing and then it does some analysis of
// its output and then it prints out some results. Because
// `rustc` (which this file wraps) doesn't produce the output,
// this file can't redirect that output.
let mut cmd = Command::new(&tool);
cmd.args(&args);

Expand All @@ -227,6 +242,24 @@ fn main() {
}
}

/// Run a command via bash, in order to redirect its output to a file.
/// `redirect` should be something like "> out" or "2> out".
fn bash_command(tool: OsString, args: Vec<OsString>, redirect: &str) -> Command {
let mut bash_cmd = String::new();
bash_cmd.push_str(&format!("{} ", tool.to_str().unwrap()));
for arg in args {
// Args with double quotes (e.g. `--cfg feature="foo"`)
// will be munged by bash if we don't protect them. So we
// wrap every arg in single quotes.
bash_cmd.push_str(&format!("'{}' ", arg.to_str().unwrap()));
}
bash_cmd.push_str(redirect);

let mut cmd = Command::new("bash");
cmd.args(&["-c", &bash_cmd]);
cmd
}

#[cfg(unix)]
fn exec(cmd: &mut Command) -> ! {
use std::os::unix::prelude::*;
Expand Down Expand Up @@ -289,7 +322,7 @@ fn run_summarize(name: &str, prof_out_dir: &Path, prefix: &str) -> std::io::Resu
"Failed to run successfully",
));
}
std::fs::read_to_string(prof_out_dir.join(&format!("{}.json", prefix)))
fs::read_to_string(prof_out_dir.join(&format!("{}.json", prefix)))
}

#[cfg(windows)]
Expand Down