TODO source4/torture/smb2/durable_open.c
authorStefan Metzmacher <metze@samba.org>
Tue, 14 Aug 2018 13:16:21 +0000 (15:16 +0200)
committerStefan Metzmacher <metze@samba.org>
Tue, 14 Aug 2018 15:52:56 +0000 (17:52 +0200)
source4/torture/smb2/durable_open.c

index 092294ff534146f5d188cdd79ac57e51aa4d9afa..58bbe3bf648fae7bd8c4ef5c86a1a9d4bc914af1 100644 (file)
@@ -2821,6 +2821,13 @@ done:
        COMPARE_CREATE_TIME_EQUAL(given,correct); \
 } while (0)
 
+#define COMPARE_TIMES_AFTER_WRITE(given,correct) do { \
+       COMPARE_ACCESS_TIME_GREATER(given,correct); \
+       COMPARE_WRITE_TIME_GREATER(given,correct); \
+       COMPARE_CHANGE_TIME_GREATER(given,correct); \
+       COMPARE_CREATE_TIME_EQUAL(given,correct); \
+} while (0)
+
 #define GET_INFO_FILE(tree, finfo) do { \
        struct timeval _atv; \
        struct timeval _wtv; \
@@ -2889,366 +2896,6 @@ done:
        } \
 } while (0)
 
