From 26690d33e483ea83236413ea424d748251aa2696 Mon Sep 17 00:00:00 2001 From: Alex Crichton Date: Wed, 13 Apr 2016 23:37:57 -0700 Subject: [PATCH] Stream build script output to the console This commit alters Cargo's behavior when the `-vv` option is passed (two verbose flags) to stream output of all build scripts to the console. Cargo makes not attempt to prevent interleaving or indicate *which* build script is producing output, rather it simply forwards all output to one to the console. Cargo still acts as a middle-man, capturing the output, to parse build script output and interpret the results. The parsing is still deferred to completion but the stream output happens while the build script is running. On Unix this is implemented via `select` and on Windows this is implemented via IOCP. Closes #1106 --- Cargo.lock | 38 +++++ Cargo.toml | 1 + src/cargo/ops/cargo_rustc/custom_build.rs | 66 +++++++- src/cargo/ops/cargo_rustc/job.rs | 20 +-- src/cargo/ops/cargo_rustc/job_queue.rs | 98 +++++++---- src/cargo/ops/cargo_rustc/mod.rs | 8 +- src/cargo/util/errors.rs | 8 + src/cargo/util/mod.rs | 2 + src/cargo/util/read2.rs | 194 ++++++++++++++++++++++ tests/build-script.rs | 60 ++++++- 10 files changed, 442 insertions(+), 53 deletions(-) create mode 100644 src/cargo/util/read2.rs diff --git a/Cargo.lock b/Cargo.lock index b82576568df..7db2c69a6f8 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -21,6 +21,7 @@ dependencies = [ "libc 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", "libgit2-sys 0.4.3 (registry+https://github.com/rust-lang/crates.io-index)", "log 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)", + "miow 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", "num_cpus 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", "regex 0.1.58 (registry+https://github.com/rust-lang/crates.io-index)", "rustc-serialize 0.3.18 (registry+https://github.com/rust-lang/crates.io-index)", @@ -81,6 +82,11 @@ dependencies = [ "winapi 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "cfg-if" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "cmake" version = "0.1.16" @@ -317,6 +323,29 @@ dependencies = [ "libc 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "miow" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "kernel32-sys 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", + "net2 0.2.24 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "ws2_32-sys 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "net2" +version = "0.2.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "cfg-if 0.1.0 (registry+https://github.com/rust-lang/crates.io-index)", + "kernel32-sys 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", + "libc 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "ws2_32-sys 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "nom" version = "1.2.2" @@ -486,3 +515,12 @@ name = "winapi-build" version = "0.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "ws2_32-sys" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi-build 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + diff --git a/Cargo.toml b/Cargo.toml index 996bc04e143..3b0402079b6 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -33,6 +33,7 @@ glob = "0.2" kernel32-sys = "0.2" libc = "0.2" log = "0.3" +miow = "0.1" num_cpus = "0.2" regex = "0.1" rustc-serialize = "0.3" diff --git a/src/cargo/ops/cargo_rustc/custom_build.rs b/src/cargo/ops/cargo_rustc/custom_build.rs index 95df5a42b8a..8660a65ee7b 100644 --- a/src/cargo/ops/cargo_rustc/custom_build.rs +++ b/src/cargo/ops/cargo_rustc/custom_build.rs @@ -3,13 +3,16 @@ use std::fs; use std::path::{PathBuf, Path}; use std::str; use std::sync::{Mutex, Arc}; +use std::process::{Stdio, Output}; use core::PackageId; use util::{CargoResult, Human}; use util::{internal, ChainError, profile, paths}; -use util::Freshness; +use util::{Freshness, ProcessBuilder, read2}; +use util::errors::{process_error, ProcessError}; use super::job::Work; +use super::job_queue::JobState; use super::{fingerprint, Kind, Context, Unit}; use super::CommandType; @@ -159,14 +162,12 @@ fn build_work<'a, 'cfg>(cx: &mut Context<'a, 'cfg>, unit: &Unit<'a>) try!(fs::create_dir_all(&cx.layout(unit.pkg, Kind::Host).build(unit.pkg))); try!(fs::create_dir_all(&cx.layout(unit.pkg, unit.kind).build(unit.pkg))); - let exec_engine = cx.exec_engine.clone(); - // Prepare the unit of "dirty work" which will actually run the custom build // command. // // Note that this has to do some extra work just before running the command // to determine extra environment variables and such. - let dirty = Work::new(move |desc_tx| { + let dirty = Work::new(move |state| { // Make sure that OUT_DIR exists. // // If we have an old build directory, then just move it into place, @@ -203,8 +204,9 @@ fn build_work<'a, 'cfg>(cx: &mut Context<'a, 'cfg>, unit: &Unit<'a>) } // And now finally, run the build command itself! - desc_tx.send(p.to_string()).ok(); - let output = try!(exec_engine.exec_with_output(p).map_err(|mut e| { + state.running(&p); + let cmd = p.into_process_builder(); + let output = try!(stream_output(state, &cmd).map_err(|mut e| { e.desc = format!("failed to run custom build command for `{}`\n{}", pkg_name, e.desc); Human(e) @@ -438,3 +440,55 @@ pub fn build_map<'b, 'cfg>(cx: &mut Context<'b, 'cfg>, } } } + +fn stream_output(state: &JobState, cmd: &ProcessBuilder) + -> Result { + let mut stdout = Vec::new(); + let mut stderr = Vec::new(); + + let status = try!((|| { + let mut cmd = cmd.build_command(); + cmd.stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .stdin(Stdio::null()); + let mut child = try!(cmd.spawn()); + let out = child.stdout.take().unwrap(); + let err = child.stderr.take().unwrap(); + + try!(read2(out, err, &mut |is_out, data, eof| { + let idx = if eof { + data.len() + } else { + match data.iter().rposition(|b| *b == b'\n') { + Some(i) => i + 1, + None => return, + } + }; + let data = data.drain(..idx); + let dst = if is_out {&mut stdout} else {&mut stderr}; + let start = dst.len(); + dst.extend(data); + let s = String::from_utf8_lossy(&dst[start..]); + if is_out { + state.stdout(&s); + } else { + state.stderr(&s); + } + })); + child.wait() + })().map_err(|e| { + let msg = format!("could not exeute process {}", cmd); + process_error(&msg, Some(e), None, None) + })); + let output = Output { + stdout: stdout, + stderr: stderr, + status: status, + }; + if !output.status.success() { + let msg = format!("process didn't exit successfully: {}", cmd); + Err(process_error(&msg, None, Some(&status), Some(&output))) + } else { + Ok(output) + } +} diff --git a/src/cargo/ops/cargo_rustc/job.rs b/src/cargo/ops/cargo_rustc/job.rs index 0c270cfdf23..ae7ba303738 100644 --- a/src/cargo/ops/cargo_rustc/job.rs +++ b/src/cargo/ops/cargo_rustc/job.rs @@ -1,14 +1,14 @@ -use std::sync::mpsc::Sender; use std::fmt; use util::{CargoResult, Fresh, Dirty, Freshness}; +use super::job_queue::JobState; pub struct Job { dirty: Work, fresh: Work } /// Each proc should send its description before starting. /// It should send either once or close immediately. pub struct Work { - inner: Box, CargoResult<()>> + Send>, + inner: Box FnBox<&'a JobState<'b>, CargoResult<()>> + Send>, } trait FnBox { @@ -23,7 +23,7 @@ impl R> FnBox for F { impl Work { pub fn new(f: F) -> Work - where F: FnOnce(Sender) -> CargoResult<()> + Send + 'static + where F: FnOnce(&JobState) -> CargoResult<()> + Send + 'static { Work { inner: Box::new(f) } } @@ -32,14 +32,14 @@ impl Work { Work::new(|_| Ok(())) } - pub fn call(self, tx: Sender) -> CargoResult<()> { + pub fn call(self, tx: &JobState) -> CargoResult<()> { self.inner.call_box(tx) } pub fn then(self, next: Work) -> Work { - Work::new(move |tx| { - try!(self.call(tx.clone())); - next.call(tx) + Work::new(move |state| { + try!(self.call(state)); + next.call(state) }) } } @@ -52,10 +52,10 @@ impl Job { /// Consumes this job by running it, returning the result of the /// computation. - pub fn run(self, fresh: Freshness, tx: Sender) -> CargoResult<()> { + pub fn run(self, fresh: Freshness, state: &JobState) -> CargoResult<()> { match fresh { - Fresh => self.fresh.call(tx), - Dirty => self.dirty.call(tx), + Fresh => self.fresh.call(state), + Dirty => self.dirty.call(state), } } } diff --git a/src/cargo/ops/cargo_rustc/job_queue.rs b/src/cargo/ops/cargo_rustc/job_queue.rs index 4c855582d46..9179421903c 100644 --- a/src/cargo/ops/cargo_rustc/job_queue.rs +++ b/src/cargo/ops/cargo_rustc/job_queue.rs @@ -1,6 +1,7 @@ use std::collections::HashSet; use std::collections::hash_map::HashMap; use std::fmt; +use std::io::Write; use std::sync::mpsc::{channel, Sender, Receiver}; use crossbeam::{self, Scope}; @@ -12,6 +13,7 @@ use util::{CargoResult, profile, internal}; use super::{Context, Kind, Unit}; use super::job::Job; +use super::engine::CommandPrototype; /// A management structure of the entire dependency graph to compile. /// @@ -21,8 +23,8 @@ use super::job::Job; pub struct JobQueue<'a> { jobs: usize, queue: DependencyQueue, Vec<(Job, Freshness)>>, - tx: Sender>, - rx: Receiver>, + tx: Sender<(Key<'a>, Message)>, + rx: Receiver<(Key<'a>, Message)>, active: usize, pending: HashMap, PendingBuild>, compiled: HashSet<&'a PackageId>, @@ -47,9 +49,30 @@ struct Key<'a> { kind: Kind, } -struct Message<'a> { +pub struct JobState<'a> { + tx: Sender<(Key<'a>, Message)>, key: Key<'a>, - result: CargoResult<()>, +} + +enum Message { + Run(String), + Stdout(String), + Stderr(String), + Finish(CargoResult<()>), +} + +impl<'a> JobState<'a> { + pub fn running(&self, cmd: &CommandPrototype) { + let _ = self.tx.send((self.key, Message::Run(cmd.to_string()))); + } + + pub fn stdout(&self, out: &str) { + let _ = self.tx.send((self.key, Message::Stdout(out.to_string()))); + } + + pub fn stderr(&self, err: &str) { + let _ = self.tx.send((self.key, Message::Stderr(err.to_string()))); + } } impl<'a> JobQueue<'a> { @@ -107,8 +130,9 @@ impl<'a> JobQueue<'a> { // After a job has finished we update our internal state if it was // successful and otherwise wait for pending work to finish if it failed // and then immediately return. + let mut error = None; loop { - while self.active < self.jobs { + while error.is_none() && self.active < self.jobs { if !queue.is_empty() { let (key, job, fresh) = queue.remove(0); try!(self.run(key, fresh, job, cx.config, scope)); @@ -131,30 +155,46 @@ impl<'a> JobQueue<'a> { break } - // Now that all possible work has been scheduled, wait for a piece - // of work to finish. If any package fails to build then we stop - // scheduling work as quickly as possibly. - let msg = self.rx.recv().unwrap(); - info!("end: {:?}", msg.key); - self.active -= 1; - match msg.result { - Ok(()) => { - try!(self.finish(msg.key, cx)); + let (key, msg) = self.rx.recv().unwrap(); + + match msg { + Message::Run(cmd) => { + try!(cx.config.shell().verbose(|c| c.status("Running", &cmd))); + } + Message::Stdout(out) => { + if cx.config.extra_verbose() { + try!(write!(cx.config.shell().out(), "{}", out)); + } } - Err(e) => { - if self.active > 0 { - try!(cx.config.shell().say( - "Build failed, waiting for other \ - jobs to finish...", YELLOW)); - for _ in self.rx.iter().take(self.active as usize) {} + Message::Stderr(err) => { + if cx.config.extra_verbose() { + try!(write!(cx.config.shell().err(), "{}", err)); + } + } + Message::Finish(result) => { + info!("end: {:?}", key); + self.active -= 1; + match result { + Ok(()) => try!(self.finish(key, cx)), + Err(e) => { + if self.active > 0 { + try!(cx.config.shell().say( + "Build failed, waiting for other \ + jobs to finish...", YELLOW)); + } + if error.is_none() { + error = Some(e); + } + } } - return Err(e) } } } if self.queue.is_empty() { Ok(()) + } else if let Some(e) = error { + Err(e) } else { debug!("queue: {:#?}", self.queue); Err(internal("finished with jobs still left in the queue")) @@ -175,21 +215,17 @@ impl<'a> JobQueue<'a> { *self.counts.get_mut(key.pkg).unwrap() -= 1; let my_tx = self.tx.clone(); - let (desc_tx, desc_rx) = channel(); scope.spawn(move || { - my_tx.send(Message { + let res = job.run(fresh, &JobState { + tx: my_tx.clone(), key: key, - result: job.run(fresh, desc_tx), - }).unwrap(); + }); + my_tx.send((key, Message::Finish(res))).unwrap(); }); // Print out some nice progress information try!(self.note_working_on(config, &key, fresh)); - // only the first message of each job is processed - if let Ok(msg) = desc_rx.recv() { - try!(config.shell().verbose(|c| c.status("Running", &msg))); - } Ok(()) } @@ -219,7 +255,9 @@ impl<'a> JobQueue<'a> { // In general, we try to print "Compiling" for the first nontrivial task // run for a package, regardless of when that is. We then don't print // out any more information for a package after we've printed it once. - fn note_working_on(&mut self, config: &Config, key: &Key<'a>, + fn note_working_on(&mut self, + config: &Config, + key: &Key<'a>, fresh: Freshness) -> CargoResult<()> { if (self.compiled.contains(key.pkg) && !key.profile.doc) || (self.documented.contains(key.pkg) && key.profile.doc) { diff --git a/src/cargo/ops/cargo_rustc/mod.rs b/src/cargo/ops/cargo_rustc/mod.rs index 2919f07d0ac..6b07d8f413f 100644 --- a/src/cargo/ops/cargo_rustc/mod.rs +++ b/src/cargo/ops/cargo_rustc/mod.rs @@ -247,7 +247,7 @@ fn rustc(cx: &mut Context, unit: &Unit) -> CargoResult { let rustflags = try!(cx.rustflags_args(unit)); - return Ok(Work::new(move |desc_tx| { + return Ok(Work::new(move |state| { // Only at runtime have we discovered what the extra -L and -l // arguments are for native libraries, so we process those here. We // also need to be sure to add any -L paths for our plugins to the @@ -272,7 +272,7 @@ fn rustc(cx: &mut Context, unit: &Unit) -> CargoResult { // Add the arguments from RUSTFLAGS rustc.args(&rustflags); - desc_tx.send(rustc.to_string()).ok(); + state.running(&rustc); try!(exec_engine.exec(rustc).chain_error(|| { human(format!("Could not compile `{}`.", name)) })); @@ -410,13 +410,13 @@ fn rustdoc(cx: &mut Context, unit: &Unit) -> CargoResult { let key = (unit.pkg.package_id().clone(), unit.kind); let exec_engine = cx.exec_engine.clone(); - Ok(Work::new(move |desc_tx| { + Ok(Work::new(move |state| { if let Some(output) = build_state.outputs.lock().unwrap().get(&key) { for cfg in output.cfgs.iter() { rustdoc.arg("--cfg").arg(cfg); } } - desc_tx.send(rustdoc.to_string()).unwrap(); + state.running(&rustdoc); exec_engine.exec(rustdoc).chain_error(|| { human(format!("Could not document `{}`.", name)) }) diff --git a/src/cargo/util/errors.rs b/src/cargo/util/errors.rs index 3a84be560f6..8b41dd3e6ce 100644 --- a/src/cargo/util/errors.rs +++ b/src/cargo/util/errors.rs @@ -453,6 +453,10 @@ pub fn internal_error(error: &str, detail: &str) -> Box { } pub fn internal(error: S) -> Box { + _internal(&error) +} + +fn _internal(error: &fmt::Display) -> Box { Box::new(ConcreteCargoError { description: error.to_string(), detail: None, @@ -462,6 +466,10 @@ pub fn internal(error: S) -> Box { } pub fn human(error: S) -> Box { + _human(&error) +} + +fn _human(error: &fmt::Display) -> Box { Box::new(ConcreteCargoError { description: error.to_string(), detail: None, diff --git a/src/cargo/util/mod.rs b/src/cargo/util/mod.rs index d638691d774..3b18fb1e573 100644 --- a/src/cargo/util/mod.rs +++ b/src/cargo/util/mod.rs @@ -18,6 +18,7 @@ pub use self::sha256::Sha256; pub use self::to_semver::ToSemver; pub use self::to_url::ToUrl; pub use self::vcs::{GitRepo, HgRepo}; +pub use self::read2::read2; pub mod config; pub mod errors; @@ -41,3 +42,4 @@ mod shell_escape; mod vcs; mod lazy_cell; mod flock; +mod read2; diff --git a/src/cargo/util/read2.rs b/src/cargo/util/read2.rs new file mode 100644 index 00000000000..4596b260a13 --- /dev/null +++ b/src/cargo/util/read2.rs @@ -0,0 +1,194 @@ +pub use self::imp::read2; + +#[cfg(unix)] +mod imp { + use std::cmp; + use std::io::prelude::*; + use std::io; + use std::mem; + use std::os::unix::prelude::*; + use std::process::{ChildStdout, ChildStderr}; + use libc; + + pub fn read2(mut out_pipe: ChildStdout, + mut err_pipe: ChildStderr, + mut data: &mut FnMut(bool, &mut Vec, bool)) -> io::Result<()> { + unsafe { + libc::fcntl(out_pipe.as_raw_fd(), libc::F_SETFL, libc::O_NONBLOCK); + libc::fcntl(err_pipe.as_raw_fd(), libc::F_SETFL, libc::O_NONBLOCK); + } + + let mut out_done = false; + let mut err_done = false; + let mut out = Vec::new(); + let mut err = Vec::new(); + + let max = cmp::max(out_pipe.as_raw_fd(), err_pipe.as_raw_fd()); + loop { + // wait for either pipe to become readable using `select` + let r = unsafe { + let mut read: libc::fd_set = mem::zeroed(); + if !out_done { + libc::FD_SET(out_pipe.as_raw_fd(), &mut read); + } + if !err_done { + libc::FD_SET(err_pipe.as_raw_fd(), &mut read); + } + libc::select(max + 1, &mut read, 0 as *mut _, 0 as *mut _, + 0 as *mut _) + }; + if r == -1 { + let err = io::Error::last_os_error(); + if err.kind() == io::ErrorKind::Interrupted { + continue + } + return Err(err) + } + + // Read as much as we can from each pipe, ignoring EWOULDBLOCK or + // EAGAIN. If we hit EOF, then this will happen because the underlying + // reader will return Ok(0), in which case we'll see `Ok` ourselves. In + // this case we flip the other fd back into blocking mode and read + // whatever's leftover on that file descriptor. + let handle = |res: io::Result<_>| { + match res { + Ok(_) => Ok(true), + Err(e) => { + if e.kind() == io::ErrorKind::WouldBlock { + Ok(false) + } else { + Err(e) + } + } + } + }; + if !out_done && try!(handle(out_pipe.read_to_end(&mut out))) { + out_done = true; + } + data(true, &mut out, out_done); + if !err_done && try!(handle(err_pipe.read_to_end(&mut err))) { + err_done = true; + } + data(false, &mut err, err_done); + + if out_done && err_done { + return Ok(()) + } + } + } +} + +#[cfg(windows)] +mod imp { + extern crate miow; + extern crate winapi; + + use std::io; + use std::os::windows::prelude::*; + use std::process::{ChildStdout, ChildStderr}; + use std::slice; + + use self::miow::iocp::{CompletionPort, CompletionStatus}; + use self::miow::pipe::NamedPipe; + use self::miow::Overlapped; + use self::winapi::ERROR_BROKEN_PIPE; + + struct Pipe<'a> { + dst: &'a mut Vec, + overlapped: Overlapped, + pipe: NamedPipe, + done: bool, + } + + macro_rules! try { + ($e:expr) => (match $e { + Ok(e) => e, + Err(e) => { + println!("{} failed with {}", stringify!($e), e); + return Err(e) + } + }) + } + + pub fn read2(out_pipe: ChildStdout, + err_pipe: ChildStderr, + mut data: &mut FnMut(bool, &mut Vec, bool)) -> io::Result<()> { + let mut out = Vec::new(); + let mut err = Vec::new(); + + let port = try!(CompletionPort::new(1)); + try!(port.add_handle(0, &out_pipe)); + try!(port.add_handle(1, &err_pipe)); + + unsafe { + let mut out_pipe = Pipe::new(out_pipe, &mut out); + let mut err_pipe = Pipe::new(err_pipe, &mut err); + + try!(out_pipe.read()); + try!(err_pipe.read()); + + let mut status = [CompletionStatus::zero(), CompletionStatus::zero()]; + + while !out_pipe.done || !err_pipe.done { + for status in try!(port.get_many(&mut status, None)) { + if status.token() == 0 { + out_pipe.complete(status); + data(true, out_pipe.dst, out_pipe.done); + try!(out_pipe.read()); + } else { + err_pipe.complete(status); + data(false, err_pipe.dst, err_pipe.done); + try!(err_pipe.read()); + } + } + } + + Ok(()) + } + } + + impl<'a> Pipe<'a> { + unsafe fn new(p: P, dst: &'a mut Vec) -> Pipe<'a> { + Pipe { + dst: dst, + pipe: NamedPipe::from_raw_handle(p.into_raw_handle()), + overlapped: Overlapped::zero(), + done: false, + } + } + + unsafe fn read(&mut self) -> io::Result<()> { + let dst = slice_to_end(self.dst); + match self.pipe.read_overlapped(dst, &mut self.overlapped) { + Ok(_) => Ok(()), + Err(e) => { + if e.raw_os_error() == Some(ERROR_BROKEN_PIPE as i32) { + self.done = true; + Ok(()) + } else { + Err(e) + } + } + } + } + + unsafe fn complete(&mut self, status: &CompletionStatus) { + let prev = self.dst.len(); + self.dst.set_len(prev + status.bytes_transferred() as usize); + if status.bytes_transferred() == 0 { + self.done = true; + } + } + } + + unsafe fn slice_to_end(v: &mut Vec) -> &mut [u8] { + if v.capacity() == 0 { + v.reserve(16); + } + if v.capacity() == v.len() { + v.reserve(1); + } + slice::from_raw_parts_mut(v.as_mut_ptr().offset(v.len() as isize), + v.capacity() - v.len()) + } +} diff --git a/tests/build-script.rs b/tests/build-script.rs index f555c22a326..d0b947b823a 100644 --- a/tests/build-script.rs +++ b/tests/build-script.rs @@ -36,8 +36,7 @@ fn custom_build_script_failed() { [RUNNING] `rustc build.rs --crate-name build_script_build --crate-type bin [..]` [RUNNING] `[..]build-script-build[..]` [ERROR] failed to run custom build command for `foo v0.5.0 ({url})` -Process didn't exit successfully: `[..]build[..]build-script-build[..]` \ - (exit code: 101)", +process didn't exit successfully: `[..]build-script-build[..]` (exit code: 101)", url = p.url()))); } @@ -2042,8 +2041,12 @@ fn warnings_emitted() { assert_that(p.cargo_process("build").arg("-v"), execs().with_status(0) .with_stderr("\ +[COMPILING] foo v0.5.0 ([..]) +[RUNNING] `rustc [..]` +[RUNNING] `[..]` warning: foo warning: bar +[RUNNING] `rustc [..]` ")); } @@ -2080,7 +2083,16 @@ fn warnings_hidden_for_upstream() { assert_that(p.cargo_process("build").arg("-v"), execs().with_status(0) - .with_stderr("")); + .with_stderr("\ +[UPDATING] registry `[..]` +[DOWNLOADING] bar v0.1.0 ([..]) +[COMPILING] bar v0.1.0 ([..]) +[RUNNING] `rustc [..]` +[RUNNING] `[..]` +[RUNNING] `rustc [..]` +[COMPILING] foo v0.5.0 ([..]) +[RUNNING] `rustc [..]` +")); } #[test] @@ -2117,7 +2129,49 @@ fn warnings_printed_on_vv() { assert_that(p.cargo_process("build").arg("-vv"), execs().with_status(0) .with_stderr("\ +[UPDATING] registry `[..]` +[DOWNLOADING] bar v0.1.0 ([..]) +[COMPILING] bar v0.1.0 ([..]) +[RUNNING] `rustc [..]` +[RUNNING] `[..]` warning: foo warning: bar +[RUNNING] `rustc [..]` +[COMPILING] foo v0.5.0 ([..]) +[RUNNING] `rustc [..]` +")); +} + +#[test] +fn output_shows_on_vv() { + let p = project("foo") + .file("Cargo.toml", r#" + [project] + name = "foo" + version = "0.5.0" + authors = [] + build = "build.rs" + "#) + .file("src/lib.rs", "") + .file("build.rs", r#" + use std::io::prelude::*; + + fn main() { + std::io::stderr().write_all(b"stderr\n").unwrap(); + std::io::stdout().write_all(b"stdout\n").unwrap(); + } + "#); + + assert_that(p.cargo_process("build").arg("-vv"), + execs().with_status(0) + .with_stdout("\ +stdout +") + .with_stderr("\ +[COMPILING] foo v0.5.0 ([..]) +[RUNNING] `rustc [..]` +[RUNNING] `[..]` +stderr +[RUNNING] `rustc [..]` ")); }