diff --git a/Cargo.toml b/Cargo.toml index 147b38e55..51e5c8b4c 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,6 +18,7 @@ path = "src/cargo/lib.rs" [dependencies] atty = "0.2" +bytesize = "1.0" crates-io = { path = "src/crates-io", version = "0.20" } crossbeam-utils = "0.5" crypto-hash = "0.3.1" diff --git a/src/cargo/core/compiler/job_queue.rs b/src/cargo/core/compiler/job_queue.rs index c2681c892..1323e393c 100644 --- a/src/cargo/core/compiler/job_queue.rs +++ b/src/cargo/core/compiler/job_queue.rs @@ -14,6 +14,7 @@ use jobserver::{Acquired, HelperThread}; use core::profiles::Profile; use core::{PackageId, Target, TargetKind}; use handle_error; +use util; use util::{internal, profile, CargoResult, CargoResultExt, ProcessBuilder}; use util::{Config, DependencyQueue, Dirty, Fresh, Freshness}; use util::{Progress, ProgressStyle}; @@ -368,16 +369,7 @@ impl<'a> JobQueue<'a> { opt_type += " + debuginfo"; } - let time_elapsed = { - let duration = cx.bcx.config.creation_time().elapsed(); - let secs = duration.as_secs(); - - if secs >= 60 { - format!("{}m {:02}s", secs / 60, secs % 60) - } else { - format!("{}.{:02}s", secs, duration.subsec_nanos() / 10_000_000) - } - }; + let time_elapsed = util::elapsed(cx.bcx.config.creation_time().elapsed()); if self.queue.is_empty() { let message = format!( diff --git a/src/cargo/core/package.rs b/src/cargo/core/package.rs index a35f5ad3c..a5769c2af 100644 --- a/src/cargo/core/package.rs +++ b/src/cargo/core/package.rs @@ -4,21 +4,22 @@ use std::fmt; use std::hash; use std::mem; use std::path::{Path, PathBuf}; -use std::time::Duration; +use std::time::{Instant, Duration}; +use bytesize::ByteSize; +use curl::easy::{Easy, HttpVersion}; +use curl::multi::{Multi, EasyHandle}; +use lazycell::LazyCell; use semver::Version; use serde::ser; use toml; -use lazycell::LazyCell; -use curl::easy::{Easy, HttpVersion}; -use curl::multi::{Multi, EasyHandle}; use core::{Dependency, Manifest, PackageId, SourceId, Target}; use core::{FeatureMap, SourceMap, Summary}; use core::source::MaybePackage; use core::interning::InternedString; use ops; -use util::{internal, lev_distance, Config, Progress, ProgressStyle}; +use util::{self, internal, lev_distance, Config, Progress, ProgressStyle}; use util::errors::{CargoResult, CargoResultExt, HttpNot200}; use util::network::Retry; @@ -258,9 +259,11 @@ pub struct Downloads<'a, 'cfg: 'a> { results: Vec<(usize, CargoResult<()>)>, next: usize, retry: Retry<'cfg>, - progress: RefCell>, + progress: RefCell>>, downloads_finished: usize, - downloaded_bytes: usize, + downloaded_bytes: u64, + largest: (u64, String), + start: Instant, } struct Download { @@ -269,8 +272,9 @@ struct Download { data: RefCell>, url: String, descriptor: String, - total: Cell, - current: Cell, + total: Cell, + current: Cell, + start: Instant, } impl<'cfg> PackageSet<'cfg> { @@ -304,19 +308,21 @@ impl<'cfg> PackageSet<'cfg> { pub fn enable_download<'a>(&'a self) -> CargoResult> { assert!(!self.downloading.replace(true)); Ok(Downloads { + start: Instant::now(), set: self, next: 0, pending: HashMap::new(), pending_ids: HashSet::new(), results: Vec::new(), retry: Retry::new(self.config)?, - progress: RefCell::new(Progress::with_style( + progress: RefCell::new(Some(Progress::with_style( "Downloading", ProgressStyle::Ratio, self.config, - )), + ))), downloads_finished: 0, downloaded_bytes: 0, + largest: (0, String::new()), }) } pub fn get_one(&self, id: &PackageId) -> CargoResult<&Package> { @@ -409,9 +415,9 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { handle.progress_function(move |dl_total, dl_cur, _, _| { tls::with(|downloads| { let dl = &downloads.pending[&token].0; - dl.total.set(dl_total as usize); - dl.current.set(dl_cur as usize); - downloads.tick(false).is_ok() + dl.total.set(dl_total as u64); + dl.current.set(dl_cur as u64); + downloads.tick(WhyTick::DownloadUpdate).is_ok() }) })?; @@ -423,8 +429,10 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { descriptor, total: Cell::new(0), current: Cell::new(0), + start: Instant::now(), }; self.enqueue(dl, handle)?; + self.tick(WhyTick::DownloadStarted)?; Ok(None) } @@ -443,8 +451,6 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { /// /// This function will panic if there are no remaining downloads. pub fn wait(&mut self) -> CargoResult<&'a Package> { - self.tick(true)?; - let (dl, data) = loop { assert_eq!(self.pending.len(), self.pending_ids.len()); let (token, result) = self.wait_for_curl()?; @@ -496,13 +502,26 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { // // We can continue to iterate on this, but this is hopefully good enough // for now. - if !self.progress.borrow().is_enabled() { + if !self.progress.borrow().as_ref().unwrap().is_enabled() { self.set.config.shell().status("Downloading", &dl.descriptor)?; } self.downloads_finished += 1; self.downloaded_bytes += dl.total.get(); - self.tick(true)?; + if dl.total.get() > self.largest.0 { + self.largest = (dl.total.get(), dl.id.name().to_string()); + } + + // We're about to synchronously extract the crate below. While we're + // doing that our download progress won't actually be updated, nor do we + // have a great view into the progress of the extraction. Let's prepare + // the user for this CPU-heavy step if it looks like it'll take some + // time to do so. + if dl.total.get() < ByteSize::kb(400).0 { + self.tick(WhyTick::DownloadFinished)?; + } else { + self.tick(WhyTick::Extracting(&dl.id.name()))?; + } // Inform the original source that the download is finished which // should allow us to actually get the package and fill it in now. @@ -564,17 +583,67 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { } } - fn tick(&self, now: bool) -> CargoResult<()> { - self.progress.borrow_mut().tick( - self.downloads_finished, - self.downloads_finished + self.pending.len(), - ) + fn tick(&self, why: WhyTick) -> CargoResult<()> { + let mut progress = self.progress.borrow_mut(); + let progress = progress.as_mut().unwrap(); + + if let WhyTick::DownloadUpdate = why { + if !progress.update_allowed() { + return Ok(()) + } + } + let mut msg = format!("{} crates", self.pending.len()); + match why { + WhyTick::Extracting(krate) => { + msg.push_str(&format!(", extracting {} ...", krate)); + } + _ => { + let mut dur = Duration::new(0, 0); + let mut remaining = 0; + for (dl, _) in self.pending.values() { + dur += dl.start.elapsed(); + remaining += dl.total.get() - dl.current.get(); + } + if remaining > 0 && dur > Duration::from_millis(500) { + msg.push_str(&format!(", remaining bytes: {}", ByteSize(remaining))); + } + } + } + progress.print_now(&msg) } } +enum WhyTick<'a> { + DownloadStarted, + DownloadUpdate, + DownloadFinished, + Extracting(&'a str), +} + impl<'a, 'cfg> Drop for Downloads<'a, 'cfg> { fn drop(&mut self) { self.set.downloading.set(false); + let progress = self.progress.get_mut().take().unwrap(); + // Don't print a download summary if we're not using a progress bar, + // we've already printed lots of `Downloading...` items. + if !progress.is_enabled() { + return + } + if self.downloads_finished == 0 { + return + } + let mut status = format!("{} crates ({}) in {}", + self.downloads_finished, + ByteSize(self.downloaded_bytes), + util::elapsed(self.start.elapsed())); + if self.largest.0 > ByteSize::mb(1).0 { + status.push_str(&format!( + " (largest was `{}` at {})", + self.largest.1, + ByteSize(self.largest.0), + )); + } + drop(self.set.config.shell().status("Downloaded", status)); } } diff --git a/src/cargo/lib.rs b/src/cargo/lib.rs index 6792ba12c..d511238f4 100644 --- a/src/cargo/lib.rs +++ b/src/cargo/lib.rs @@ -15,6 +15,7 @@ #![cfg_attr(feature = "cargo-clippy", allow(wrong_self_convention))] // perhaps Rc should be special cased in Clippy? extern crate atty; +extern crate bytesize; extern crate clap; #[cfg(target_os = "macos")] extern crate core_foundation; diff --git a/src/cargo/util/mod.rs b/src/cargo/util/mod.rs index aeb78b295..c18914954 100644 --- a/src/cargo/util/mod.rs +++ b/src/cargo/util/mod.rs @@ -1,3 +1,5 @@ +use std::time::Duration; + pub use self::cfg::{Cfg, CfgExpr}; pub use self::config::{homedir, Config, ConfigValue}; pub use self::dependency_queue::{DependencyQueue, Dirty, Fresh, Freshness}; @@ -46,3 +48,13 @@ mod read2; mod progress; mod lockserver; pub mod diagnostic_server; + +pub fn elapsed(duration: Duration) -> String { + let secs = duration.as_secs(); + + if secs >= 60 { + format!("{}m {:02}s", secs / 60, secs % 60) + } else { + format!("{}.{:02}s", secs, duration.subsec_nanos() / 10_000_000) + } +} diff --git a/src/cargo/util/progress.rs b/src/cargo/util/progress.rs index 15ca758af..c6cedf621 100644 --- a/src/cargo/util/progress.rs +++ b/src/cargo/util/progress.rs @@ -16,13 +16,17 @@ pub enum ProgressStyle { Ratio, } +struct Throttle { + first: bool, + last_update: Instant, +} + struct State<'cfg> { config: &'cfg Config, format: Format, - first: bool, - last_update: Instant, name: String, done: bool, + throttle: Throttle, } struct Format { @@ -50,10 +54,9 @@ impl<'cfg> Progress<'cfg> { max_width: n, max_print: 80, }, - first: true, - last_update: Instant::now(), name: name.to_string(), done: false, + throttle: Throttle::new(), }), } } @@ -71,31 +74,10 @@ impl<'cfg> Progress<'cfg> { } pub fn tick(&mut self, cur: usize, max: usize) -> CargoResult<()> { - match self.state { - Some(ref mut s) => s.tick(cur, max, "", true), - None => Ok(()), - } - } - - pub fn clear(&mut self) { - if let Some(ref mut s) = self.state { - s.clear(); - } - } - - pub fn tick_now(&mut self, cur: usize, max: usize, msg: &str) -> CargoResult<()> { - match self.state { - Some(ref mut s) => s.tick(cur, max, msg, false), - None => Ok(()), - } - } -} - -impl<'cfg> State<'cfg> { - fn tick(&mut self, cur: usize, max: usize, msg: &str, throttle: bool) -> CargoResult<()> { - if self.done { - return Ok(()); - } + let s = match &mut self.state { + Some(s) => s, + None => return Ok(()), + }; // Don't update too often as it can cause excessive performance loss // just putting stuff onto the terminal. We also want to avoid @@ -109,36 +91,110 @@ impl<'cfg> State<'cfg> { // 2. If we've drawn something, then we rate limit ourselves to only // draw to the console every so often. Currently there's a 100ms // delay between updates. - if throttle { - if self.first { - let delay = Duration::from_millis(500); - if self.last_update.elapsed() < delay { - return Ok(()); - } - self.first = false; - } else { - let interval = Duration::from_millis(100); - if self.last_update.elapsed() < interval { - return Ok(()); - } - } - self.last_update = Instant::now(); + if !s.throttle.allowed() { + return Ok(()) } - if cur == max { + s.tick(cur, max, "") + } + + pub fn tick_now(&mut self, cur: usize, max: usize, msg: &str) -> CargoResult<()> { + match self.state { + Some(ref mut s) => s.tick(cur, max, msg), + None => Ok(()), + } + } + + pub fn update_allowed(&mut self) -> bool { + match &mut self.state { + Some(s) => s.throttle.allowed(), + None => false, + } + } + + pub fn print_now(&mut self, msg: &str) -> CargoResult<()> { + match &mut self.state { + Some(s) => s.print("", msg), + None => Ok(()), + } + } + + pub fn clear(&mut self) { + if let Some(ref mut s) = self.state { + s.clear(); + } + } +} + +impl Throttle { + fn new() -> Throttle { + Throttle { + first: true, + last_update: Instant::now(), + } + } + + fn allowed(&mut self) -> bool { + if self.first { + let delay = Duration::from_millis(500); + if self.last_update.elapsed() < delay { + return false + } + } else { + let interval = Duration::from_millis(100); + if self.last_update.elapsed() < interval { + return false + } + } + self.update(); + true + } + + fn update(&mut self) { + self.first = false; + self.last_update = Instant::now(); + } +} + +impl<'cfg> State<'cfg> { + fn tick(&mut self, cur: usize, max: usize, msg: &str) -> CargoResult<()> { + if self.done { + return Ok(()); + } + + if max > 0 && cur == max { self.done = true; } // Write out a pretty header, then the progress bar itself, and then // return back to the beginning of the line for the next print. self.try_update_max_width(); - if let Some(string) = self.format.progress_status(cur, max, msg) { - self.config.shell().status_header(&self.name)?; - write!(self.config.shell().err(), "{}\r", string)?; + if let Some(pbar) = self.format.progress(cur, max) { + self.print(&pbar, msg)?; } Ok(()) } + fn print(&mut self, prefix: &str, msg: &str) -> CargoResult<()> { + self.throttle.update(); + self.try_update_max_width(); + + // make sure we have enough room for the header + if self.format.max_width < 15 { + return Ok(()) + } + self.config.shell().status_header(&self.name)?; + let mut line = prefix.to_string(); + self.format.render(&mut line, msg); + + while line.len() < self.format.max_width - 15 { + line.push(' '); + } + + write!(self.config.shell().err(), "{}\r", line)?; + Ok(()) + } + fn clear(&mut self) { self.try_update_max_width(); let blank = " ".repeat(self.format.max_width); @@ -153,7 +209,7 @@ impl<'cfg> State<'cfg> { } impl Format { - fn progress_status(&self, cur: usize, max: usize, msg: &str) -> Option { + fn progress(&self, cur: usize, max: usize) -> Option { // Render the percentage at the far right and then figure how long the // progress bar is let pct = (cur as f64) / (max as f64); @@ -192,26 +248,36 @@ impl Format { string.push_str("]"); string.push_str(&stats); - let mut avail_msg_len = self.max_width - self.width(); + Some(string) + } + + fn render(&self, string: &mut String, msg: &str) { + let mut avail_msg_len = self.max_width - string.len() - 15; let mut ellipsis_pos = 0; - if avail_msg_len > 3 { - for c in msg.chars() { - let display_width = c.width().unwrap_or(0); - if avail_msg_len >= display_width { - avail_msg_len -= display_width; - string.push(c); - if avail_msg_len >= 3 { - ellipsis_pos = string.len(); - } - } else { - string.truncate(ellipsis_pos); - string.push_str("..."); - break; + if avail_msg_len <= 3 { + return + } + for c in msg.chars() { + let display_width = c.width().unwrap_or(0); + if avail_msg_len >= display_width { + avail_msg_len -= display_width; + string.push(c); + if avail_msg_len >= 3 { + ellipsis_pos = string.len(); } + } else { + string.truncate(ellipsis_pos); + string.push_str("..."); + break; } } + } - Some(string) + #[cfg(test)] + fn progress_status(&self, cur: usize, max: usize, msg: &str) -> Option { + let mut ret = self.progress(cur, max)?; + self.render(&mut ret, msg); + Some(ret) } fn width(&self) -> usize {