Re: speed up test-stat-time

[Eric Blake]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

According to Eric Blake on 10/9/2009 9:44 PM:
> According to Eric Blake on 10/9/2009 12:06 PM:
>> Multiple calls to sleep(2) add up fast!  I've especially noticed it while
>> working on my utimensat series, where repeatedly running 'make check' stalls 
>> on
>> this test.  Unless you are insane enough to run on FAT, or unlucky enough to 
>> be
>> on mingw (since I didn't want to drag in a dependency on xnanosleep just for
>> this test), this patch gives an order-of-magnitude speedup to test-stat-time.
> 
> And in testing it, I came across spurious failures on at least Darwin's
> NFS client, where mtime is rather bogus until a sync().  I'm pushing this:

File systems are fickle ;)

On an xfs system under Linux, the test is now too fast - it looks like
filesystem timestamps have nanosecond resolution, but are quantized to
approximately 10ms increments.  Sometimes the test passes, but it often
fails, because the stamp file and test file got created during the same
10ms window and had identical ctime.  I'm pushing this to relax the test a
bit; it still completes in under a second on a decent system.

I also noticed that a filesystem listed as ext2/ext3 (I'm not sure which,
but suspect ext2) only supported 1 second resolution; on that file system,
the test normally dragged on for the full 8 seconds (out of necessity).
But there was a slight window for a race (made larger by the longer delay
for xfs), where if the first timestamp was created in the last fraction of
one second, then the next timestamp occurs during the first portion of the
next second, then the two files appear 1 second apart but subsequent
actions using the shorter timeout will fall within the same second and
fail to see a difference.  The new difference algorithm is more robust at
avoiding this race.

- --
Don't work too hard, make some time for fun as well!

Eric Blake             address@hidden
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Public key at home.comcast.net/~ericblake/eblake.gpg
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkrQl60ACgkQ84KuGfSFAYCvBgCeJEqh82PpcLc1JjL43xNL6hhE
Y3YAnRSYe/1DTCkhYzQC3SBdFVeSZ+62
=jtgy
-----END PGP SIGNATURE-----

>From 013ba2c3823412b09ac7707526673788d2190b67 Mon Sep 17 00:00:00 2001
From: Eric Blake <address@hidden>
Date: Sat, 10 Oct 2009 08:04:41 -0600
Subject: [PATCH] test-stat-time: avoid more spurious failures

On xfs, although timestamps can have a full nanosecond resolution,
successive file actions appear to be quantized to approximately
10 millisecond windows.  Running with just 1 ms delays could
cause two actions to fall in the same window, leading to sporadic
failures on a fast enough machine.  Slow down to prevent this.

On ext2, timestamps only have 1 second resolution, but if the
first timestamp was made at 1.95 and the second at 2.10, then
the two files appear 1 second apart, and the shorter delay was
used, causing spurious failures.  Require that the observable
difference lie within the same second, using a second try if
necessary, to prevent this.

* tests/test-stat-time.c (nap): Wait for 15ms rather than 2ms, for
xfs; and avoid race if the two timestamps cross quantization edge.

Signed-off-by: Eric Blake <address@hidden>
---
 ChangeLog              |    4 ++++
 tests/test-stat-time.c |   26 +++++++++++++++++++-------
 2 files changed, 23 insertions(+), 7 deletions(-)

diff --git a/ChangeLog b/ChangeLog
index 0fe5ede..6debba7 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,5 +1,9 @@
 2009-10-10  Eric Blake  <address@hidden>

+       test-stat-time: avoid more spurious failures
+       * tests/test-stat-time.c (nap): Wait for 15ms rather than 2ms, for
+       xfs; and avoid race if the two timestamps cross quantization edge.
+
        futimens: new module
        * modules/futimens: New file.
        * lib/futimens.c (futimens): Likewise.
diff --git a/tests/test-stat-time.c b/tests/test-stat-time.c
index 3759024..da52851 100644
--- a/tests/test-stat-time.c
+++ b/tests/test-stat-time.c
@@ -104,19 +104,31 @@ nap (void)
   static long delay;
   if (!delay)
     {
-      /* Initialize only once, by sleeping for 1 millisecond.  If that
-         was enough to observe a difference, then we are set;
-         otherwise fall back to 2 seconds.  */
+      /* Initialize only once, by sleeping for 15 milliseconds (needed
+         since xfs has a quantization of about 10 milliseconds, even
+         though it has a granularity of 1 nanosecond).  If the seconds
+         differ, repeat the test one more time (in case we crossed a
+         quantization boundary on a file system with 1 second
+         resolution).  If we can't observe a difference in only the
+         nanoseconds, then fall back to 2 seconds.  */
       struct stat st1;
       struct stat st2;
       ASSERT (stat ("t-stt-stamp1", &st1) == 0);
       ASSERT (unlink ("t-stt-stamp1") == 0);
-      usleep (delay = 1000);
+      usleep (delay = 15000);
       create_file ("t-stt-stamp1");
       ASSERT (stat ("t-stt-stamp1", &st2) == 0);
-      if (! (st1.st_mtime < st2.st_mtime
-             || (st1.st_mtime == st2.st_mtime
-                 && get_stat_mtime_ns (&st1) < get_stat_mtime_ns (&st2))))
+      if (st1.st_mtime != st2.st_mtime)
+        {
+          /* Seconds differ, give it one more shot.  */
+          st1 = st2;
+          ASSERT (unlink ("t-stt-stamp1") == 0);
+          usleep (delay);
+          create_file ("t-stt-stamp1");
+          ASSERT (stat ("t-stt-stamp1", &st2) == 0);
+        }
+      if (! (st1.st_mtime == st2.st_mtime
+             && get_stat_mtime_ns (&st1) < get_stat_mtime_ns (&st2)))
         delay = 2000000;
     }
   usleep (delay);
-- 
1.6.5.rc1