[PATCHES] make delaywrite torture tests more reliable (part 1)

Michael Adam obnox at samba.org
Thu Oct 2 09:31:06 MDT 2014


Attached find a first patchset to make our delaywrite
torture tests more reliable.

This patchset treats the first group of tests
that essentially check whether the write time
is immediately updated by the server after a
truncation/expansion operation.

There was a potentially false failure condition
in these tests, where a long running fileinfo
call would let torture think the server did
not update the time immediately. This was a
frequent cause of failure in autobuild.
It should be gone now.

The patches treat each of the functions separately,
also doing some additional cleanup work.

Review/Comment/push appreciated!

More patches for the other test cases to follow...

Cheers -  Michael

PS: patches also in my master-torture-for-review branch:
https://git.samba.org/?p=obnox/samba/samba-obnox.git;a=shortlog;h=refs/heads/master-torture-for-review


-------------- next part --------------
From 8861354edee2290f1016d1fb9d272c711548172b Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:02:48 +0200
Subject: [PATCH 01/29] torture: add torture_assert_int_not_equal

Signed-off-by: Michael Adam <obnox at samba.org>
---
 lib/torture/torture.h | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/lib/torture/torture.h b/lib/torture/torture.h
index 3a08042..e6f323a 100644
--- a/lib/torture/torture.h
+++ b/lib/torture/torture.h
@@ -414,6 +414,16 @@ void torture_result(struct torture_context *test,
 	} \
 	} while(0)
 
+#define torture_assert_int_not_equal(torture_ctx,got,not_expected,cmt)\
+	do { int __got = (got), __not_expected = (not_expected); \
+	if (__got == __not_expected) { \
+		torture_result(torture_ctx, TORTURE_FAIL, \
+			__location__": "#got" was %d (0x%X), expected a different number: %s", \
+			__got, __got, cmt); \
+		return false; \
+	} \
+	} while(0)
+
 #define torture_assert_u64_equal(torture_ctx,got,expected,cmt)\
 	do { uint64_t __got = (got), __expected = (expected); \
 	if (__got != __expected) { \
-- 
1.9.1


From 9e8de7e36e4dfe944971c3e103a38d2ebaeb3a64 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:03:05 +0200
Subject: [PATCH 02/29] torture: add torture_assert_u64_not_equal()

Signed-off-by: Michael Adam <obnox at samba.org>
---
 lib/torture/torture.h | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/lib/torture/torture.h b/lib/torture/torture.h
index e6f323a..d6a9217 100644
--- a/lib/torture/torture.h
+++ b/lib/torture/torture.h
@@ -449,6 +449,17 @@ void torture_result(struct torture_context *test,
 	} \
 	} while(0)
 
+#define torture_assert_u64_not_equal(torture_ctx,got,not_expected,cmt)\
+	do { uint64_t __got = (got), __not_expected = (not_expected); \
+	if (__got == __not_expected) { \
+		torture_result(torture_ctx, TORTURE_FAIL, \
+			__location__": "#got" was %llu (0x%llX), expected a different number: %s", \
+			(unsigned long long)__got, (unsigned long long)__got, \
+			cmt); \
+		return false; \
+	} \
+	} while(0)
+
 #define torture_assert_errno_equal(torture_ctx,expected,cmt)\
 	do { int __expected = (expected); \
 	if (errno != __expected) { \
-- 
1.9.1


From ce83b987d0d148dc086b86798a1a577968d1589a Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:17:13 +0200
Subject: [PATCH 03/29] s4:torture:basic: whitespace cleanup in
 delayed_write_update

git diff -w shows no diff

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 12d95e2..3c1b48c 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -65,9 +65,9 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
 	status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
-	
-	torture_comment(tctx, "Initial write time %s\n", 
-	       nt_time_string(tctx, finfo1.basic_info.out.write_time));
+
+	torture_comment(tctx, "Initial write time %s\n",
+			nt_time_string(tctx, finfo1.basic_info.out.write_time));
 
 	written =  smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
 
@@ -88,8 +88,8 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
 			ret = false;
 			break;
 		}
-		torture_comment(tctx, "write time %s\n", 
-		       nt_time_string(tctx, finfo2.basic_info.out.write_time));
+		torture_comment(tctx, "write time %s\n",
+			nt_time_string(tctx, finfo2.basic_info.out.write_time));
 		if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
 			double diff = timeval_elapsed(&start);
 			if (diff < (used_delay / (double)1000000)) {
-- 
1.9.1


From def5d4af345685eac74b78af7477ffd1bc9bb9dd Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:19:49 +0200
Subject: [PATCH 04/29] s4:torture:basic: use torture_assert macros in
 delayed_write_update

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 53 ++++++++++++++++----------------------
 1 file changed, 22 insertions(+), 31 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 3c1b48c..a49329c 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -53,52 +53,44 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
 	torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
 
 	fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-	if (fnum1 == -1) {
-		torture_result(tctx, TORTURE_FAIL, "Failed to open %s", fname);
-		return false;
-	}
+	torture_assert_int_not_equal(tctx, fnum1, -1, talloc_asprintf(tctx,
+				     "Failed to open %s", fname));
 
 	finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
 	finfo1.basic_info.in.file.fnum = fnum1;
 	finfo2 = finfo1;
 
 	status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
-
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
 	torture_comment(tctx, "Initial write time %s\n",
 			nt_time_string(tctx, finfo1.basic_info.out.write_time));
 
 	written =  smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
-
-	if (written != 1) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "write failed - wrote %d bytes (%s)\n", 
-					   (int)written, __location__);
-		return false;
-	}
+	torture_assert_int_equal(tctx, written, 1,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (120 * sec), 0);
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
+
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo2.basic_info.out.write_time));
-		if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
+
+		if (finfo1.basic_info.out.write_time !=
+		    finfo2.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"
-						"(expected > %.2f) (wrong!)\n",
-						diff, used_delay / (double)1000000);
-				ret = false;
-				break;
-			}
+
+			torture_assert(tctx,
+				       diff >= (used_delay / (double)1000000),
+				       talloc_asprintf(tctx,
+					"Server updated write_time after %.2f "
+					"seconds (expected >= %.2f)\n",
+					diff, used_delay/(double)1000000));
 
 			torture_comment(tctx, "Server updated write_time after %.2f seconds (correct)\n",
 					diff);
