touch timestamp accuracy on EXT4

Question

Update: Turns out I was being very stupid. I was checking the modification time when I should be checking the access time. The reason it was not reproducible was that the test files were made with dd if=/dev/urandom of="$target" bs='1K' count=1 || exit 1, which most of the time was too fast for the modification time (end of dd) of the new files to be different from the access time (start time of dd). Another thing to watch out for.

I'm working on a script to apply the access time of one file plus two years to another file. This uses stat -c %x, date --rfc-3339=ns and touch -a --date="$result". stat and date both output date strings with nanoseconds, like

2012-11-17 10:22:15.390351800+01:00

, and info coreutils 'touch invocation' says it supports nanoseconds. But sometimes when applying touch there is a small difference between the timestamp applied and the one returned afterwards by stat. Here's data from an actual run:

$ for i in {1..100}; do ./t_timecopy.sh 2>/dev/null| grep ASSERT; done
ASSERT:Expecting same access time expected:<2012-11-17 10:58:40.719320935+01:00> but was:<2012-11-17 10:58:40.723322203+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:00:04.342346275+01:00> but was:<2012-11-17 11:00:04.346358718+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:00:39.343348183+01:00> but was:<2012-11-17 11:00:39.347351686+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:01:08.655348312+01:00> but was:<2012-11-17 11:01:08.659347625+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:01:37.930346876+01:00> but was:<2012-11-17 11:01:37.934347311+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:02:16.939319832+01:00> but was:<2012-11-17 11:02:16.943323061+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:02:46.456443149+01:00> but was:<2012-11-17 11:02:46.458379114+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:03:15.487339595+01:00> but was:<2012-11-17 11:03:15.491341426+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:04:04.646335863+01:00> but was:<2012-11-17 11:04:04.650346634+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:04:14.410326608+01:00> but was:<2012-11-17 11:04:14.414331233+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:04:24.159367348+01:00> but was:<2012-11-17 11:04:24.163352418+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:04:33.931387953+01:00> but was:<2012-11-17 11:04:33.935350115+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:05:03.394361030+01:00> but was:<2012-11-17 11:05:03.398320957+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:05:42.054317430+01:00> but was:<2012-11-17 11:05:42.059106497+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:06:40.346320820+01:00> but was:<2012-11-17 11:06:40.350346956+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:08:17.194346778+01:00> but was:<2012-11-17 11:08:17.198338832+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:08:27.102347603+01:00> but was:<2012-11-17 11:08:27.106320380+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:09:16.247322948+01:00> but was:<2012-11-17 11:09:16.251347966+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:09:55.191325266+01:00> but was:<2012-11-17 11:09:55.195320672+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:12:09.915318301+01:00> but was:<2012-11-17 11:12:09.919334099+01:00>
ASSERT:Expecting same access time expected:<2012-11-17 11:12:28.906346914+01:00> but was:<2012-11-17 11:12:28.910348186+01:00>

So 21 out of 100 tests failed, with a mean of 3.938ms and a median of 4.001 ms. Any ideas what could cause this?

$ uname -a
Linux user 2.6.32-22-generic #33-Ubuntu SMP Wed Apr 28 13:27:30 UTC 2010 i686 GNU/Linux

Answer 1

I used this bunch of (admittedly quick & dirty) oneliners to test your issue on my system - a Mandriva Linux 2010.1 (x86-64):

seq 1 1000 | while read f; do sleep 0.01; touch test-$f-0; done

seq 1 1000 | while read f; do touch -a -d "$(stat -c %x test-$f-0 | sed 's|^2010|2012|')" test-$f-1; done

seq 1 1000 | while read f; do A="$(stat -c %x test-$f-0)"; B="$(stat -c %x test-$f-1)"; if [[ ! "${A#2010}" = "${B#2012}" ]]; then echo test-$f; fi; done

I was unable to reproduce your issue even once. It sounds like touch is not fed the expected timestamp at the -d parameter, but something computed otherwise.

Of course the issue could be system-specific, in which case we'd need more information on your system (CPU, is the OS 32 or 64 bit, kernel/glibc/coreutils versions etc).

UPDATE:

I tried the same with 32-bit versions of stat and touch. No issues came up. The kernel was still an 64-bit one.

UPDATE2:

I also tried this set of oneliners, that focus more on atime:

$ seq 1 1000 | while read f; do sleep 0.01; touch test-$f-0; done
$ seq 1 1000 | while read f; do sleep 0.01; touch test-$f-1; done
$ seq 1 1000 | while read f; do sleep 0.01; cat test-$f-0; done
$ seq 1 1000 | while read f; do touch -a -d "$(stat -c %x test-$f-0 | sed 's|^2010|2012|')" test-$f-1; done
$ seq 1 1000 | while read f; do A="$(stat -c %x test-$f-0)"; B="$(stat -c %x test-$f-1)"; if [[ ! "${A#2010}" = "${B#2012}" ]]; then echo test-$f; fi; done

Again no issue detected. I tried this with both the relatime and strictatime mount options.

UPDATE3:

I just got to perform the tests above on my Mandriva i686 laptop. I seem to get no issues with nanosecond accuracy there either. I also verified on another 32bit system that if nanosecond accuracy is not supported (e.g. on ext3), the nanosecond field in the stat output becomes zero.

Answer 2

Touch on Windows 7 64 bit brings similar problems. This is my exploit code:

touch a && touch b && ls --full-time a b
touch -r a b && ls --full-time a b

And the output:

-rw-rw-rw-  1 Jarek 0 0 2012-05-09 12:05:27.851839700 +0200 a
-rw-rw-rw-  1 Jarek 0 0 2012-05-09 12:05:27.874841000 +0200 b

-rw-rw-rw-  1 Jarek 0 0 2012-05-09 12:05:27.851839700 +0200 a
-rw-rw-rw-  1 Jarek 0 0 2012-05-09 12:05:27.851839000 +0200 b

ls and touch come from gnuwin32. In first 2 output lines there is a timestamp difference of 20 ms. Good. But in the second run they should be equal (b took the stamp from a). No luck. There is a difference of 0.7 us :).

svn status sees the difference and hence it's hard to fool it with touch.