From: Stefan Metzmacher <metze@samba.org>
Date: Tue, 14 Aug 2018 13:16:21 +0000 (+0200)
Subject: TODO source4/torture/smb2/durable_open.c
X-Git-Url: http://git.samba.org/?a=commitdiff_plain;h=18b68abbce9acd359d5ae08f51b9997d5b0209ae;hp=c272320ea8996686dd1d9072ceee2c56c8ee2e29;p=metze%2Fsamba%2Fwip.git

TODO source4/torture/smb2/durable_open.c
---

diff --git a/source4/torture/smb2/durable_open.c b/source4/torture/smb2/durable_open.c
index 092294ff5341..58bbe3bf648f 100644
--- a/source4/torture/smb2/durable_open.c
+++ b/source4/torture/smb2/durable_open.c
@@ -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;