@@ -107,13 +99,12 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
-	
-	if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server did not update write time (wrong!)");
-		ret = false;
-	}
 
+	torture_assert_u64_not_equal(tctx,
+				     finfo2.basic_info.out.write_time,
+				     finfo1.basic_info.out.write_time,
+				     "Server did not update write time within "
+				     "120 seconds");
 
 	if (fnum1 != -1)
 		smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From 342005799bbebd8c6f0b2f4dce6c111879c65bae Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 14:53:01 +0200
Subject: [PATCH 05/29] s4:torture:basic: remove two unused variables from
 delayed_write_update3c

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index a49329c..ba874a4 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -1994,8 +1994,8 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
 				        struct smbcli_state *cli,
 				        struct smbcli_state *cli2)
 {
-	union smb_fileinfo finfo0, finfo1, finfo2, finfo3, finfo4;
-	union smb_fileinfo pinfo0, pinfo1, pinfo2, pinfo3, pinfo4, pinfo5;
+	union smb_fileinfo finfo0, finfo1, finfo2, finfo3;
+	union smb_fileinfo pinfo0, pinfo1, pinfo2, pinfo3, pinfo4;
 	const char *fname = BASEDIR "\\torture_file3c.txt";
 	int fnum1 = -1;
 	bool ret = true;
@@ -2025,14 +2025,12 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
 	finfo1 = finfo0;
 	finfo2 = finfo0;
 	finfo3 = finfo0;
-	finfo4 = finfo0;
 	pinfo0.basic_info.level = RAW_FILEINFO_BASIC_INFO;
 	pinfo0.basic_info.in.file.path = fname;
 	pinfo1 = pinfo0;
 	pinfo2 = pinfo0;
 	pinfo3 = pinfo0;
 	pinfo4 = pinfo0;
-	pinfo5 = pinfo0;
 
 	/* get the initial times */
 	GET_INFO_BOTH(finfo0,pinfo0);
-- 
1.9.1


From f64dd95e2c353003b6f61ff3d81af8d6d94be746 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:25:34 +0200
Subject: [PATCH 06/29] s4:torture:basic: whitespace fix in
 delayed_write_update1

No diff with git diff -w

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index ba874a4..05183d9 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -158,8 +158,8 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-	torture_comment(tctx, "Initial write time %s\n", 
-	       nt_time_string(tctx, finfo1.all_info.out.write_time));
+	torture_comment(tctx, "Initial write time %s\n",
+			nt_time_string(tctx, finfo1.all_info.out.write_time));
 
 	/* 3 second delay to ensure we get past any 2 second time
 	   granularity (older systems may have that) */
@@ -195,7 +195,7 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo2.all_info.out.write_time));
+			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))) {
@@ -255,7 +255,7 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo3.all_info.out.write_time));
+			nt_time_string(tctx, finfo3.all_info.out.write_time));
 		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
 			double diff = timeval_elapsed(&start);
 
-- 
1.9.1


From 0a94a92b3c0b330d6cdf38043a64822cb2baf586 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:35:09 +0200
Subject: [PATCH 07/29] s4:torture:basic: make use of torture_assert macros in
 delayed_write_update1

No logic change except for adding early returns.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 84 +++++++++++++-------------------------
 1 file changed, 28 insertions(+), 56 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 05183d9..8294fea 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -135,10 +135,8 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 	torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
 
 	fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-	if (fnum1 == -1) {
-		torture_result(tctx, TORTURE_FAIL, "Failed to open %s", fname);
-		return false;
-	}
+	torture_assert_int_not_equal(tctx, fnum1, -1, talloc_asprintf(tctx,
+				     "Failed to open %s", fname));
 
 	memset(buf, 'x', 2048);
 	written =  smbcli_write(cli->tree, fnum1, 0, buf, 0, 2048);
