Builds relatively frequently fail due to Cargo not running rustc

[Mark-Simulacrum]

DEBUG 2018-03-21T01:17:37Z: collector::execute: running cargo Build --release
TRACE 2018-03-21T01:17:37Z: collector::execute: running: "cargo" "pkgid" "--manifest-path" "Cargo.toml"
TRACE 2018-03-21T01:17:37Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0\n", stderr: "" }
TRACE 2018-03-21T01:17:37Z: collector::execute: running: "cargo" "rustc" "-p" "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0" "--release" "--manifest-path" "Cargo.toml" "--"
 "-Ztime-passes"
TRACE 2018-03-21T01:17:41Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "22638589607;;instructions:u;4255865057;100.00;1.45;insn per cycle\n15646044215;;cycles:u;4255865057;1
00.00;3.676;GHz\n4255.784305;;task-clock;4255784305;100.00;1.022;CPUs utilized\n4255.767085;;cpu-clock;4255784305;100.00;1.022;CPUs utilized\n328003;;faults;4255784305;100.00;0.077;M/sec\n443096;;max-rss;3;100.
00\n4.172464609;;wall-time;4;100.00\n", stderr: "   Compiling issue-20936-deep-vector v0.1.0 (file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI)\n    Finished release [optimized] target(s) in 4.17 secs\n" }
TRACE 2018-03-21T01:17:41Z: collector::execute: running: "bash" "-c" "find . -name \'*.rs\' | xargs touch"
TRACE 2018-03-21T01:17:41Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "", stderr: "" }
DEBUG 2018-03-21T01:17:41Z: collector::execute: running cargo Build --release
TRACE 2018-03-21T01:17:41Z: collector::execute: running: "cargo" "pkgid" "--manifest-path" "Cargo.toml"
TRACE 2018-03-21T01:17:41Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0\n", stderr: "" }
TRACE 2018-03-21T01:17:41Z: collector::execute: running: "cargo" "rustc" "-p" "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0" "--release" "--manifest-path" "Cargo.toml" "--"
 "-Ztime-passes"
TRACE 2018-03-21T01:17:46Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "24287232194;;instructions:u;4408121623;100.00;1.49;insn per cycle\n16264090228;;cycles:u;4408121623;1
00.00;3.690;GHz\n4408.041653;;task-clock;4408041653;100.00;1.024;CPUs utilized\n4408.037422;;cpu-clock;4408041653;100.00;1.024;CPUs utilized\n326458;;faults;4408041653;100.00;0.074;M/sec\n447736;;max-rss;3;100.
00\n4.311661802;;wall-time;4;100.00\n", stderr: "   Compiling issue-20936-deep-vector v0.1.0 (file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI)\n    Finished release [optimized] target(s) in 4.31 secs\n" }
TRACE 2018-03-21T01:17:46Z: collector::execute: running: "bash" "-c" "find . -name \'*.rs\' | xargs touch"
TRACE 2018-03-21T01:17:46Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "", stderr: "" }
DEBUG 2018-03-21T01:17:46Z: collector::execute: running cargo Build --release
TRACE 2018-03-21T01:17:46Z: collector::execute: running: "cargo" "pkgid" "--manifest-path" "Cargo.toml"
TRACE 2018-03-21T01:17:46Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0\n", stderr: "" }
TRACE 2018-03-21T01:17:46Z: collector::execute: running: "cargo" "rustc" "-p" "file:///tmp/rustc-benchmark-deep-vector.V3nu37sz33DI#issue-20936-deep-vector:0.1.0" "--release" "--manifest-path" "Cargo.toml" "--" "-Ztime-passes"
TRACE 2018-03-21T01:17:46Z: collector::execute: output: Output { status: ExitStatus(ExitStatus(0)), stdout: "", stderr: "    Finished release [optimized] target(s) in 0.0 secs\n" }
thread 'main' panicked at 'at least one stat collected, output: ""', collector/src/bin/rustc-perf-collector/execute.rs:445:5

We currently run bash -c "find . -name '*.rs' | xargs touch" but apparently that isn't enough in all cases, as we aren't running rustc sometimes which leads to the build failing as we then don't collect any stats. This happens pretty often, so I'm looking for a fix urgently.

cc @alexcrichton -- is there a good way to force Cargo to build a particular package?

cc @nikomatsakis / @michaelwoerister (perf is basically ~down because of this, until we find a solution most builds are failing)

[alexcrichton]

Hm if touch isn't causing a rebuild it's probably because the files are accidentally not getting touched? Short of switching target directories or blowing away the previous one there's no way to force cargo to build something

[Mark-Simulacrum]

Is it possible that the system time is drifting or something like that? It feels unlikely but based on the fact that this isn't a consistent failure for the same benchmark and it seems to work locally and on Travis, at least mostly, I'm surprised what could be the cause here... the directory is in /tmp which perhaps isn't quite standard for Cargo, so there could maybe be some flaws there?

[alexcrichton]

Hm are you sure the find is executing in the right directory? In that are you sure it's actually touching the right files forward?

[michaelwoerister]

/tmp sometimes does have a different file system, IIRC. Maybe timestamps don't work as reliably there? I've run into such file system timestamp related problems a lot on FAT in the past. You could try adding a 2 second timeout before running touch and see if that helps.

[Mark-Simulacrum]

This seems to have been fixed by 31c4830, which made us retry running rustc/cargo if we didn't get output. I'm personally surprised that was enough, but it seems to have fixed the problem, so I'm happy enough.

[RalfJung]

Is it possible that you ran into rust-lang/cargo#5918 ?