v1.9.0 timestamp compare regression

[YngveNPettersen]

When using Ninja v1.9.0 to build Chromium targets (in our case on to of current v74 builds) starting a new build with updated files also includes a rebuild of about 2-3000 targets.

Investigating, Ninja explain shows lines like this:

ninja explain: output resources/inspector/devtools_compatibility.js older than most recent input ../../chromium/third_party/blink/renderer/devtools/front_end/devtools_compatibility.js (5738534283342450 vs 5738534283342458)
ninja explain: resources/inspector/devtools_compatibility.js is dirty

The problem seems to be caused by the timestamp for the target file being rounded down to the nearest 10 in whatever accuracy is used (I am assuming microseconds)

Chromium copies files using the Python function shutil.copy2 (Python 2), which also copies metadata. (see function ExecRecursiveMirror in the chromium file build/toolchain/win/tool_wrapper.py)

My guess is that the metadata copy function isn't using storage with enough digits (or bits) and ends up rounding the value down to the nearest 10.

The result is that even if there are no changes in the source, starting a build will always rebuild several thousand targets (in our case 5-10% of the targets), rather than saying "nothing to do" as Ninja 1.8.0 does.

[jhasse]

This looks like https://bugs.python.org/issue10148 and was fixed in Python 3.3.0. It's very unfortunate, but I don't think that Ninja should include a workaround for this. Chromium should port its scripts to Python 3 or backport the fix to Python 2 (or a fix that rounds up instead?).

[YngveNPettersen]

AFAIK Chromium are looking at upgrading their Python scripts, but we are probably looking at several months (at least) until that project is far enough along to change the Python version to 3.x

I also doubt that Python 2 would be updated with such a fix at this time.

The alternative is to revert to Ninja 1.8.0, and delay any further Ninja upgrades for at least a year, until after Chromium's Python support have been updated.

[jhasse]

Yeah, it sucks. I don't have an idea how to "fix" this without breaking builds that rely on 1.9.0's nanosecond resolution though.

[YngveNPettersen]

When in doubt, make it an option

[jhasse]

Given that this is the main feature of 1.9, that option basically is "use 1.8.2".

[YngveNPettersen]

OK :(

Reverted our deployment to v1.8.2

[jhasse]

If there are any bugfixes or features from 1.9 that you would like to have sooner rather than later (i.e. next year), I'm open to backporting them for a possible 1.8.3 release.

[YngveNPettersen]

I did not notice anything in particular when skimming the list

[jhasse]

Okay. Thanks btw for the issue. I'm closing it since it's not really a bug in Ninja, but a Python 2 bug that is revealed by 1.9's ns timestamps. If you have an idea for a good workaround, feel free to reopen it.

[randomascii]

I hit this problem as well (on Windows) and ninja complained that the files were not up-to-date even when I copied the files with xcopy. This made it seem like it was a ninja bug rather than a python bug.

That is, if I repeatedly run "ninja pyproto\google\protobuf\text_format.py" then it keeps copying the file. That is inconclusive. But if I xcopy the file and then run ninja it still thinks the file is dirty. This proves that ninja is buggy, unless we want to posit that xcopy has a bug in how it copies dates. Example is here:

c:\src\chromium\src\out\release>xcopy ....\third_party\protobuf\python\google\protobuf\text_format.py pyproto\google\protobuf\text_format.py
Overwrite C:\src\chromium\src\out\release\pyproto\google\protobuf\text_format.py (Yes/No/All)? y
....\third_party\protobuf\python\google\protobuf\text_format.py
1 File(s) copied

c:\src\chromium\src\out\release>autoninja -d explain pyproto\google\protobuf\text_format.py
"c:\src\depot_tools\ninja.exe" -d explain pyproto\google\protobuf\text_format.py -j 320
ninja explain: recorded mtime of pyproto/google/protobuf/text_format.py older than most recent input ../../third_party/protobuf/python/google/protobuf/text_format.py (5686921677987650 vs 5686921677987657)
[1 processes, 1/1 @ 8.7/s : 0.114s ] COPY ../../third_party/protobuf/python/google/protobuf/text_format.py pyproto/google/protobuf/text_format.py
Longest build steps:
0.1 weighted s to build pyproto/google/protobuf/text_format.py (0.1 s CPU time)
Time by build-step type:
0.1 s weighted time to generate 1 .py files (0.1 s CPU time)
0.1 s weighted time (0.1 s CPU time, 1.0x parallelism)
1 build steps completed, average of 8.77/s

[randomascii]

Can we reopen this? This definitely seems like a ninja bug. It only happens with recent builds of ninja, it happens without using python to copy the files, why was this closed as being a ninja bug? I'd reopen this but I lack that power.

[jhasse]

Can you open a new issue with your example? Because the Python 2 bug is real, so I don't want to mix them.

[randomascii]

Done. #1573. I found the change that is causing problems. It is odd that the symptoms seem to be identical (except that with the new issue the problem happens even when doing an xcopy of the files) - it feels like the same underlying root cause, somehow.

[randomascii]

Sorry, I was just misunderstanding this bug. I have nothing new to add. I closed my new issue.