@@ -167,32 +165,19 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 	/* Do a zero length SMBwrite call to truncate. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 1024, 0);
-
-	if (written != 0) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "write failed - wrote %d bytes (%s)\n",
-					   (int)written, __location__);
-		return false;
-	}
+	torture_assert_int_equal(tctx, written, 0,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (120 * sec), 0);
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo2.all_info.out.size != 1024) {
-			torture_result(tctx, TORTURE_FAIL, 
-						   "file not truncated, size = %u (should be 1024)",
-				(unsigned int)finfo2.all_info.out.size);
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo2.all_info.out.size, 1024,
+					 "file not truncated to expected size "
+					 "(1024)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo2.all_info.out.write_time));
@@ -217,42 +202,29 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo1.all_info.out.write_time == finfo2.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server did not update write time (wrong!)");
-		ret = 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");
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
 
 	/* Do a non-zero length SMBwrite and make sure it doesn't update the write time. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 0, 1);
-
-	if (written != 1) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "write failed - wrote %d bytes (%s)",
-					   (int)written, __location__);
-		return false;
-	}
+	torture_assert_int_equal(tctx, written, 1,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (10*sec), 0);
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo3);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo3.all_info.out.size != 1024) {
-			DEBUG(0, ("file not truncated, size = %u (should be 1024)\n",
-				(unsigned int)finfo3.all_info.out.size));
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo3.all_info.out.size, 1024,
+					 "file not truncated to expected size "
+					 "(1024)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
@@ -268,11 +240,10 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server updated write time (wrong!)");
-		ret = false;
-	}
+	torture_assert_u64_equal(tctx,
+				 finfo3.all_info.out.write_time,
+				 finfo2.all_info.out.write_time,
+				 "Server updated write time (wrong!)");
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
@@ -284,11 +255,12 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 	status = smb_raw_pathinfo(cli->tree, tctx, &pinfo4);
 	torture_assert_ntstatus_ok(tctx, status, "pathinfo failed");
 
-	if (finfo3.all_info.out.write_time == pinfo4.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL,
-					   "Server did not update write time on close (wrong!)");
-		ret = false;
-	} else if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
+	torture_assert_u64_not_equal(tctx,
+				     pinfo4.all_info.out.write_time,
+				     finfo3.all_info.out.write_time,
+				     "Server did not update write time on "
+				     "close (wrong!)");
+	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
 		torture_comment(tctx, "Server updated write time on close (correct)\n");
 	}
 
-- 
1.9.1


From 8011620f8d02e6f727a83ee3c7feba41289a1e2b Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:52:57 +0200
Subject: [PATCH 08/29] s4:torture:basic: add update into past as error
 condition in delayed_write_update1

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 8294fea..759f68e 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -260,9 +260,12 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 				     finfo3.all_info.out.write_time,
 				     "Server did not update write time on "
 				     "close (wrong!)");
-	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
-		torture_comment(tctx, "Server updated write time on close (correct)\n");
-	}
+	torture_assert(tctx,
+		pinfo4.all_info.out.write_time > finfo3.all_info.out.write_time,
+		"Server updated write time on close, but to an earlier point "
+		"in time");
+
+	torture_comment(tctx, "Server updated write time on close (correct)\n");
 
 	if (fnum1 != -1)
 		smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From cab09a1d21a6cefa551b793b3f96c92382abfe33 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:32:41 +0200
Subject: [PATCH 09/29] s4:torture:basic: add check for size after initial
 write to delayed_write_update1

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 759f68e..284fa92 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -156,6 +156,9 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
+	torture_assert_u64_equal(tctx, finfo1.all_info.out.size, 2048,
+				 "file size not as expected after write(2048)");
+
 	torture_comment(tctx, "Initial write time %s\n",
 			nt_time_string(tctx, finfo1.all_info.out.write_time));
 
-- 
1.9.1


From a243c9904875a4d535f60400a1dc380d54105a64 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:58:05 +0200
Subject: [PATCH 10/29] s4:torture:basic: use assert in the second loop in
 delayed_write_update1

We can hence replace the assert after the loop by a success torture_comment.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 21 ++++++++++-----------
 1 file changed, 10 insertions(+), 11 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 284fa92..a7a837a 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -231,22 +231,21 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
-		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-			double diff = timeval_elapsed(&start);
 
-			torture_comment(tctx, "server updated write_time after %.2f seconds"
-					"(wrong)\n",
-					diff);
-			break;
-		}
+		torture_assert_u64_equal(tctx,
+					 finfo3.all_info.out.write_time,
+					 finfo2.all_info.out.write_time,
+					 talloc_asprintf(tctx,
+						"Server updated write time "
+						"after %.2f seconds (wrong!)",
+						timeval_elapsed(&start)));
+
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
 
-	torture_assert_u64_equal(tctx,
-				 finfo3.all_info.out.write_time,
-				 finfo2.all_info.out.write_time,
-				 "Server updated write time (wrong!)");
+	torture_comment(tctx, "Server did not update write time within 10 "
+			"seconds. Good!\n", timeval_elapsed(&start));
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
-- 
1.9.1


From 9c114ebd33763050f409ce97e2dffd75817d2cc5 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:11:27 +0200
Subject: [PATCH 11/29] s4:torture:basic: eliminate potential for false
 failures in delayed_write_update1

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 at samba.org>
---
 source4/torture/basic/delaywrite.c | 36 ++++++++++++++++++------------------
 1 file changed, 18 insertions(+), 18 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index a7a837a..3b97458 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -129,6 +129,8 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 	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_update1\n");
 
@@ -173,6 +175,8 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 	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);
 
@@ -184,31 +188,27 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
 
 		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 SMBwrite truncate "
-					"server updated write_time after %.2f seconds"
-					"(write time update dealy == %.2f)(wrong!)\n",
-					       diff, used_delay / (double)1000000);
-				ret = false;
-				break;
-			}
 
-			torture_comment(tctx, "After SMBwrite truncate "
-					"server updated write_time after %.2f seconds"
-					"(1 sec == %.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);
-- 
1.9.1


From 8303c7cb02b624045e76493ef5fc1a4988d64e0c Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:32:59 +0200
Subject: [PATCH 12/29] s4:torture:basic: fix spacing in the
 delayed_write_update1a test.

No diff visible with git diff -w

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 3b97458..595fe10 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -324,8 +324,8 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-	torture_comment(tctx, "Initial write time %s\n", 
-	       nt_time_string(tctx, finfo1.all_info.out.write_time));
+	torture_comment(tctx, "Initial write time %s\n",
+			nt_time_string(tctx, finfo1.all_info.out.write_time));
 
 	/* Do a zero length SMBwrite call to truncate. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 10240, 0);
@@ -357,7 +357,7 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo2.all_info.out.write_time));
+			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))) {
@@ -391,8 +391,8 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 	/* Do a non-zero length SMBwrite and make sure it doesn't update the write time. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 0, 1);
 
-	torture_assert_int_equal(tctx, written, 1, 
-							 "unexpected number of bytes written");
+	torture_assert_int_equal(tctx, written, 1,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (10*sec), 0);
@@ -415,7 +415,7 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo3.all_info.out.write_time));
+			nt_time_string(tctx, finfo3.all_info.out.write_time));
 		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
 			double diff = timeval_elapsed(&start);
 
-- 
1.9.1


From 1904b201f8365f9f74eb4072c13e5376a2b5608b Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:37:02 +0200
Subject: [PATCH 13/29] s4:torture:basic: make use of torture_assert macros in
 delayed_write_update1a

This does not change the logic except for adding early
returns in failure cases.
But it makes the code more compact and obvious.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 77 +++++++++++++-------------------------
 1 file changed, 27 insertions(+), 50 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 595fe10..3f19c4d 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -301,10 +301,8 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 	torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
 
 	fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-	if (fnum1 == -1) {
-		torture_result(tctx, TORTURE_FAIL, "Failed to open %s", fname);
-		return false;
-	}
+	torture_assert_int_not_equal(tctx, fnum1, -1, talloc_asprintf(tctx,
+				     "Failed to open %s", fname));
 
 	memset(buf, 'x', 2048);
 	written =  smbcli_write(cli->tree, fnum1, 0, buf, 0, 2048);
@@ -330,31 +328,19 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 	/* Do a zero length SMBwrite call to truncate. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 10240, 0);
 
-	if (written != 0) {
-		torture_result(tctx, TORTURE_FAIL, "write failed - wrote %d bytes (%s)",
-		       (int)written, __location__);
-		return false;
-	}
+	torture_assert_int_equal(tctx, written, 0,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (120*sec), 0);
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			torture_result(tctx, TORTURE_FAIL, "fileinfo failed: %s", 
-						   nt_errstr(status));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo2.all_info.out.size != 10240) {
-			torture_result(tctx, TORTURE_FAIL, 
-						   "file not truncated, size = %u (should be 10240)",
-				(unsigned int)finfo2.all_info.out.size);
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo2.all_info.out.size, 10240,
+					 "file not truncated to expected size "
+					 "(10240)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo2.all_info.out.write_time));
@@ -373,17 +359,17 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 					"server updated write_time after %.2f seconds"
 					"(write time update delay == %.2f)(correct)\n",
 					diff, used_delay / (double)1000000);
+
 			break;
 		}
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo1.all_info.out.write_time == finfo2.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server did not update write time (wrong!)");
-		ret = false;
-	}
+	torture_assert_u64_not_equal(tctx,
+				     finfo1.all_info.out.write_time,
+				     finfo2.all_info.out.write_time,
+				     "Server did not update write time.");
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
@@ -399,20 +385,11 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo3);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			torture_result(tctx, TORTURE_FAIL, "fileinfo failed: %s\n", 
-						   nt_errstr(status));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo3.all_info.out.size != 10240) {
-			torture_result(tctx, TORTURE_FAIL, 
-						   "file not truncated, size = %u (should be 10240)",
-						   (unsigned int)finfo3.all_info.out.size);
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo3.all_info.out.size, 10240,
+					 "file not truncated to expected size "
+					 "(10240)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
@@ -428,11 +405,10 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server updated write time (wrong!)");
-		ret = false;
-	}
+	torture_assert_int_equal(tctx,
+				 finfo3.all_info.out.write_time,
+				 finfo2.all_info.out.write_time,
+				 "Server updated write time (wrong!)");
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
@@ -441,11 +417,12 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 	status = smb_raw_pathinfo(cli->tree, tctx, &pinfo4);
 	torture_assert_ntstatus_ok(tctx, status, "pathinfo failed");
 
-	if (finfo3.all_info.out.write_time == pinfo4.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server did not update write time on close (wrong!)");
-		ret = false;
-	} else if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
+	torture_assert_u64_not_equal(tctx,
+				     pinfo4.all_info.out.write_time,
+				     finfo3.all_info.out.write_time,
+				     "Server did not update write time on "
+				     "close (wrong!)");
+	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
 		torture_comment(tctx, "Server updated write time on close (correct)\n");
 	}
 
-- 
1.9.1


From edc40e8503d93d8151950d8af3e6e1ecac404838 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 15:49:07 +0200
Subject: [PATCH 14/29] s4:torture:basic: add update into past as error
 condition in delayed_write_update1a

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 3f19c4d..cac9dfb 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -422,9 +422,12 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 				     finfo3.all_info.out.write_time,
 				     "Server did not update write time on "
 				     "close (wrong!)");
-	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
-		torture_comment(tctx, "Server updated write time on close (correct)\n");
-	}
+	torture_assert(tctx,
+		pinfo4.all_info.out.write_time > finfo3.all_info.out.write_time,
+		"Server updated write time on close, but to an earlier point "
+		"in time");
+
+	torture_comment(tctx, "Server updated write time on close (correct)\n");
 
 	if (fnum1 != -1)
 		smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From db479b5a54571d53ae7cc097b4a65ed71a85ecfa Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:33:13 +0200
Subject: [PATCH 15/29] s4:torture:basic: add check for size after initial
 write in delayed_write_update1a

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index cac9dfb..aef8c61 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -322,6 +322,9 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
+	torture_assert_u64_equal(tctx, finfo1.all_info.out.size, 2048,
+				 "file size not as expected after write(2048)");
+
 	torture_comment(tctx, "Initial write time %s\n",
 			nt_time_string(tctx, finfo1.all_info.out.write_time));
 
-- 
1.9.1


From c27c4227fa7d1b51058e39323f5ea92d13f9af1c Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:46:29 +0200
Subject: [PATCH 16/29] s4:torture:basic: use assert in the second loop in
 delayed_write_update1a

We can hence replace the assert after the loop by a success torture_comment.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 21 ++++++++++-----------
 1 file changed, 10 insertions(+), 11 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index aef8c61..88642e3 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -396,22 +396,21 @@ static bool test_delayed_write_update1a(struct torture_context *tctx, struct smb
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
-		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-			double diff = timeval_elapsed(&start);
 
-			torture_result(tctx, TORTURE_FAIL, "server updated write_time after %.2f seconds"
-					"(write time update delay == %.2f)(correct)\n",
-					diff, used_delay / (double)1000000);
-			break;
-		}
+		torture_assert_u64_equal(tctx,
+					 finfo3.all_info.out.write_time,
+					 finfo2.all_info.out.write_time,
+					 talloc_asprintf(tctx,
+						"Server updated write time "
+						"after %.2f seconds (wrong!)",
+						timeval_elapsed(&start)));
+
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
 
-	torture_assert_int_equal(tctx,
-				 finfo3.all_info.out.write_time,
-				 finfo2.all_info.out.write_time,
-				 "Server updated write time (wrong!)");
+	torture_comment(tctx, "Server did not update write time within 10 "
+			"seconds. Good!\n", timeval_elapsed(&start));
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From f00d2d7ffaea2905fc3427a87cff70bb8cdd6144 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 13:56:43 +0200
Subject: [PATCH 17/29] s4:torture:basic: eliminate potential for false
 failures in delayed_write_update1a

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 at samba.org>
---
 source4/torture/basic/delaywrite.c | 37 ++++++++++++++++++-------------------
 1 file changed, 18 insertions(+), 19 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 88642e3..e80d2b3 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -295,6 +295,8 @@ static bool test_delayed_write_update1a(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_update1a\n");
 
@@ -336,6 +338,8 @@ static bool test_delayed_write_update1a(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);
 
@@ -347,32 +351,27 @@ static bool test_delayed_write_update1a(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 SMBwrite 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 SMBwrite 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,
-				     finfo1.all_info.out.write_time,
-				     finfo2.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);
-- 
1.9.1


From a67b4fd07c0db6825d3fc878a87593e88af4e7bf Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:34:19 +0200
Subject: [PATCH 18/29] s4:torture:basic: whitespace cleanup in
 delayed_write_update1b

no diff with git diff -w

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index e80d2b3..432482c 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -486,7 +486,7 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
 	torture_comment(tctx, "Initial write time %s\n",
-	       nt_time_string(tctx, finfo1.all_info.out.write_time));
+		nt_time_string(tctx, finfo1.all_info.out.write_time));
 
 	/* Do a SET_END_OF_FILE_INFO call to truncate. */
 	status = smbcli_ftruncate(cli->tree, fnum1, (uint64_t)10240);
