Auto merge of #5314 - matklad:need-more-time, r=alexcrichton

Try to measure all time it takes to compile code

As @killercup noticed on IRC, no-op build by Cargo takes as much as 300 ms (on stable, beta and nightly), which seems unreasonable. However, Cargo wrongly reports ` Finished dev [unoptimized + debuginfo] target(s) in 0.0 secs`, and this might be the reason why we haven't noticed this before.

So let's try to measure time slightly better:

```
~/projects/rustraytracer master*
λ time cargo +stable build
    Finished dev [unoptimized + debuginfo] target(s) in 0.0 secs
cargo +stable build  0.16s user 0.02s system 94% cpu 0.195 total

~/projects/rustraytracer master*
λ time $c build # Cargo with this patch applied
    Finished dev [unoptimized + debuginfo] target(s) in 0.31 secs
$c build  0.30s user 0.02s system 96% cpu 0.330 total
```

r? @alexcrichton

Author: bors

src/cargo/ops/cargo_rustc/job_queue.rs

@@ -148,8 +148,6 @@ impl<'a> JobQueue<'a> {
         scope: &Scope<'a>,
         jobserver_helper: &HelperThread,
     ) -> CargoResult<()> {
-        use std::time::Instant;
-
         let mut tokens = Vec::new();
         let mut queue = Vec::new();
         trace!("queue: {:#?}", self.queue);
@@ -165,7 +163,6 @@ impl<'a> JobQueue<'a> {
         // successful and otherwise wait for pending work to finish if it failed
         // and then immediately return.
         let mut error = None;
-        let start_time = Instant::now();
         loop {
             // Dequeue as much work as we can, learning about everything
             // possible that can run. Note that this is also the point where we
@@ -265,7 +262,7 @@ impl<'a> JobQueue<'a> {
         if profile.debuginfo.is_some() {
             opt_type += " + debuginfo";
         }
-        let duration = start_time.elapsed();
+        let duration = cx.config.creation_time().elapsed();
         let time_elapsed = format!(
             "{}.{1:.2} secs",
             duration.as_secs(),

src/cargo/util/config.rs

@@ -11,6 +11,7 @@ use std::mem;
 use std::path::{Path, PathBuf};
 use std::str::FromStr;
 use std::sync::{Once, ONCE_INIT};
+use std::time::Instant;
 
 use curl::easy::Easy;
 use jobserver;
@@ -65,6 +66,7 @@ pub struct Config {
     easy: LazyCell<RefCell<Easy>>,
     /// Cache of the `SourceId` for crates.io
     crates_io_source_id: LazyCell<SourceId>,
+    creation_time: Instant,
 }
 
 impl Config {
@@ -101,6 +103,7 @@ impl Config {
             cli_flags: CliUnstable::default(),
             easy: LazyCell::new(),
             crates_io_source_id: LazyCell::new(),
+            creation_time: Instant::now(),
         }
     }
 
@@ -678,6 +681,10 @@ impl Config {
     {
         Ok(self.crates_io_source_id.try_borrow_with(f)?.clone())
     }
+
+    pub fn creation_time(&self) -> Instant {
+        self.creation_time
+    }
 }
 
 #[derive(Eq, PartialEq, Clone, Copy)]