s4:torture:basic: eliminate potential for false failures in delayed_write_update1c
authorMichael Adam <obnox@samba.org>
Thu, 2 Oct 2014 15:15:04 +0000 (17:15 +0200)
committerAndrew Bartlett <abartlet@samba.org>
Fri, 3 Oct 2014 06:34:06 +0000 (08:34 +0200)
We want to test that the write did update the write time immediately.
We check this by getting the file info in a loop for a few seconds.
There are several result cases:

- the server updated the write time immediately - success
- the server updated the write time, but not immediately - failure
- the server did not update the write time - failure

The loop is only there to be able to discern between the two
failure cases. The check for success is whether the first
getinfo has reportet the updated write time.

The potential for false failures was the additional timing check.
So if the first fileinfo call just took too long (e.g. due to a
busy system), this was reported as failure.

This patch should eliminate interemittent autobuild failures.

Signed-off-by: Michael Adam <obnox@samba.org>
Reviewed-by: Andrew Bartlett <abartlet@samba.org>
source4/torture/basic/delaywrite.c

index 6abb7b51f44b0ab7c3f9c1794abf1ba8948cbe05..67788f48a254a37266722c7cabbf87bf453c375d 100644 (file)
@@ -616,6 +616,8 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
        double sec = ((double)used_delay) / ((double)normal_delay);
        int msec = 1000 * sec;
        char buf[2048];
+       bool first;
+       bool updated;
 
        torture_comment(tctx, "\nRunning test_delayed_write_update1c\n");
 
@@ -661,6 +663,8 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
        start = timeval_current();
        end = timeval_add(&start, (120*sec), 0);
+       first = true;
+       updated = false;
        while (!timeval_expired(&end)) {
                status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
@@ -672,31 +676,27 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
                torture_comment(tctx, "write time %s\n",
                        nt_time_string(tctx, finfo2.all_info.out.write_time));
-               if (finfo1.all_info.out.write_time != finfo2.all_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       if (diff > (0.25 * (used_delay / (double)1000000))) {
-                               torture_result(tctx, TORTURE_FAIL, "After SET_ALLOCATION_INFO truncate "
-                                       "server updated write_time after %.2f seconds"
-                                       "(write time update delay == %.2f)(wrong!)\n",
-                                       diff, used_delay / (double)1000000);
-                               ret = false;
-                               break;
-                       }
 
-                       torture_comment(tctx, "After SET_ALLOCATION_INFO truncate "
-                                       "server updated write_time after %.2f seconds"
-                                       "(write time update delay == %.2f)(correct)\n",
-                                       diff, used_delay / (double)1000000);
+               if (finfo1.all_info.out.write_time !=
+                   finfo2.all_info.out.write_time)
+               {
+                       updated = true;
                        break;
                }
+
                fflush(stdout);
                smb_msleep(1 * msec);
+               first = false;
        }
 
-       torture_assert_u64_not_equal(tctx,
-                                    finfo2.all_info.out.write_time,
-                                    finfo1.all_info.out.write_time,
-                                    "Server did not update write time");
+       torture_assert(tctx, updated,
+                      "Server did not update write time within 120 seconds");
+
+       torture_assert(tctx, first, talloc_asprintf(tctx,
+                      "Server did not update write time immediately but only "
+                      "after %.2f seconds!", timeval_elapsed(&start)));
+
+       torture_comment(tctx, "Server updated write time immediately. Good!\n");
 
        fflush(stdout);
        smb_msleep(2 * msec);