@@ -513,7 +513,7 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo2.all_info.out.write_time));
+			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))) {
@@ -548,8 +548,8 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	/* Do a non-zero length SMBwrite and make sure it doesn't update the write time. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 0, 1);
 
-	torture_assert_int_equal(tctx, written, 1, 
-							 "unexpected number of bytes written");
+	torture_assert_int_equal(tctx, written, 1,
+				 "unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (10*sec), 0);
@@ -571,7 +571,7 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo3.all_info.out.write_time));
+			nt_time_string(tctx, finfo3.all_info.out.write_time));
 		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
 			double diff = timeval_elapsed(&start);
 
-- 
1.9.1


From b9040ebddbaaac48336c0f1348aaddf82b07a729 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:40:26 +0200
Subject: [PATCH 19/29] s4:torture:basic: make use of torture_assert macros in
 delayed_write_update1b

This does not change the logic except for adding early
returns in failure cases.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 65 ++++++++++++++------------------------
 1 file changed, 24 insertions(+), 41 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 432482c..c39f91f 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -462,10 +462,8 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
 
 	fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-	if (fnum1 == -1) {
-		torture_result(tctx, TORTURE_FAIL, "Failed to open %s", fname);
-		return false;
-	}
+	torture_assert_int_not_equal(tctx, fnum1, -1, talloc_asprintf(tctx,
+				     "Failed to open %s", fname));
 
 	memset(buf, 'x', 2048);
 	written =  smbcli_write(cli->tree, fnum1, 0, buf, 0, 2048);
@@ -498,19 +496,11 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo2.all_info.out.size != 10240) {
-			torture_result(tctx, TORTURE_FAIL,
-						   "file not truncated (size = %u, should be 10240)",
-						   (unsigned int)finfo2.all_info.out.size );
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo2.all_info.out.size, 10240,
+					 "file not truncated to expected size "
+					 "(10240)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo2.all_info.out.write_time));
@@ -536,11 +526,10 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo1.all_info.out.write_time == finfo2.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL,
-					   "Server did not update write time (wrong!)");
-		ret = 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");
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
@@ -556,19 +545,11 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo3);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			torture_result(tctx, TORTURE_FAIL,
-						   "fileinfo failed: %s", nt_errstr(status));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo3.all_info.out.size != 10240) {
-			DEBUG(0, ("file not truncated (size = %u, should be 10240)\n",
-				(unsigned int)finfo3.all_info.out.size ));
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo3.all_info.out.size, 10240,
+					 "file not truncated to expected size "
+					 "(10240)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
@@ -584,10 +565,10 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, "Server updated write time (wrong!)\n");
-		ret = false;
-	}
+	torture_assert_u64_equal(tctx,
+				 finfo3.all_info.out.write_time,
+				 finfo2.all_info.out.write_time,
+				 "Server updated write time");
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
@@ -596,10 +577,12 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 	status = smb_raw_pathinfo(cli->tree, tctx, &pinfo4);
 	torture_assert_ntstatus_ok(tctx, status, "pathinfo failed");
 
-	if (finfo3.all_info.out.write_time == pinfo4.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, "Server did not update write time on close (wrong!)\n");
-		ret = false;
-	} else if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
+	torture_assert_u64_not_equal(tctx,
+				     pinfo4.all_info.out.write_time,
+				     finfo3.all_info.out.write_time,
+				     "Server did not update write time on "
+				     "close (wrong!)");
+	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
 		torture_comment(tctx, "Server updated write time on close (correct)\n");
 	}
 
-- 
1.9.1


From e95350fa1204d238eac26d5db9d594e983d903e8 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:44:34 +0200
Subject: [PATCH 20/29] s4:torture:basic: add update into past as error
 condition in delayed_write_update1b

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index c39f91f..57e2f50 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -582,9 +582,12 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 				     finfo3.all_info.out.write_time,
 				     "Server did not update write time on "
 				     "close (wrong!)");
-	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
-		torture_comment(tctx, "Server updated write time on close (correct)\n");
-	}
+	torture_assert(tctx,
+		pinfo4.all_info.out.write_time > finfo3.all_info.out.write_time,
+		"Server updated write time on close, but to an earlier point "
+		"in time");
+
+	torture_comment(tctx, "Server updated write time on close (correct)\n");
 
 	if (fnum1 != -1)
 		smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From 44379b7e4b261275fa54f0f312a6da04320d227b Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:53:26 +0200
Subject: [PATCH 21/29] s4:torture:basic: add check for size after initial
 write in delayed_write_update1b

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 57e2f50..995cee8 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -483,6 +483,9 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
+	torture_assert_u64_equal(tctx, finfo1.all_info.out.size, 2048,
+				 "file size not as expected after write(2048)");
+
 	torture_comment(tctx, "Initial write time %s\n",
 		nt_time_string(tctx, finfo1.all_info.out.write_time));
 
-- 
1.9.1


From ec6b81c875b634bdc99dc40a8cb5b68365cecb7b Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:46:18 +0200
Subject: [PATCH 22/29] s4:torture:basic: use assert in the second loop in
 delayed_write_update1b

We can hence replace the assert after the loop by a success torture_comment.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 21 ++++++++++-----------
 1 file changed, 10 insertions(+), 11 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 995cee8..302850f 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -556,22 +556,21 @@ static bool test_delayed_write_update1b(struct torture_context *tctx, struct smb
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
-		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-			double diff = timeval_elapsed(&start);
 
-			torture_comment(tctx, "server updated write_time after %.2f seconds"
-					"(write time update delay == %.2f)(correct)\n",
-					diff, used_delay / (double)1000000);
-			break;
-		}
+		torture_assert_u64_equal(tctx,
+					 finfo3.all_info.out.write_time,
+					 finfo2.all_info.out.write_time,
+					 talloc_asprintf(tctx,
+						"Server updated write time "
+						"after %.2f seconds (wrong!)",
+						timeval_elapsed(&start)));
+
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
 
-	torture_assert_u64_equal(tctx,
-				 finfo3.all_info.out.write_time,
-				 finfo2.all_info.out.write_time,
-				 "Server updated write time");
+	torture_comment(tctx, "Server did not update write time within 10 "
+			"seconds. Good!\n", timeval_elapsed(&start));
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From 5e04da382c1dba4676491e2670b1e629d4463f57 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 16:48:40 +0200
Subject: [PATCH 23/29] s4:torture:basic: eliminate potential for false
 failures in delayed_write_update1b

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 at samba.org>
---
 source4/torture/basic/delaywrite.c | 37 ++++++++++++++++++-------------------
 1 file changed, 18 insertions(+), 19 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 302850f..33fad04 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -456,6 +456,8 @@ static bool test_delayed_write_update1b(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_update1b\n");
 
@@ -496,6 +498,8 @@ static bool test_delayed_write_update1b(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);
 
@@ -507,32 +511,27 @@ static bool test_delayed_write_update1b(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_END_OF_FILE truncate "
-					"server updated write_time after %.2f seconds"
-					"(write time update delay == %.2f)(wrong!)",
-					diff, used_delay / (double)1000000);
-				ret = false;
-				break;
-			}
 
-			torture_comment(tctx, "After SET_END_OF_FILE 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);
-- 
1.9.1


From e8a0dbf9fe4a599464f8b549d532ce0fcd0100c5 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:02:38 +0200
Subject: [PATCH 24/29] s4:torture:basic: whitespace cleanup in
 delayed_write_update1c

no diff with git diff -w

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 33fad04..e422c23 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -646,7 +646,7 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
 	torture_comment(tctx, "Initial write time %s\n",
-	       nt_time_string(tctx, finfo1.all_info.out.write_time));
+		nt_time_string(tctx, finfo1.all_info.out.write_time));
 
 	/* Do a SET_ALLOCATION_SIZE call to truncate. */
 	parms.allocation_info.level = RAW_SFILEINFO_ALLOCATION_INFO;
@@ -655,8 +655,8 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
 	status = smb_raw_setfileinfo(cli->tree, &parms);
 
-	torture_assert_ntstatus_ok(tctx, status, 
-							   "RAW_SFILEINFO_ALLOCATION_INFO failed");
+	torture_assert_ntstatus_ok(tctx, status,
+				   "RAW_SFILEINFO_ALLOCATION_INFO failed");
 
 	start = timeval_current();
 	end = timeval_add(&start, (120*sec), 0);
@@ -679,7 +679,7 @@ 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));
+			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))) {
@@ -712,8 +712,8 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
 	/* Do a non-zero length SMBwrite and make sure it doesn't update the write time. */
 	written = smbcli_smbwrite(cli->tree, fnum1, "x", 0, 1);
-	torture_assert_int_equal(tctx, written, 1, 
-							 "Unexpected number of bytes written");
+	torture_assert_int_equal(tctx, written, 1,
+				 "Unexpected number of bytes written");
 
 	start = timeval_current();
 	end = timeval_add(&start, (10*sec), 0);
@@ -734,7 +734,7 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 		}
 
 		torture_comment(tctx, "write time %s\n",
-		       nt_time_string(tctx, finfo3.all_info.out.write_time));
+			nt_time_string(tctx, finfo3.all_info.out.write_time));
 		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
 			double diff = timeval_elapsed(&start);
 
