rustpkg: no_rebuilding_dep test failure

[klutzy]

My debian x64 fails on make check:

$ rust -v
rust 0.8-pre (2562f48 2013-09-16 06:30:51 -0700)
host: x86_64-unknown-linux-gnu

$ RUST_LOG=rustpkg make check TESTNAME=no_rebuilding_dep 2> out
<snip>
running 1 test
test tests::no_rebuilding_dep ... FAILED

metrics saved to: tmp/check-stage2-T-x86_64-unknown-linux-gnu-H-x86_64-unknown-linux-gnu-rustpkg-metrics.json
failures:
    tests::no_rebuilding_dep

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured

$ cat out
Created /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1 and does it exist? true
mk_workspace: creating /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1
Created /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1 and does it exist? true
Created empty package dir for foo-0.1, returning /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1
Created /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1 and does it exist? true
 cd /tmp/d5lF0kcJw3ifff0Wtemp_workspace; /home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/bin/rustpkg build foo
Output from command /home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/bin/rustpkg with args &[~"build", ~"foo"] was WARNING: The Rust package manager is experimental and may be unstable
note: Installed package bar-0.1 to /tmp/d5lF0kcJw3ifff0Wtemp_workspace
 {Using sysroot: /home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu
Will store workcache in /tmp/d5lF0kcJw3ifff0Wtemp_workspace/.rust
Workcache database file: /tmp/d5lF0kcJw3ifff0Wtemp_workspace/.rust/rustpkg_db.json
Didn't find foo-0.1 in /tmp/d5lF0kcJw3ifff0Wtemp_workspace/.rust
Found foo-0.1 in /tmp/d5lF0kcJw3ifff0Wtemp_workspace
found pkg foo-0.1 in workspace /tmp/d5lF0kcJw3ifff0Wtemp_workspace, trying to build
Checking package source for package ID foo-0.1, workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace
Checking dirs: ~"/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo"
For package id foo-0.1, returning /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1
pkgsrc: Returning {/tmp/d5lF0kcJw3ifff0Wtemp_workspace|/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1|foo-0.1}
package source = Package ID foo-0.1 in start dir /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1 [workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace]
package_script_option: checking whether /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/pkg.rs exists
exec_work: looking up foo-0.1 and extra::workcache::WorkMap(extra::treemap::TreeMap<~str,extra::workcache::KindMap>{root: None, length: 0u})
"Cache miss!"
build: workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace (in Rust path? true is git dir? false pkgid = foo-0.1 pkgsrc start_dir = /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1
Package source directory = Package ID foo-0.1 in start dir /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1 [workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace]
package_script_option: checking whether /tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/pkg.rs exists
Calling pkg_script_option on None
packa[...]
lib_output_file_name: given /tmp/d5lF0kcJw3ifff0Wtemp_workspace and parent .rust and short name bar
library_in_workspace: checking whether a library named bar exists
short_name = bar where = Build workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace prefix = build
Listing directory /tmp/d5lF0kcJw3ifff0Wtemp_workspace/build/x86_64-unknown-linux-gnu/bar
dir has 4u entries
lib_prefix = libbar and lib_filetype = .so
p = barbench, p's extension is None
p = bar, p's extension is None
p = libbar-40b5eb3af07a7a64-0.1.so, p's extension is Some(".so")
Maybe 0.1 is a version
Attempting to parse: 0.1
Maybe libbar equals libbar
p = bartest, p's extension is None
result_filename = /tmp/d5lF0kcJw3ifff0Wtemp_workspace/build/x86_64-unknown-linux-gnu/bar/libbar-40b5eb3af07a7a64-0.1.so
 cd /tmp/d5lF0kcJw3ifff0Wtemp_workspace; /home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/bin/rustpkg build foo
Output from command /home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/bin/rustpkg with args &[~"build", ~"foo"] was WARNING: The Rust package manager is experimental and may be unstable
workcache: discovered input binary:/home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/lib/libextra-a7c050cfd46b2c9a-0.8-pre.so is fresh
workcache: discovered input binary:/home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/lib/libstd-6c65cf4b443341b1-0.8-pre.so is fresh
workcache: discovered input binary:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/bin/bar is fresh
workcache: discovered input binary:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/lib/x86_64-unknown-linux-gnu/libbar-40b5eb3af07a7a64-0.1.so is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1/bench.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1/lib.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1/main.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1/test.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/bench.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/lib.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/main.rs is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/foo-0.1/test.rs is not fresh
workcache: discovered input binary:/home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/lib/libextra-a7c050cfd46b2c9a-0.8-pre.so is fresh
workcache: discovered input binary:/home/lime/src/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustc/x86_64-unknown-linux-gnu/lib/libstd-6c65cf4b443341b1-0.8-pre.so is fresh
workcache: discovered input file:/tmp/d5lF0kcJw3ifff0Wtemp_workspace/src/bar-0.1/bench.rs is fr[...]
lib_output_file_name: given /tmp/d5lF0kcJw3ifff0Wtemp_workspace and parent .rust and short name bar
library_in_workspace: checking whether a library named bar exists
short_name = bar where = Build workspace = /tmp/d5lF0kcJw3ifff0Wtemp_workspace prefix = build
Listing directory /tmp/d5lF0kcJw3ifff0Wtemp_workspace/build/x86_64-unknown-linux-gnu/bar
dir has 4u entries
lib_prefix = libbar and lib_filetype = .so
p = barbench, p's extension is None
p = bar, p's extension is None
p = libbar-40b5eb3af07a7a64-0.1.so, p's extension is Some(".so")
Maybe 0.1 is a version
Attempting to parse: 0.1
Maybe libbar equals libbar
p = bartest, p's extension is None
result_filename = /tmp/d5lF0kcJw3ifff0Wtemp_workspace/build/x86_64-unknown-linux-gnu/bar/libbar-40b5eb3af07a7a64-0.1.so
task <unnamed> failed at 'assertion failed: foo_date_1 < foo_date_2', /home/lime/src/rust/src/librustpkg/tests.rs:959
task <unnamed> failed at 'Some tests failed', /home/lime/src/rust/src/libextra/test.rs:131
make: *** [tmp/check-stage2-T-x86_64-unknown-linux-gnu-H-x86_64-unknown-linux-gnu-rustpkg.ok] Error 101

bors also failed on pr #9211, auto-linux-64-nopt-t build log. (buildbot succeeded after retrial)

[klutzy]

cc @catamorphism

[catamorphism]

Yes, I'm actually working on this right now. It has to do with timestamp granularity not being fine enough (so I'm rewriting the test to not compare timestamps).

[klutzy]

#9269 disabled the test. #9263 will hopefully fix it

[erickt]

@catamorphism: I had this same problem in fbuild. I worked around if by comparing hashes if the timestamps were the same. For the tests, I believe I just did something cheesy where I just would do the equivalent of a sleep 1 in between

Another thing you might run into is that I had to put locks in a couple places to make sure that multiple threads didn't stomp on each other. First was a lock around hashing a file to prevent work duplication. Second, I ended up running the database in it's own thread and serialized reads and writes with a queue to protect against multiple threads trying to run the same function at the same time. You can see that code here by looking for any uses of _rpc. I'm not sure if workcache.rs is protecting against that. I'm traveling tomorrow, but I should be around this weekend or next week if any of that was unclear or have any questions.

[catamorphism]

This test is enabled now.

@erickt My workaround, which Jack suggested, is to make the output file read-only so that if it gets wrongly rebuilt, the operation will fail. I also thought of doing a sleep 1, but I think adding that into the test suite would be frowned upon :-)

As for locks, I think workcache takes care of that, but I'll look out for that issue in the future.