X-Git-Url: https://git.whamcloud.com/?p=fs%2Flustre-release.git;a=blobdiff_plain;f=lustre%2Ftests%2Ffsx.c;h=3139866798276f7850c50146bae1f88b26baa957;hp=e7c1495ef0aed6e7c7a93b7c5e6844681276cedb;hb=7a814e94e065551ab79e2ba75df9626e4940efc5;hpb=504dcd05b6489275e14f94881ba87640b9a38f85 diff --git a/lustre/tests/fsx.c b/lustre/tests/fsx.c index e7c1495..3139866 100644 --- a/lustre/tests/fsx.c +++ b/lustre/tests/fsx.c @@ -1,6 +1,8 @@ /* * Copyright (c) 1998-2001 Apple Computer, Inc. All rights reserved. * + * Copyright (c) 2012, Intel Corporation. + * * @APPLE_LICENSE_HEADER_START@ * * The contents of this file constitute Original Code as defined in and @@ -41,6 +43,7 @@ # include # include # include +# include #endif #include #include @@ -59,15 +62,36 @@ #define NUMPRINTCOLUMNS 32 /* # columns of data to print on each line */ /* + * Each test run will work with one or more separate file descriptors for the + * same file. This allows testing cache coherency across multiple mountpoints + * of the same network filesystem on a single client. + */ +struct test_file { + char *path; + int fd; +} *test_files = NULL; + +int num_test_files; +enum fd_iteration_policy { + FD_SINGLE, + FD_ROTATE, + FD_RANDOM, +}; +int fd_policy = FD_RANDOM; +int fd_last; + +/* * A log entry is an operation and a bunch of arguments. */ struct log_entry { - int operation; - int args[3]; + int operation; + int args[3]; + struct timeval tv; + const struct test_file *tf; }; -#define LOGSIZE 1000 +#define LOGSIZE 100000 struct log_entry oplog[LOGSIZE]; /* the log */ int logptr = 0; /* current position in log */ @@ -92,22 +116,23 @@ char *original_buf; /* a pointer to the original data */ char *good_buf; /* a pointer to the correct data */ char *temp_buf; /* a pointer to the current data */ char *fname; /* name of our test file */ -int fd; /* fd for our test file */ +char logfile[1024]; /* name of our log file */ +char goodfile[1024]; /* name of our test file */ off_t file_size = 0; off_t biggest = 0; char state[256]; unsigned long testcalls = 0; /* calls to function "test" */ -unsigned long simulatedopcount = 0; /* -b flag */ +long simulatedopcount = 0; /* -b flag */ int closeprob = 0; /* -c flag */ int debug = 0; /* -d flag */ -unsigned long debugstart = 0; /* -D flag */ -unsigned long maxfilelen = 256 * 1024; /* -l flag */ +long debugstart = 0; /* -D flag */ +long maxfilelen = 256 * 1024; /* -l flag */ int sizechecks = 1; /* -n flag disables them */ int maxoplen = 64 * 1024; /* -o flag */ int quiet = 0; /* -q flag */ -unsigned long progressinterval = 0; /* -p flag */ +long progressinterval = 0; /* -p flag */ int readbdy = 1; /* -r flag */ int style = 0; /* -s flag */ int truncbdy = 1; /* -t flag */ @@ -123,7 +148,6 @@ int mapped_reads = 1; /* -R flag disables it */ int fsxgoodfd = 0; FILE * fsxlogf = NULL; int badoff = -1; -int closeopen = 0; void @@ -152,15 +176,20 @@ warn(const char * fmt, ...) void +__attribute__((format(printf, 1, 2))) prt(char *fmt, ...) { va_list args; va_start(args, fmt); vfprintf(stdout, fmt, args); - if (fsxlogf) - vfprintf(fsxlogf, fmt, args); va_end(args); + + if (fsxlogf) { + va_start(args, fmt); + vfprintf(fsxlogf, fmt, args); + va_end(args); + } } void @@ -171,23 +200,42 @@ prterr(char *prefix) void -log4(int operation, int arg0, int arg1, int arg2) +log4(int operation, int arg0, int arg1, int arg2, struct timeval *tv, + const struct test_file *tf) { struct log_entry *le; le = &oplog[logptr]; le->operation = operation; - if (closeopen) - le->operation = ~ le->operation; le->args[0] = arg0; le->args[1] = arg1; le->args[2] = arg2; + le->tv = *tv; + le->tf = tf; logptr++; logcount++; if (logptr >= LOGSIZE) logptr = 0; } +const char * +fill_tf_buf(const struct test_file *tf) +{ + static int max_tf_len; + static char tf_buf[32]; + + if (fd_policy == FD_SINGLE) + return ""; + + if (max_tf_len == 0) + max_tf_len = snprintf(tf_buf, sizeof(tf_buf) - 1, + "%u", num_test_files - 1); + + sprintf(tf_buf, "[%0*lu]", max_tf_len, + (unsigned long)(tf - test_files)); + + return tf_buf; +} void logdump(void) @@ -207,14 +255,13 @@ logdump(void) int opnum; opnum = i+1 + (logcount/LOGSIZE)*LOGSIZE; - prt("%d(%d mod 256): ", opnum, opnum%256); lp = &oplog[i]; - if ((closeopen = lp->operation < 0)) - lp->operation = ~ lp->operation; + prt("%d%s: %lu.%06lu ", opnum, fill_tf_buf(lp->tf), + lp->tv.tv_sec, lp->tv.tv_usec); switch (lp->operation) { case OP_MAPREAD: - prt("MAPREAD\t0x%x thru 0x%x\t(0x%x bytes)", + prt("MAPREAD 0x%x thru 0x%x (0x%x bytes)", lp->args[0], lp->args[0] + lp->args[1] - 1, lp->args[1]); if (badoff >= lp->args[0] && badoff < @@ -222,7 +269,7 @@ logdump(void) prt("\t***RRRR***"); break; case OP_MAPWRITE: - prt("MAPWRITE 0x%x thru 0x%x\t(0x%x bytes)", + prt("MAPWRITE 0x%x thru 0x%x (0x%x bytes)", lp->args[0], lp->args[0] + lp->args[1] - 1, lp->args[1]); if (badoff >= lp->args[0] && badoff < @@ -230,7 +277,7 @@ logdump(void) prt("\t******WWWW"); break; case OP_READ: - prt("READ\t0x%x thru 0x%x\t(0x%x bytes)", + prt("READ 0x%x thru 0x%x (0x%x bytes)", lp->args[0], lp->args[0] + lp->args[1] - 1, lp->args[1]); if (badoff >= lp->args[0] && @@ -238,7 +285,7 @@ logdump(void) prt("\t***RRRR***"); break; case OP_WRITE: - prt("WRITE\t0x%x thru 0x%x\t(0x%x bytes)", + prt("WRITE 0x%x thru 0x%x (0x%x bytes)", lp->args[0], lp->args[0] + lp->args[1] - 1, lp->args[1]); if (lp->args[0] > lp->args[2]) @@ -257,6 +304,9 @@ logdump(void) badoff < lp->args[!!down]) prt("\t******WWWW"); break; + case OP_CLOSEOPEN: + prt("CLOSE/OPEN"); + break; case OP_SKIPPED: prt("SKIPPED (no operation)"); break; @@ -264,8 +314,6 @@ logdump(void) prt("BOGUS LOG ENTRY (operation code = %d)!", lp->operation); } - if (closeopen) - prt("\n\t\tCLOSE/OPEN"); prt("\n"); i++; if (i == LOGSIZE) @@ -292,9 +340,10 @@ save_buffer(char *buffer, off_t bufferlength, int fd) if (size_by_seek == (off_t)-1) prterr("save_buffer: lseek eof"); else if (bufferlength > size_by_seek) { - warn("save_buffer: .fsxgood file too short... will -save 0x%llx bytes instead of 0x%llx\n", (unsigned long long)size_by_seek, - (unsigned long long)bufferlength); + warn("save_buffer: .fsxgood file too short... will" + "save 0x%llx bytes instead of 0x%llx\n", + (unsigned long long)size_by_seek, + (unsigned long long)bufferlength); bufferlength = size_by_seek; } } @@ -308,8 +357,8 @@ save 0x%llx bytes instead of 0x%llx\n", (unsigned long long)size_by_seek, if (byteswritten == -1) prterr("save_buffer write"); else - warn("save_buffer: short write, 0x%x bytes instead -of 0x%llx\n", + warn("save_buffer: short write, 0x%x bytes instead" + "of 0x%llx\n", (unsigned)byteswritten, (unsigned long long)bufferlength); } @@ -325,8 +374,8 @@ report_failure(int status) if (good_buf) { save_buffer(good_buf, file_size, fsxgoodfd); prt("Correct content saved for comparison\n"); - prt("(maybe hexdump \"%s\" vs \"%s.fsxgood\")\n", - fname, fname); + prt("(maybe hexdump \"%s\" vs \"%s\")\n", + fname, goodfile); } close(fsxgoodfd); } @@ -356,7 +405,7 @@ check_buffers(unsigned offset, unsigned size) if (c != t) { if (n == 0) { bad = short_at(&temp_buf[i]); - prt("0x%5x\t0x%04x\t0x%04x", offset, + prt("%#07x\t%#06x\t%#06x", offset, short_at(&good_buf[offset]), bad); op = temp_buf[offset & 1 ? i+1 : i]; } @@ -368,25 +417,124 @@ check_buffers(unsigned offset, unsigned size) size--; } if (n) { - prt("\t0x%5x\n", n); + prt("\t%#7x\n", n); if (bad) - prt("operation# (mod 256) for the bad data -may be %u\n", ((unsigned)op & 0xff)); + prt("operation# (mod 256) for the bad data" + "may be %u\n", ((unsigned)op & 0xff)); else - prt("operation# (mod 256) for the bad data -unknown, check HOLE and EXTEND ops\n"); + prt("operation# (mod 256) for the bad data" + "unknown, check HOLE and EXTEND ops\n"); } else prt("????????????????\n"); report_failure(110); } } +struct test_file * +get_tf(void) +{ + unsigned index = 0; + + switch (fd_policy) { + case FD_ROTATE: + index = fd_last++; + break; + case FD_RANDOM: + index = random(); + break; + case FD_SINGLE: + index = 0; + break; + default: + prt("unknown policy"); + exit(1); + break; + } + return &test_files[ index % num_test_files ]; +} + +void +assign_fd_policy(char *policy) +{ + if (!strcmp(policy, "random")) + fd_policy = FD_RANDOM; + else if (!strcmp(policy, "rotate")) + fd_policy = FD_ROTATE; + else { + prt("unknown -I policy: '%s'\n", policy); + exit(1); + } +} + +int +get_fd(void) +{ + struct test_file *tf = get_tf(); + return tf->fd; +} + +static const char *my_basename(const char *path) +{ + char *c = strrchr(path, '/'); + + return c ? c++ : path; +} + +void +open_test_files(char **argv, int argc) +{ + struct test_file *tf; + int i; + + num_test_files = argc; + if (num_test_files == 1) + fd_policy = FD_SINGLE; + + test_files = calloc(num_test_files, sizeof(*test_files)); + if (test_files == NULL) { + prterr("reallocating space for test files"); + exit(1); + } + + for (i = 0, tf = test_files; i < num_test_files; i++, tf++) { + + tf->path = argv[i]; + tf->fd = open(tf->path, O_RDWR|(lite ? 0 : O_CREAT|O_TRUNC), + 0666); + if (tf->fd < 0) { + prterr(tf->path); + exit(91); + } + } + + if (quiet || fd_policy == FD_SINGLE) + return; + + for (i = 0, tf = test_files; i < num_test_files; i++, tf++) + prt("fd %d: %s\n", i, tf->path); +} + +void +close_test_files(void) +{ + int i; + struct test_file *tf; + + for (i = 0, tf = test_files; i < num_test_files; i++, tf++) { + if (close(tf->fd)) { + prterr("close"); + report_failure(99); + } + } +} + void check_size(void) { struct stat statbuf; off_t size_by_seek; + int fd = get_fd(); if (fstat(fd, &statbuf)) { prterr("check_size: fstat"); @@ -407,57 +555,103 @@ void check_trunc_hack(void) { struct stat statbuf; - - ftruncate(fd, (off_t)0); - ftruncate(fd, (off_t)100000); - fstat(fd, &statbuf); + int fd = get_fd(); + + /* should not ignore ftruncate(2)'s return value */ + if (ftruncate(fd, (off_t)0) < 0) { + prterr("trunc_hack: ftruncate(0)"); + exit(1); + } + if (ftruncate(fd, (off_t)100000) < 0) { + prterr("trunc_hack: ftruncate(100000)"); + exit(1); + } + if (fstat(fd, &statbuf)) { + prterr("trunc_hack: fstat"); + statbuf.st_size = -1; + } if (statbuf.st_size != (off_t)100000) { prt("no extend on truncate! not posix!\n"); exit(130); } - ftruncate(fd, 0); + if (ftruncate(fd, 0) < 0) { + prterr("trunc_hack: ftruncate(0) (2nd call)"); + exit(1); + } } +void +output_line(struct test_file *tf, int op, unsigned offset, + unsigned size, struct timeval *tv) +{ + char *ops[] = { + [OP_READ] = "read", + [OP_WRITE] = "write", + [OP_TRUNCATE] = "trunc from", + [OP_MAPREAD] = "mapread", + [OP_MAPWRITE] = "mapwrite", + }; + + /* W. */ + if (!(!quiet && ((progressinterval && + testcalls % progressinterval == 0) || + (debug && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))))) + return; + + prt("%06lu%s %lu.%06lu %-10s %#08x %s %#08x\t(0x%x bytes)\n", + testcalls, fill_tf_buf(tf), tv->tv_sec, tv->tv_usec, + ops[op], + offset, op == OP_TRUNCATE ? " to " : "thru", + offset + size - 1, size); +} void doread(unsigned offset, unsigned size) { + struct timeval t; off_t ret; unsigned iret; + struct test_file *tf = get_tf(); + int fd = tf->fd; offset -= offset % readbdy; + gettimeofday(&t, NULL); if (size == 0) { if (!quiet && testcalls > simulatedopcount) prt("skipping zero size read\n"); - log4(OP_SKIPPED, OP_READ, offset, size); + log4(OP_SKIPPED, OP_READ, offset, size, &t, tf); return; } if (size + offset > file_size) { if (!quiet && testcalls > simulatedopcount) prt("skipping seek/read past end of file\n"); - log4(OP_SKIPPED, OP_READ, offset, size); + log4(OP_SKIPPED, OP_READ, offset, size, &t, tf); return; } - log4(OP_READ, offset, size, 0); + log4(OP_READ, offset, size, 0, &t, tf); if (testcalls <= simulatedopcount) return; - if (!quiet && ((progressinterval && - testcalls % progressinterval == 0) || - (debug && - (monitorstart == -1 || - (offset + size > monitorstart && - (monitorend == -1 || offset <= monitorend)))))) - prt("%lu read\t0x%x thru\t0x%x\t(0x%x bytes)\n", testcalls, - offset, offset + size - 1, size); + output_line(tf, OP_READ, offset, size, &t); + ret = lseek(fd, (off_t)offset, SEEK_SET); if (ret == (off_t)-1) { prterr("doread: lseek"); report_failure(140); } iret = read(fd, temp_buf, size); + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu read done\n", t.tv_sec, t.tv_usec); + } if (iret != size) { if (iret == -1) prterr("doread: read"); @@ -473,52 +667,69 @@ doread(unsigned offset, unsigned size) void domapread(unsigned offset, unsigned size) { + struct timeval t; unsigned pg_offset; unsigned map_size; char *p; + struct test_file *tf = get_tf(); + int fd = tf->fd; offset -= offset % readbdy; + gettimeofday(&t, NULL); if (size == 0) { if (!quiet && testcalls > simulatedopcount) prt("skipping zero size read\n"); - log4(OP_SKIPPED, OP_MAPREAD, offset, size); + log4(OP_SKIPPED, OP_MAPREAD, offset, size, &t, tf); return; } if (size + offset > file_size) { if (!quiet && testcalls > simulatedopcount) prt("skipping seek/read past end of file\n"); - log4(OP_SKIPPED, OP_MAPREAD, offset, size); + log4(OP_SKIPPED, OP_MAPREAD, offset, size, &t, tf); return; } - log4(OP_MAPREAD, offset, size, 0); + log4(OP_MAPREAD, offset, size, 0, &t, tf); if (testcalls <= simulatedopcount) return; - if (!quiet && ((progressinterval && - testcalls % progressinterval == 0) || - (debug && - (monitorstart == -1 || - (offset + size > monitorstart && - (monitorend == -1 || offset <= monitorend)))))) - prt("%lu mapread\t0x%x thru\t0x%x\t(0x%x bytes)\n", testcalls, - offset, offset + size - 1, size); + output_line(tf, OP_MAPREAD, offset, size, &t); pg_offset = offset & page_mask; map_size = pg_offset + size; - if ((p = (char *)mmap(0, map_size, PROT_READ, MAP_FILE | -MAP_SHARED, fd, - (off_t)(offset - pg_offset))) == (char *)-1) { + if ((p = mmap(0, map_size, PROT_READ, MAP_FILE | MAP_SHARED, fd, + (off_t)(offset - pg_offset))) == MAP_FAILED) { prterr("domapread: mmap"); report_failure(190); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu mmap done\n", t.tv_sec, t.tv_usec); + } memcpy(temp_buf, p + pg_offset, size); + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu memcpy done\n", t.tv_sec, t.tv_usec); + } if (munmap(p, map_size) != 0) { prterr("domapread: munmap"); report_failure(191); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu munmap done\n", t.tv_sec, t.tv_usec); + } check_buffers(offset, size); } @@ -539,18 +750,22 @@ gendata(char *original_buf, char *good_buf, unsigned offset, unsigned size) void dowrite(unsigned offset, unsigned size) { + struct timeval t; off_t ret; unsigned iret; + struct test_file *tf = get_tf(); + int fd = tf->fd; offset -= offset % writebdy; + gettimeofday(&t, NULL); if (size == 0) { if (!quiet && testcalls > simulatedopcount) prt("skipping zero size write\n"); - log4(OP_SKIPPED, OP_WRITE, offset, size); + log4(OP_SKIPPED, OP_WRITE, offset, size, &t, tf); return; } - log4(OP_WRITE, offset, size, file_size); + log4(OP_WRITE, offset, size, file_size, &t, tf); gendata(original_buf, good_buf, offset, size); if (file_size < offset + size) { @@ -566,20 +781,21 @@ dowrite(unsigned offset, unsigned size) if (testcalls <= simulatedopcount) return; - if (!quiet && ((progressinterval && - testcalls % progressinterval == 0) || - (debug && - (monitorstart == -1 || - (offset + size > monitorstart && - (monitorend == -1 || offset <= monitorend)))))) - prt("%lu write\t0x%x thru\t0x%x\t(0x%x bytes)\n", testcalls, - offset, offset + size - 1, size); + output_line(tf, OP_WRITE, offset, size, &t); + ret = lseek(fd, (off_t)offset, SEEK_SET); if (ret == (off_t)-1) { prterr("dowrite: lseek"); report_failure(150); } iret = write(fd, good_buf + offset, size); + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu write done\n", t.tv_sec, t.tv_usec); + } if (iret != size) { if (iret == -1) prterr("dowrite: write"); @@ -594,21 +810,25 @@ dowrite(unsigned offset, unsigned size) void domapwrite(unsigned offset, unsigned size) { + struct timeval t; unsigned pg_offset; unsigned map_size; off_t cur_filesize; char *p; + struct test_file *tf = get_tf(); + int fd = tf->fd; offset -= offset % writebdy; + gettimeofday(&t, NULL); if (size == 0) { if (!quiet && testcalls > simulatedopcount) prt("skipping zero size write\n"); - log4(OP_SKIPPED, OP_MAPWRITE, offset, size); + log4(OP_SKIPPED, OP_MAPWRITE, offset, size, &t, tf); return; } cur_filesize = file_size; - log4(OP_MAPWRITE, offset, size, 0); + log4(OP_MAPWRITE, offset, size, 0, &t, tf); gendata(original_buf, good_buf, offset, size); if (file_size < offset + size) { @@ -624,55 +844,86 @@ domapwrite(unsigned offset, unsigned size) if (testcalls <= simulatedopcount) return; - if (!quiet && ((progressinterval && - testcalls % progressinterval == 0) || - (debug && - (monitorstart == -1 || - (offset + size > monitorstart && - (monitorend == -1 || offset <= monitorend)))))) - prt("%lu mapwrite\t0x%x thru\t0x%x\t(0x%x bytes)\n", testcalls, - offset, offset + size - 1, size); + output_line(tf, OP_MAPWRITE, offset, size, &t); if (file_size > cur_filesize) { if (ftruncate(fd, file_size) == -1) { prterr("domapwrite: ftruncate"); exit(201); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu truncate done\n", t.tv_sec, t.tv_usec); + } } pg_offset = offset & page_mask; map_size = pg_offset + size; - if ((p = (char *)mmap(0, map_size, PROT_READ | PROT_WRITE, - MAP_FILE | MAP_SHARED, fd, - (off_t)(offset - pg_offset))) == (char *)-1) { + if ((p = mmap(0, map_size, PROT_READ | PROT_WRITE, MAP_FILE|MAP_SHARED, + fd, (off_t)(offset - pg_offset))) == MAP_FAILED) { prterr("domapwrite: mmap"); report_failure(202); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu mmap done\n", t.tv_sec, t.tv_usec); + } memcpy(p + pg_offset, good_buf + offset, size); + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu memcpy done\n", t.tv_sec, t.tv_usec); + } if (msync(p, map_size, 0) != 0) { prterr("domapwrite: msync"); report_failure(203); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu msync done\n", t.tv_sec, t.tv_usec); + } if (munmap(p, map_size) != 0) { prterr("domapwrite: munmap"); report_failure(204); } + if (!quiet && (debug > 1 && + (monitorstart == -1 || + (offset + size > monitorstart && + (monitorend == -1 || offset <= monitorend))))) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu munmap done\n", t.tv_sec, t.tv_usec); + } } void dotruncate(unsigned size) { + struct timeval t; int oldsize = file_size; + struct test_file *tf = get_tf(); + int fd = tf->fd; size -= size % truncbdy; + gettimeofday(&t, NULL); if (size > biggest) { biggest = size; if (!quiet && testcalls > simulatedopcount) prt("truncating to largest ever: 0x%x\n", size); } - log4(OP_TRUNCATE, size, (unsigned)file_size, 0); + log4(OP_TRUNCATE, size, (unsigned)file_size, 0, &t, tf); if (size > file_size) memset(good_buf + file_size, '\0', size - file_size); @@ -681,16 +932,17 @@ dotruncate(unsigned size) if (testcalls <= simulatedopcount) return; - if ((progressinterval && testcalls % progressinterval == 0) || - (debug && (monitorstart == -1 || monitorend == -1 || - size <= monitorend))) - prt("%lu trunc\tfrom 0x%x to 0x%x\n", testcalls, oldsize, -size); + output_line(tf, OP_TRUNCATE, oldsize, size, &t); + if (ftruncate(fd, (off_t)size) == -1) { prt("ftruncate1: %x\n", size); prterr("dotruncate: ftruncate"); report_failure(160); } + if (!quiet && debug > 1) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu trunc done\n", t.tv_sec, t.tv_usec); + } } @@ -698,6 +950,7 @@ void writefileimage() { ssize_t iret; + int fd = get_fd(); if (lseek(fd, (off_t)0, SEEK_SET) == (off_t)-1) { prterr("writefileimage: lseek"); @@ -708,8 +961,9 @@ writefileimage() if (iret == -1) prterr("writefileimage: write"); else - prt("short write: 0x%x bytes instead of 0x%llx\n", - iret, (unsigned long long)file_size); + prt("short write: 0x%lx bytes instead of 0x%llx\n", + (unsigned long)iret, + (unsigned long long)file_size); report_failure(172); } if (lite ? 0 : ftruncate(fd, file_size) == -1) { @@ -723,20 +977,35 @@ writefileimage() void docloseopen(void) { + struct timeval t; + struct test_file *tf = get_tf(); + if (testcalls <= simulatedopcount) return; + gettimeofday(&t, NULL); + log4(OP_CLOSEOPEN, file_size, (unsigned)file_size, 0, &t, tf); + if (debug) - prt("%lu close/open\n", testcalls); - if (close(fd)) { + prt("%06lu %lu.%06lu close/open\n", testcalls, t.tv_sec, + t.tv_usec); + if (close(tf->fd)) { prterr("docloseopen: close"); report_failure(180); } - fd = open(fname, O_RDWR, 0); - if (fd < 0) { + if (!quiet && debug > 1) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu close done\n", t.tv_sec, t.tv_usec); + } + tf->fd = open(tf->path, O_RDWR, 0); + if (tf->fd < 0) { prterr("docloseopen: open"); report_failure(181); } + if (!quiet && debug > 1) { + gettimeofday(&t, NULL); + prt(" %lu.%06lu open done\n", t.tv_sec, t.tv_usec); + } } @@ -758,9 +1027,6 @@ test(void) testcalls++; - if (closeprob) - closeopen = (rv >> 3) < (1 << 28) / closeprob; - if (debugstart > 0 && testcalls >= debugstart) debug = 1; @@ -807,7 +1073,7 @@ test(void) } if (sizechecks && testcalls > simulatedopcount) check_size(); - if (closeopen) + if (closeprob && (rv >> 3) < (1 << 28) / closeprob) docloseopen(); } @@ -827,33 +1093,36 @@ void usage(void) { fprintf(stdout, "usage: %s", - "fsx [-dnqLOW] [-b opnum] [-c Prob] [-l flen] [-m -start:end] [-o oplen] [-p progressinterval] [-r readbdy] [-s style] [-t -truncbdy] [-w writebdy] [-D startingop] [-N numops] [-P dirpath] [-S seed] -fname\n\ - -b opnum: beginning operation number (default 1)\n\ - -c P: 1 in P chance of file close+open at each op (default infinity)\n\ - -d: debug output for all operations\n\ - -l flen: the upper bound on file size (default 262144)\n\ - -m startop:endop: monitor (print debug output) specified byte range -(default 0:infinity)\n\ - -n: no verifications of file size\n\ - -o oplen: the upper bound on operation size (default 65536)\n\ - -p progressinterval: debug output at specified operation interval\n\ - -q: quieter operation\n\ - -r readbdy: 4096 would make reads page aligned (default 1)\n\ - -s style: 1 gives smaller truncates (default 0)\n\ - -t truncbdy: 4096 would make truncates page aligned (default 1)\n\ - -w writebdy: 4096 would make writes page aligned (default 1)\n\ - -D startingop: debug output starting at specified operation\n\ - -L: fsxLite - no file creations & no file size changes\n\ - -N numops: total # operations to do (default infinity)\n\ - -O: use oplen (see -o flag) for every op (default random)\n\ - -P: save .fsxlog and .fsxgood files in dirpath (default ./)\n\ - -S seed: for random # generator (default 1) 0 gets timestamp\n\ - -W: mapped write operations DISabled\n\ - -R: read() system calls only (mapped reads disabled)\n\ - fname: this filename is REQUIRED (no default)\n"); + "fsx [-dnqLOW] [-b opnum] [-c Prob] [-l flen] [-m " +"start:end] [-o oplen] [-p progressinterval] [-r readbdy] [-s style] [-t " +"truncbdy] [-w writebdy] [-D startingop] [-N numops] [-P dirpath] [-S seed] " +"[ -I random|rotate ] fname [additional paths to fname..]\n" +" -b opnum: beginning operation number (default 1)\n" +" -c P: 1 in P chance of file close+open at each op (default infinity)\n" +" -d: debug output for all operations [-d -d = more debugging]\n" +" -l flen: the upper bound on file size (default 262144)\n" +" -m startop:endop: monitor (print debug output) specified byte rang" +"(default 0:infinity)\n" +" -n: no verifications of file size\n" +" -o oplen: the upper bound on operation size (default 65536)\n" +" -p progressinterval: debug output at specified operation interval\n" +" -q: quieter operation\n" +" -r readbdy: 4096 would make reads page aligned (default 1)\n" +" -s style: 1 gives smaller truncates (default 0)\n" +" -t truncbdy: 4096 would make truncates page aligned (default 1)\n" +" -w writebdy: 4096 would make writes page aligned (default 1)\n" +" -D startingop: debug output starting at specified operation\n" +" -L: fsxLite - no file creations & no file size changes\n" +" -N numops: total # operations to do (default infinity)\n" +" -O: use oplen (see -o flag) for every op (default random)\n" +" -P: save .fsxlog and .fsxgood files in dirpath (default ./)\n" +" -S seed: for random # generator (default 1) 0 gets timestamp\n" +" -W: mapped write operations DISabled\n" +" -R: read() system calls only (mapped reads disabled)\n" +" -I: When multiple paths to the file are given each operation uses" +" a different path. Iterate through them in order with 'rotate'" +" or chose then at 'random'. (defaults to random)\n" +" fname: this filename is REQUIRED (no default)\n"); exit(90); } @@ -891,14 +1160,12 @@ getnum(char *s, char **e) return (ret); } - int main(int argc, char **argv) { int i, style, ch; char *endp; - char goodfile[1024]; - char logfile[1024]; + int dirpath = 0; goodfile[0] = 0; logfile[0] = 0; @@ -908,14 +1175,15 @@ main(int argc, char **argv) setvbuf(stdout, (char *)0, _IOLBF, 0); /* line buffered stdout */ - while ((ch = getopt(argc, argv, "b:c:dl:m:no:p:qr:s:t:w:D:LN:OP:RS:W")) + while ((ch = getopt(argc, argv, + "b:c:dl:m:no:p:qr:s:t:w:D:I:LN:OP:RS:W")) != EOF) switch (ch) { case 'b': simulatedopcount = getnum(optarg, &endp); if (!quiet) - fprintf(stdout, "Will begin at operation -%ld\n", + fprintf(stdout, "Will begin at operation" + "%ld\n", simulatedopcount); if (simulatedopcount == 0) usage(); @@ -931,7 +1199,7 @@ main(int argc, char **argv) usage(); break; case 'd': - debug = 1; + debug++; break; case 'l': maxfilelen = getnum(optarg, &endp); @@ -991,6 +1259,9 @@ main(int argc, char **argv) if (debugstart < 1) usage(); break; + case 'I': + assign_fd_policy(optarg); + break; case 'L': lite = 1; break; @@ -1007,6 +1278,7 @@ main(int argc, char **argv) strcat(goodfile, "/"); strncpy(logfile, optarg, sizeof(logfile)); strcat(logfile, "/"); + dirpath = 1; break; case 'R': mapped_reads = 0; @@ -1032,7 +1304,7 @@ main(int argc, char **argv) } argc -= optind; argv += optind; - if (argc != 1) + if (argc < 1) usage(); fname = argv[0]; @@ -1049,19 +1321,17 @@ main(int argc, char **argv) initstate(seed, state, 256); setstate(state); - fd = open(fname, O_RDWR|(lite ? 0 : O_CREAT|O_TRUNC), 0666); - if (fd < 0) { - prterr(fname); - exit(91); - } - strncat(goodfile, fname, 256); + + open_test_files(argv, argc); + + strncat(goodfile, dirpath ? my_basename(fname) : fname, 256); strcat (goodfile, ".fsxgood"); fsxgoodfd = open(goodfile, O_RDWR|O_CREAT|O_TRUNC, 0666); if (fsxgoodfd < 0) { prterr(goodfile); exit(92); } - strncat(logfile, fname, 256); + strncat(logfile, dirpath ? my_basename(fname) : fname, 256); strcat (logfile, ".fsxlog"); fsxlogf = fopen(logfile, "w"); if (fsxlogf == NULL) { @@ -1070,6 +1340,7 @@ main(int argc, char **argv) } if (lite) { off_t ret; + int fd = get_fd(); file_size = maxfilelen = lseek(fd, (off_t)0, SEEK_END); if (file_size == (off_t)-1) { prterr(fname); @@ -1092,6 +1363,7 @@ main(int argc, char **argv) memset(temp_buf, '\0', maxoplen); if (lite) { /* zero entire existing file */ ssize_t written; + int fd = get_fd(); written = write(fd, good_buf, (size_t)maxfilelen); if (written != maxfilelen) { @@ -1099,8 +1371,8 @@ main(int argc, char **argv) prterr(fname); warn("main: error on write"); } else - warn("main: short write, 0x%x bytes instead -of 0x%x\n", + warn("main: short write, 0x%x bytes instead" + "of 0x%x\n", (unsigned)written, maxfilelen); exit(98); } @@ -1110,10 +1382,7 @@ of 0x%x\n", while (numops == -1 || numops--) test(); - if (close(fd)) { - prterr("close"); - report_failure(99); - } + close_test_files(); prt("All operations completed A-OK!\n"); exit(0);