-- 
1.9.1


From e0b9e4178c59646764815d1d58f4506633632cac Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:08:12 +0200
Subject: [PATCH 25/29] s4:torture:basic: make use of torture_assert macros in
 delayed_write_update1c

This does not change the logic except for adding early
returns in failure cases.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 65 ++++++++++++++------------------------
 1 file changed, 23 insertions(+), 42 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index e422c23..1ffa57c 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -622,10 +622,8 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 	torture_assert(tctx, torture_setup_dir(cli, BASEDIR), "Failed to setup up test directory: " BASEDIR);
 
 	fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
-	if (fnum1 == -1) {
-		torture_result(tctx, TORTURE_FAIL, "Failed to open %s", fname);
-		return false;
-	}
+	torture_assert_int_not_equal(tctx, fnum1, -1, talloc_asprintf(tctx,
+				     "Failed to open %s", fname));
 
 	memset(buf, 'x', 2048);
 	written =  smbcli_write(cli->tree, fnum1, 0, buf, 0, 2048);
@@ -663,20 +661,11 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			torture_result(tctx, TORTURE_FAIL, "fileinfo failed: %s", 
-						   nt_errstr(status));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo2.all_info.out.size != 0) {
-			torture_result(tctx, TORTURE_FAIL, 
-						   "file not truncated (size = %u, should be 10240)",
-				(unsigned int)finfo2.all_info.out.size);
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo2.all_info.out.size, 0,
+					 "file not truncated to expected size "
+					 "(0)");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo2.all_info.out.write_time));
@@ -701,11 +690,10 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo1.all_info.out.write_time == finfo2.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server did not update write time (wrong!)");
-		ret = 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");
 
 	fflush(stdout);
 	smb_msleep(2 * msec);