-#if 0
-static bool test_delayed_write_update3(struct torture_context *tctx,
-                                      struct smbcli_state *cli,
-                                      struct smbcli_state *cli2)
-{
-       union smb_fileinfo finfo0, finfo1, finfo2, finfo3;
-       union smb_fileinfo pinfo0, pinfo1, pinfo2, pinfo3, pinfo4;
-       const char *fname = BASEDIR "\\torture_file3.txt";
-       int fnum1 = -1;
-       bool ret = true;
-       ssize_t written;
-       struct timeval start;
-       struct timeval end;
-       double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", 2000000);
-       int normal_delay = 2000000;
-       double sec = ((double)used_delay) / ((double)normal_delay);
-       int msec = 1000 * sec;
-
-       torture_comment(tctx, "\nRunning test_delayed_write_update3\n");
-
-       torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
-
-       torture_comment(tctx, "Open the file handle\n");
-       fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-       if (fnum1 == -1) {
-               ret = false;
-               torture_result(tctx, TORTURE_FAIL, __location__": unable to open %s", fname);
-               goto done;
-       }
-
-       finfo0.basic_info.level = RAW_FILEINFO_BASIC_INFO;
-       finfo0.basic_info.in.file.fnum = fnum1;
-       finfo1 = finfo0;
-       finfo2 = finfo0;
-       finfo3 = finfo0;
-       pinfo0.basic_info.level = RAW_FILEINFO_BASIC_INFO;
-       pinfo0.basic_info.in.file.path = fname;
-       pinfo1 = pinfo0;
-       pinfo2 = pinfo0;
-       pinfo3 = pinfo0;
-       pinfo4 = pinfo0;
-
-       /* get the initial times */
-       GET_INFO_BOTH(finfo0,pinfo0);
-
-       /*
-        * make sure the write time is updated 2 seconds later
-        * calcuated from the first write
-        * (but expect upto 5 seconds extra time for a busy server)
-        */
-       start = timeval_current();
-       end = timeval_add(&start, 7 * sec, 0);
-       while (!timeval_expired(&end)) {
-               /* do a write */
-               torture_comment(tctx, "Do a write on the file handle\n");
-               written = smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
-               if (written != 1) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_FILE(finfo1);
-
-               if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       if (diff < (used_delay / (double)1000000)) {
-                               torture_result(tctx, TORTURE_FAIL, "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, "Server updated write_time after %.2f seconds "
-                                       "(correct)\n",
-                                       diff);
-                       break;
-               }
-               smb_msleep(0.5 * msec);
-       }
-
-       GET_INFO_BOTH(finfo1,pinfo1);
-       COMPARE_WRITE_TIME_GREATER(pinfo1, pinfo0);
-
-       /* sure any further write doesn't update the write time */
-       start = timeval_current();
-       end = timeval_add(&start, 15 * sec, 0);
-       while (!timeval_expired(&end)) {
-               /* do a write */
-               torture_comment(tctx, "Do a write on the file handle\n");
-               written = smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
-               if (written != 1) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_BOTH(finfo2,pinfo2);
-
-               if (finfo2.basic_info.out.write_time > finfo1.basic_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       torture_result(tctx, TORTURE_FAIL, "Server updated write_time after %.2f seconds "
-                                       "(wrong!)\n",
-                                       diff);
-                       ret = false;
-                       break;
-               }
-               smb_msleep(1 * msec);
-       }
-
-       GET_INFO_BOTH(finfo2,pinfo2);
-       COMPARE_WRITE_TIME_EQUAL(finfo2, finfo1);
-       if (finfo2.basic_info.out.write_time == finfo1.basic_info.out.write_time) {
-               torture_comment(tctx, "Server did not update write_time (correct)\n");
-       }
-
-       /* sleep */
-       smb_msleep(5 * msec);
-
-       GET_INFO_BOTH(finfo3,pinfo3);
-       COMPARE_WRITE_TIME_EQUAL(finfo3, finfo2);
-
-       /*
-        * the close updates the write time to the time of the close
-        * and not to the time of the last write!
-        */
-       torture_comment(tctx, "Close the file handle\n");
-       smbcli_close(cli->tree, fnum1);
-       fnum1 = -1;
-
-       GET_INFO_PATH(pinfo4);
-       COMPARE_WRITE_TIME_GREATER(pinfo4, pinfo3);
-
-       if (pinfo4.basic_info.out.write_time > pinfo3.basic_info.out.write_time) {
-               torture_comment(tctx, "Server updated the write_time on close (correct)\n");
-       }
-
- done:
-       if (fnum1 != -1)
-               smbcli_close(cli->tree, fnum1);
-       smbcli_unlink(cli->tree, fname);
-       smbcli_deltree(cli->tree, BASEDIR);
-
-       return ret;
-}
-
-/*
- * Show that a truncate write always updates the write time even
- * if an initial write has already updated the write time.
- */
-
-static bool test_delayed_write_update3a(struct torture_context *tctx,
-                                       struct smbcli_state *cli,
-                                       struct smbcli_state *cli2)
-{
-       union smb_fileinfo finfo0, finfo1, finfo2, finfo3;
-       union smb_fileinfo pinfo0, pinfo1, pinfo2, pinfo3, pinfo4;
-       const char *fname = BASEDIR "\\torture_file3a.txt";
-       int fnum1 = -1;
-       bool ret = true;
-       ssize_t written;
-       int i;
-       struct timeval start;
-       struct timeval end;
-       double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", 2000000);
-       int normal_delay = 2000000;
-       double sec = ((double)used_delay) / ((double)normal_delay);
-       int msec = 1000 * sec;
-
-       torture_comment(tctx, "\nRunning test_delayed_write_update3a\n");
-
-       torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
-
-       torture_comment(tctx, "Open the file handle\n");
-       fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-       if (fnum1 == -1) {
-               ret = false;
-               torture_result(tctx, TORTURE_FAIL, __location__": unable to open %s", fname);
-               goto done;
-       }
-
-       finfo0.basic_info.level = RAW_FILEINFO_BASIC_INFO;
-       finfo0.basic_info.in.file.fnum = fnum1;
-       finfo1 = finfo0;
-       finfo2 = finfo0;
-       finfo3 = finfo0;
-       pinfo0.basic_info.level = RAW_FILEINFO_BASIC_INFO;
-       pinfo0.basic_info.in.file.path = fname;
-       pinfo1 = pinfo0;
-       pinfo2 = pinfo0;
-       pinfo3 = pinfo0;
-       pinfo4 = pinfo0;
-
-       /* get the initial times */
-       GET_INFO_BOTH(finfo0,pinfo0);
-
-       /*
-        * sleep some time, to demonstrate the handling of write times
-        * doesn't depend on the time since the open
-        */
-       smb_msleep(5 * msec);
-
-       /* get the initial times */
-       GET_INFO_BOTH(finfo1,pinfo1);
-       COMPARE_WRITE_TIME_EQUAL(finfo1, finfo0);
-
-       /*
-        * make sure the write time is updated 2 seconds later
-        * calcuated from the first write
-        * (but expect upto 5 seconds extra time for a busy server)
-        */
-       start = timeval_current();
-       end = timeval_add(&start, 7 * sec, 0);
-       while (!timeval_expired(&end)) {
-               /* do a write */
-               torture_comment(tctx, "Do a write on the file handle\n");
-               written = smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
-               if (written != 1) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_FILE(finfo1);
-
-               if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       if (diff < (used_delay / (double)1000000)) {
-                               torture_result(tctx, TORTURE_FAIL, "Server updated write_time after %.2f seconds "
-                                               "(1sec == %.2f) (wrong!)\n",
-                                               diff, sec);
-                               ret = false;
-                               break;
-                       }
-
-                       torture_comment(tctx, "Server updated write_time after %.2f seconds "
-                                       "(correct)\n",
-                                       diff);
-                       break;
-               }
-               smb_msleep(0.5 * msec);
-       }
-
-       GET_INFO_BOTH(finfo1,pinfo1);
-       COMPARE_WRITE_TIME_GREATER(pinfo1, pinfo0);
-
-       smb_msleep(3 * msec);
-
-       /*
-        * demonstrate that a truncate write always
-        * updates the write time immediately
-        */
-       for (i=0; i < 3; i++) {
-               smb_msleep(2 * msec);
-               /* do a write */
-               torture_comment(tctx, "Do a truncate SMBwrite [%d] on the file handle\n", i);
-               written = smbcli_smbwrite(cli->tree, fnum1, "x", 10240, 0);
-               if (written != 0) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 0", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_BOTH(finfo2,pinfo2);
-               COMPARE_WRITE_TIME_GREATER(finfo2, finfo1);
-               finfo1 = finfo2;
-       }
-
-       smb_msleep(3 * msec);
-
-       /* sure any further write doesn't update the write time */
-       start = timeval_current();
-       end = timeval_add(&start, 15 * sec, 0);
-       while (!timeval_expired(&end)) {
-               /* do a write */
-               torture_comment(tctx, "Do a write on the file handle\n");
-               written = smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
-               if (written != 1) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_BOTH(finfo2,pinfo2);
-
-               if (finfo2.basic_info.out.write_time > finfo1.basic_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       torture_result(tctx, TORTURE_FAIL, "Server updated write_time after %.2f seconds "
-                                       "(wrong!)\n",
-                                       diff);
-                       ret = false;
-                       break;
-               }
-               smb_msleep(1 * msec);
-       }
-
-       GET_INFO_BOTH(finfo2,pinfo2);
-       COMPARE_WRITE_TIME_EQUAL(finfo2, finfo1);
-       if (finfo2.basic_info.out.write_time == finfo1.basic_info.out.write_time) {
-               torture_comment(tctx, "Server did not update write_time (correct)\n");
-       }
-
-       /* sleep */
-       smb_msleep(3 * msec);
-
-       /* get the initial times */
-       GET_INFO_BOTH(finfo1,pinfo1);
-       COMPARE_WRITE_TIME_EQUAL(finfo1, finfo2);
-
-       /*
-        * demonstrate that a truncate write always
-        * updates the write time immediately
-        */
-       for (i=0; i < 3; i++) {
-               smb_msleep(2 * msec);
-               /* do a write */
-               torture_comment(tctx, "Do a truncate SMBwrite [%d] on the file handle\n", i);
-               written = smbcli_smbwrite(cli->tree, fnum1, "x", 512, 0);
-               if (written != 0) {
-                       torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 0", (int)written);
-                       ret = false;
-                       goto done;
-               }
-               /* get the times after the write */
-               GET_INFO_BOTH(finfo2,pinfo2);
-               COMPARE_WRITE_TIME_GREATER(finfo2, finfo1);
-               finfo1 = finfo2;
-       }
-
-       /* sleep */
-       smb_msleep(3 * msec);
-
-       GET_INFO_BOTH(finfo3,pinfo3);
-       COMPARE_WRITE_TIME_EQUAL(finfo3, finfo2);
-
-       /*
-        * the close doesn't update the write time
-        */
-       torture_comment(tctx, "Close the file handle\n");
-       smbcli_close(cli->tree, fnum1);
-       fnum1 = -1;
-
-       GET_INFO_PATH(pinfo4);
-       COMPARE_WRITE_TIME_EQUAL(pinfo4, pinfo3);
-
-       if (pinfo4.basic_info.out.write_time == pinfo3.basic_info.out.write_time) {
-               torture_comment(tctx, "Server did not update the write_time on close (correct)\n");
-       }
-
- done:
-       if (fnum1 != -1)
-               smbcli_close(cli->tree, fnum1);
-       smbcli_unlink(cli->tree, fname);
-       smbcli_deltree(cli->tree, BASEDIR);
-
-       return ret;
-}
-#endif
-
 static bool test_delay_writetime(struct torture_context *tctx,
                                 double used_delay,
                                 double normal_delay,
@@ -3264,7 +2911,11 @@ static bool test_delay_writetime(struct torture_context *tctx,
        struct timeval start;
        struct timeval end;
        double sec = used_delay / normal_delay;
-       int msec = 1000 * sec;
+       double msec = 1000 * sec;
+       double nsec = 1000 * msec;
+       double expected_delay = used_delay / nsec;
+       double min_delay = expected_delay * 0.1;
+       double max_delay = 5 * expected_delay;
        bool ret = true;
        bool ok;
 
@@ -3278,13 +2929,13 @@ static bool test_delay_writetime(struct torture_context *tctx,
         * Make sure the time doesn't change during the next 5 seconds
         */
        start = timeval_current();
-       end = timeval_add(&start, 5 * sec, 0);
+       end = timeval_add(&start, max_delay * 1.25, 0);
        while (!timeval_expired(&end)) {
                smb_msleep(1 * msec);
                torture_comment(tctx, "Check for no change\n");
                ok = get_basic_info_cb(private_data, &finfoT);
                torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
-               COMPARE_WRITE_TIME_EQUAL(finfoT, finfo0);
+               COMPARE_ALL_TIMES_EQUAL(finfoT, finfo0);
        }
 
        ok = get_basic_info_cb(private_data, &finfoT);
@@ -3304,7 +2955,7 @@ static bool test_delay_writetime(struct torture_context *tctx,
        (void)(&before_write == &after_write);
 
        start = timeval_current();
-       end = timeval_add(&start, 7 * sec, 0);
+       end = timeval_add(&start, max_delay * 2, 0);
        while (!timeval_expired(&end)) {
                struct timeval before_get;
                struct timeval after_get;
@@ -3317,24 +2968,23 @@ static bool test_delay_writetime(struct torture_context *tctx,
                (void)(&before_get == &after_get);
 
                if (finfoT.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
-                       double diff = timeval_elapsed(&start);
-                       diff = timeval_elapsed2(&before_write, &after_get);
-                       if (diff < (used_delay / (double)1000000)) {
-                               torture_result(tctx, TORTURE_FAIL, __location__": 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, "Server updated write_time after %.2f seconds "
-                                       "(correct)\n",
-                                       diff);
+                       double delayS = timeval_elapsed2(&after_write, &before_get);
+                       double delayL = timeval_elapsed2(&before_write, &after_get);
+
+                       torture_comment(tctx, "Server updated write_time after %.2f/%.2f seconds "
+                                       "(min delay == %.2f, max delay == %.2f)\n",
+                                       delayS, delayL, min_delay, max_delay);
+                       torture_assert(tctx, (delayL >= min_delay),
+                                      "Server updated write_time to early!");
+                       torture_assert(tctx, (delayS <= max_delay),
+                                      "Server didn't update write_time!");
+
+                       COMPARE_WRITE_TIME_GREATER(finfoT, finfo0);
                        break;
                }
 
-               COMPARE_WRITE_TIME_EQUAL(finfoT, finfo0);
-               smb_msleep(0.5 * msec);
+               COMPARE_ALL_TIMES_EQUAL(finfoT, finfo0);
+               smb_msleep(0.01 * msec);
        }
 
        ok = get_basic_info_cb(private_data, &finfo1);
@@ -3345,18 +2995,18 @@ static bool test_delay_writetime(struct torture_context *tctx,
         * Make sure the time doesn't change during the next 5 seconds
         */
        start = timeval_current();
-       end = timeval_add(&start, 5 * sec, 0);
+       end = timeval_add(&start, max_delay * 1.25, 0);
        while (!timeval_expired(&end)) {
                smb_msleep(1 * msec);
-               torture_comment(tctx, "Check for no change\n");
+               torture_comment(tctx, "Check for no additional change\n");
                ok = get_basic_info_cb(private_data, &finfoT);
                torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
-               COMPARE_WRITE_TIME_EQUAL(finfoT, finfo1);
+               COMPARE_ALL_TIMES_EQUAL(finfoT, finfo1);
        }
 
        ok = get_basic_info_cb(private_data, &finfoT);
        torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
-       COMPARE_WRITE_TIME_EQUAL(finfoT, finfo1);
+       COMPARE_ALL_TIMES_EQUAL(finfoT, finfo1);
 #if 0
        start = timeval_current();
        end = timeval_add(&start, 7 * sec, 0);
@@ -3491,8 +3141,10 @@ static bool test_durable_open_delaywrite1(struct torture_context *tctx,
        struct timeval start;
        struct timeval end;
        //double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", 2000000);
-       double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", 1000000);
+       //double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", 1000000);
        double normal_delay = 1000000;
+       double used_delay = torture_setting_int(tctx, "writetimeupdatedelay", normal_delay);
+       //double normal_delay = 1000000;
        //int normal_delay = 2000000;
        double sec = ((double)used_delay) / ((double)normal_delay);
        int msec = 1000 * sec;