summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJeremy Allison <jra@samba.org>2009-11-05 15:37:26 -0800
committerJeremy Allison <jra@samba.org>2009-11-05 15:37:26 -0800
commitc2df97f57ce205935c37cd5a90cfeddb129cd92b (patch)
tree3f5f052ff101f4d9712eab8809f0b7a5f7802484
parent5fb9d06607c46eae7e1ec4599ad59246f84bb4ee (diff)
downloadsamba-c2df97f57ce205935c37cd5a90cfeddb129cd92b.tar.gz
samba-c2df97f57ce205935c37cd5a90cfeddb129cd92b.tar.bz2
samba-c2df97f57ce205935c37cd5a90cfeddb129cd92b.zip
Fix up some of the timing constants for DELAYWRITE. Add some extra tests up test_delayed_write_update6
to investigate what happens to a sticky write handle after a second handle close. Jeremy.
-rw-r--r--source4/torture/basic/delaywrite.c144
1 files changed, 114 insertions, 30 deletions
diff --git a/source4/torture/basic/delaywrite.c b/source4/torture/basic/delaywrite.c
index 71d8cc901f..0c43c29cad 100644
--- a/source4/torture/basic/delaywrite.c
+++ b/source4/torture/basic/delaywrite.c
@@ -74,10 +74,6 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
torture_comment(tctx, "Initial write time %s\n",
nt_time_string(tctx, finfo1.basic_info.out.write_time));
- /* 3 second delay to ensure we get past any 2 second time
- granularity (older systems may have that) */
- msleep(3 * msec);
-
written = smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
if (written != 1) {
@@ -101,7 +97,7 @@ static bool test_delayed_write_update(struct torture_context *tctx, struct smbcl
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 < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds"
"(1 sec == %.2f)(wrong!)\n",
diff, sec);
@@ -182,6 +178,10 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
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) */
+ msleep(3 * msec);
+
/* Do a zero length SMBwrite call to truncate. */
written = smbcli_smbwrite(cli->tree, fnum1, "x", 1024, 0);
@@ -277,7 +277,7 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
double diff = timeval_elapsed(&start);
torture_comment(tctx, "server updated write_time after %.2f seconds"
- "(1 sec == %.2f)(correct)\n",
+ "(1 sec == %.2f)(wrong)\n",
diff, sec);
break;
}
@@ -291,6 +291,9 @@ static bool test_delayed_write_update1(struct torture_context *tctx, struct smbc
ret = false;
}
+ fflush(stdout);
+ msleep(2 * msec);
+
/* the close should trigger an write time update */
smbcli_close(cli->tree, fnum1);
fnum1 = -1;
@@ -1170,7 +1173,7 @@ static bool test_delayed_write_update2(struct torture_context *tctx, struct smbc
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 < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds"
"(1sec == %.2f) (wrong!)\n",
diff, sec);
@@ -1415,6 +1418,19 @@ static bool test_finfo_after_write(struct torture_context *tctx, struct smbcli_s
nt_time_string(tctx, finfo.basic_info.out.access_time), \
nt_time_string(tctx, finfo.basic_info.out.write_time)); \
} while (0)
+#define GET_INFO_FILE2(finfo) do { \
+ NTSTATUS _status; \
+ _status = smb_raw_fileinfo(cli2->tree, tctx, &finfo); \
+ if (!NT_STATUS_IS_OK(_status)) { \
+ ret = false; \
+ torture_result(tctx, TORTURE_FAIL, __location__": fileinfo failed: %s", \
+ nt_errstr(_status)); \
+ goto done; \
+ } \
+ torture_comment(tctx, "fileinfo: Access(%s) Write(%s)\n", \
+ nt_time_string(tctx, finfo.basic_info.out.access_time), \
+ nt_time_string(tctx, finfo.basic_info.out.write_time)); \
+} while (0)
#define GET_INFO_PATH(pinfo) do { \
NTSTATUS _status; \
_status = smb_raw_pathinfo(cli2->tree, tctx, &pinfo); \
@@ -1544,7 +1560,7 @@ static bool test_delayed_write_update3(struct torture_context *tctx,
if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
double diff = timeval_elapsed(&start);
- if (diff < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds "
"(1sec == %.2f) (wrong!)\n",
diff, sec);
@@ -1710,7 +1726,7 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
double diff = timeval_elapsed(&start);
- if (diff < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds "
"(1sec == %.2f) (wrong!)\n",
diff, sec);
@@ -1729,12 +1745,14 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
GET_INFO_BOTH(finfo1,pinfo1);
COMPARE_WRITE_TIME_GREATER(pinfo1, pinfo0);
+ msleep(3 * msec);
+
/*
* demonstrate that a truncate write always
* updates the write time immediately
*/
for (i=0; i < 3; i++) {
- msleep(1 * msec);
+ 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);
@@ -1749,6 +1767,8 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
finfo1 = finfo2;
}
+ msleep(3 * msec);
+
/* sure any further write doesn't update the write time */
start = timeval_current();
end = timeval_add(&start, 15 * sec, 0);
@@ -1772,7 +1792,7 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo2,pinfo2);
@@ -1782,7 +1802,7 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
}
/* sleep */
- msleep(5 * msec);
+ msleep(3 * msec);
/* get the initial times */
GET_INFO_BOTH(finfo1,pinfo1);
@@ -1793,7 +1813,7 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
* updates the write time immediately
*/
for (i=0; i < 3; i++) {
- msleep(1 * msec);
+ 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);
@@ -1809,7 +1829,7 @@ static bool test_delayed_write_update3a(struct torture_context *tctx,
}
/* sleep */
- msleep(5 * msec);
+ msleep(3 * msec);
GET_INFO_BOTH(finfo3,pinfo3);
COMPARE_WRITE_TIME_EQUAL(finfo3, finfo2);
@@ -1921,7 +1941,7 @@ static bool test_delayed_write_update3b(struct torture_context *tctx,
if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
double diff = timeval_elapsed(&start);
- if (diff < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds "
"(1sec == %.2f) (wrong!)\n",
diff, sec);
@@ -1963,7 +1983,7 @@ static bool test_delayed_write_update3b(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo2,pinfo2);
@@ -2073,7 +2093,7 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
* updates the write time immediately
*/
for (i=0; i < 3; i++) {
- msleep(1 * msec);
+ 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);
@@ -2110,7 +2130,7 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo2,pinfo2);
@@ -2131,7 +2151,7 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
* updates the write time immediately
*/
for (i=0; i < 3; i++) {
- msleep(1 * msec);
+ msleep(2 * msec);
/* do a write */
torture_comment(tctx, "Do a truncate write [%d] on the file handle\n", i);
written = smbcli_smbwrite(cli->tree, fnum1, "x", 512, 0);
@@ -2175,7 +2195,7 @@ static bool test_delayed_write_update3c(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo2,pinfo2);
@@ -2296,7 +2316,7 @@ static bool test_delayed_write_update4(struct torture_context *tctx,
if (finfo1.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
double diff = timeval_elapsed(&start);
- if (diff < (TIMEDELAY_SECS * sec * 0.75)) { /* 0.75 to cope with vmware timing */
+ if (diff < (TIMEDELAY_SECS * sec * 0.3)) { /* 0.3 to cope with vmware timing */
torture_comment(tctx, "Server updated write_time after %.2f seconds "
"(1sec == %.2f) (wrong!)\n",
diff, sec);
@@ -2338,7 +2358,7 @@ static bool test_delayed_write_update4(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo2,pinfo2);
@@ -2469,7 +2489,7 @@ static bool test_delayed_write_update5(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo3,pinfo3);
@@ -2501,7 +2521,7 @@ static bool test_delayed_write_update5(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo4,pinfo4);
@@ -2631,7 +2651,7 @@ static bool test_delayed_write_update5b(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo3,pinfo3);
@@ -2663,7 +2683,7 @@ static bool test_delayed_write_update5b(struct torture_context *tctx,
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo4,pinfo4);
@@ -2796,7 +2816,7 @@ again:
/* make sure the 2 second delay from the first write are canceled */
start = timeval_current();
- end = timeval_add(&start, 15 * sec, 0);
+ end = timeval_add(&start, 10 * sec, 0);
while (!timeval_expired(&end)) {
/* get the times after the first write */
@@ -2810,7 +2830,7 @@ again:
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo3,pinfo3);
@@ -2821,7 +2841,7 @@ again:
/* sure any further write doesn't update the write time */
start = timeval_current();
- end = timeval_add(&start, 15 * sec, 0);
+ end = timeval_add(&start, 10 * sec, 0);
while (!timeval_expired(&end)) {
/* do a write */
torture_comment(tctx, "Do a write on the file handle\n");
@@ -2842,7 +2862,7 @@ again:
ret = false;
break;
}
- msleep(2 * msec);
+ msleep(1 * msec);
}
GET_INFO_BOTH(finfo4,pinfo4);
@@ -2872,6 +2892,70 @@ again:
torture_comment(tctx, "Server updated the write_time on close (correct)\n");
}
+ /* See what the second write handle thinks the time is ? */
+ finfo5.basic_info.in.file.fnum = fnum2;
+ GET_INFO_FILE2(finfo5);
+ COMPARE_WRITE_TIME_EQUAL(finfo5, pinfo6);
+
+ /* See if we have lost the sticky write time on handle2 */
+ msleep(3 * msec);
+ torture_comment(tctx, "Have we lost the sticky write time ?\n");
+
+ /* Make sure any further normal write doesn't update the write time */
+ start = timeval_current();
+ end = timeval_add(&start, 10 * sec, 0);
+ while (!timeval_expired(&end)) {
+ /* do a write */
+ torture_comment(tctx, "Do a write on the second file handle\n");
+ written = smbcli_write(cli2->tree, fnum2, 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_FILE2(finfo5);
+ GET_INFO_PATH(pinfo6);
+
+ if (finfo5.basic_info.out.write_time > pinfo6.basic_info.out.write_time) {
+ double diff = timeval_elapsed(&start);
+ torture_comment(tctx, "Server updated write_time after %.2f seconds "
+ "(1sec == %.2f) (wrong!)\n",
+ diff, sec);
+ ret = false;
+ break;
+ }
+ msleep(1 * msec);
+ }
+
+ /* What about a truncate write ? */
+ start = timeval_current();
+ end = timeval_add(&start, 10 * sec, 0);
+ while (!timeval_expired(&end)) {
+ /* do a write */
+ torture_comment(tctx, "Do a truncate write on the second file handle\n");
+ written = smbcli_write(cli2->tree, fnum2, 0, "x", 0, 0);
+ if (written != 0) {
+ 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_FILE2(finfo5);
+ GET_INFO_PATH(pinfo6);
+
+ if (finfo5.basic_info.out.write_time > pinfo6.basic_info.out.write_time) {
+ double diff = timeval_elapsed(&start);
+ torture_comment(tctx, "Server updated write_time after %.2f seconds "
+ "(1sec == %.2f) (wrong!)\n",
+ diff, sec);
+ ret = false;
+ break;
+ }
+ msleep(1 * msec);
+ }
+
+
/* keep the 2nd handle open and rerun tests */
if (first) {
first = false;