@@ -720,18 +708,10 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 	while (!timeval_expired(&end)) {
 		status = smb_raw_fileinfo(cli->tree, tctx, &finfo3);
 
-		if (!NT_STATUS_IS_OK(status)) {
-			torture_result(tctx, TORTURE_FAIL, "fileinfo failed: %s", 
-						   nt_errstr(status));
-			ret = false;
-			break;
-		}
+		torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
-		if (finfo3.all_info.out.size != 1) {
-			torture_result(tctx, TORTURE_FAIL, "file not expanded");
-			ret = false;
-			break;
-		}
+		torture_assert_u64_equal(tctx, finfo3.all_info.out.size, 1,
+					 "file not expaneded");
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
@@ -747,11 +727,10 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 		smb_msleep(1 * msec);
 	}
 
-	if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, 
-					   "Server updated write time (wrong!)");
-		ret = false;
-	}
+	torture_assert_u64_equal(tctx,
+				 finfo3.all_info.out.write_time,
+				 finfo2.all_info.out.write_time,
+				 "Server updated write time (wrong!)");
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
@@ -760,10 +739,12 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 	status = smb_raw_pathinfo(cli->tree, tctx, &pinfo4);
 	torture_assert_ntstatus_ok(tctx, status, "pathinfo failed");
 
