Nanosecond-granularity modification times cause spurious rebuilds

[shepmaster]

I have a large Cargo.toml that I'm placing in a Docker container and prebuilding all the dependencies. However, at runtime there's still one crate that is rebuilt: tempfile v2.1.4. Turning on logging shows:

INFO:cargo::ops::cargo_rustc::fingerprint: fingerprint error for tempfile v2.1.4: mtime based comopnents have changed: Some(FileTime { seconds: 1468471990, nanos: 0 }) != Some(FileTime { seconds: 1468471990, nanos: 914840077 }), paths are "/playground/target/debug/build/tempfile-1b82f6307d61d5f0/output" and "/playground/target/debug/build/tempfile-1b82f6307d61d5f0/output"

More specifically:

Some(FileTime { seconds: 1468471990, nanos: 0 })
Some(FileTime { seconds: 1468471990, nanos: 914840077 })

A complete log

[shepmaster]

This may be a Docker-specific issue, but I'm unclear as to why it would only happen with the one crate. If I watch the modification times, it appears that the filesystem truncates the modification time between images:

RUN cargo build && ls --full-time /playground/target/debug/build/tempfile-1b82f6307d61d5f0/output

RUN ls --full-time /playground/target/debug/build/tempfile-1b82f6307d61d5f0/output

-rw-r--r-- 1 root root 60 2016-07-14 13:26:37.779155991 +0000 /playground/target/debug/build/tempfile-1b82f6307d61d5f0/output

-rw-r--r-- 1 root root 60 2016-07-14 13:26:37.000000000 +0000 /playground/target/debug/build/tempfile-1b82f6307d61d5f0/output

[shepmaster]

Interestingly, tempfile is the only crate that is using MtimeBased, all the rest use Precalculated:

{
  "rustc": 0,
  "target": 0,
  "profile": 0,
  "local": {
    "variant": "MtimeBased",
    "fields": [
      [
        1468471990,
        914840077
      ],
      [
        47, 112, 108, 97, 121, 103, 114, 111, 117, 110, 100, 47, 116, 97, 114,
        103, 101, 116, 47, 100, 101, 98, 117, 103, 47, 98, 117, 105, 108, 100,
        47, 116, 101, 109, 112, 102, 105, 108, 101, 45, 49, 98, 56, 50, 102,
        54, 51, 48, 55, 100, 54, 49, 100, 53, 102, 48, 47, 111, 117, 116, 112,
        117, 116
      ]
    ]
  },
  "features": "",
  "deps": [],
  "rustflags": []
}

[shepmaster]

One thing of note is that the modification checks assert that the values are equal. Many other systems test if the file is older than the fingerprint. Is that a deliberate decision, or is it possible that could be changed?

[nagisa]

I’m not sure it is possible to do anything about this. It is generally a well known issue with timestamp-based change tracking in build systems.

[alexcrichton]

I feel like I've definitely seen this before in terms of docker dropping nanosecond precision, although I can't seem to find any issues related to that. I also wouldn't mind changing the check here to be a "less than or equal to" relation rather than "equal to", as I agree it's what I would generally expect and would also naturally solve this!

[alexcrichton]

One behavior I've found in rustbuild at least is:

• With makefiles, I run touch -t 199009090909 src/**/*.rs && make check a lot
• This does not work with Cargo, and I have no idea why.

I think it's because the mtime of a project is the maximum mtime, and if this mtime is different than what's in the metadata we rebuild, rather than if it's later we rebuild.

@shepmaster would you like to make a PR?

[arcnmx]

Chiming in that I just encountered this, and a <= check rather than == would be very useful. My particular case was sharing a cache across a CI system that uses docker, though I'm not sure whether it's docker or the caching system that's truncating the timestamps...

[shepmaster]

For those that might want a workaround, here's a jq invocation that zeroes out the nanoseconds in the fingerprint files:

jq 'if .local.variant == "MtimeBased" then .local.fields[0][1] |= 0 else . end'

I threw that in a file:

t=$(mktemp)
jq 'if .local.variant == "MtimeBased" then .local.fields[0][1] |= 0 else . end' "$1" > "$t"
mv "$t" "$1"

And then fix all the fingerprints:

find . -name '*.json' -print0 | xargs -0 -n1 /root/fix-modification-time.sh

[carols10cents]

This was fixed in #2880