-	if (finfo3.all_info.out.write_time == pinfo4.all_info.out.write_time) {
-		torture_result(tctx, TORTURE_FAIL, "Server did not update write time on close (wrong!)\n");
-		ret = false;
-	} else if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
+	torture_assert_u64_not_equal(tctx,
+				     pinfo4.all_info.out.write_time,
+				     finfo3.all_info.out.write_time,
+				     "Server did not update write time on "
+				     "close (wrong!)");
+	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
 		torture_comment(tctx, "Server updated write time on close (correct)\n");
 	}
 
-- 
1.9.1


From 462eda952fcc78bc58b444fa082925176341b851 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:09:18 +0200
Subject: [PATCH 26/29] s4:torture:basic: add update into past as error
 condition in delayed_write_update1c

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 1ffa57c..6d28157 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -744,9 +744,10 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 				     finfo3.all_info.out.write_time,
 				     "Server did not update write time on "
 				     "close (wrong!)");
-	if (finfo3.all_info.out.write_time < pinfo4.all_info.out.write_time) {
-		torture_comment(tctx, "Server updated write time on close (correct)\n");
-	}
+	torture_assert(tctx,
+		pinfo4.all_info.out.write_time > finfo3.all_info.out.write_time,
+		"Server updated write time on close, but to an earlier point "
+		"in time");
 
 	if (fnum1 != -1)
 		smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From 96b9d6e8ef1e725092c9d3314c26600a7b8bcd8a Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:10:32 +0200
Subject: [PATCH 27/29] s4:torture:basic: add check for size after initial
 write in delayed_write_update1c

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 6d28157..d13d755 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -643,6 +643,9 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
 	torture_assert_ntstatus_ok(tctx, status, "fileinfo failed");
 
+	torture_assert_u64_equal(tctx, finfo1.all_info.out.size, 2048,
+				 "file size not as expected after write(2048)");
+
 	torture_comment(tctx, "Initial write time %s\n",
 		nt_time_string(tctx, finfo1.all_info.out.write_time));
 
-- 
1.9.1


From e7c0ae2cdc3acad010c3b5eba5059558eee54a7a Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:13:21 +0200
Subject: [PATCH 28/29] s4:torture:basic: use assert in the second loop in
 delayed_write_update1b

We can hence replace the assert after the loop by a success torture_comment.

Signed-off-by: Michael Adam <obnox at samba.org>
---
 source4/torture/basic/delaywrite.c | 21 ++++++++++-----------
 1 file changed, 10 insertions(+), 11 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index d13d755..62f7971 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -718,22 +718,21 @@ static bool test_delayed_write_update1c(struct torture_context *tctx, struct smb
 
 		torture_comment(tctx, "write time %s\n",
 			nt_time_string(tctx, finfo3.all_info.out.write_time));
-		if (finfo2.all_info.out.write_time != finfo3.all_info.out.write_time) {
-			double diff = timeval_elapsed(&start);
 
-			torture_comment(tctx, "server updated write_time after %.2f seconds"
-					"(write time update delay == %.2f)(wrong)\n",
-					diff, used_delay / (double)1000000);
-			break;
-		}
+		torture_assert_u64_equal(tctx,
+					 finfo3.all_info.out.write_time,
+					 finfo2.all_info.out.write_time,
+					 talloc_asprintf(tctx,
+						"Server updated write time "
+						"after %.2f seconds (wrong!)",
+						timeval_elapsed(&start)));
+
 		fflush(stdout);
 		smb_msleep(1 * msec);
 	}
 
-	torture_assert_u64_equal(tctx,
-				 finfo3.all_info.out.write_time,
-				 finfo2.all_info.out.write_time,
-				 "Server updated write time (wrong!)");
+	torture_comment(tctx, "Server did not update write time within 10 "
+			"seconds. Good!\n");
 
 	/* the close should trigger an write time update */
 	smbcli_close(cli->tree, fnum1);
-- 
1.9.1


From e541e9f6015e1188bc78b39b6daa0084251e6bc1 Mon Sep 17 00:00:00 2001
From: Michael Adam <obnox at samba.org>
Date: Thu, 2 Oct 2014 17:15:04 +0200
Subject: [PATCH 29/29] s4:torture:basic: eliminate potential for false
 failures in delayed_write_update1c

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 at samba.org>
---
 source4/torture/basic/delaywrite.c | 36 ++++++++++++++++++------------------
 1 file changed, 18 insertions(+), 18 deletions(-)

diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 62f7971..6efe47b 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -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);
-- 
1.9.1

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: Digital signature
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20141002/c4e3110b/attachment-0001.pgp>


More information about the samba-technical mailing list