#include <sys/types.h>
#include <sys/stat.h>
-#ifdef _UWIN
+#if defined(_UWIN) || defined(__linux__)
# include <sys/param.h>
# include <limits.h>
# include <time.h>
# include <strings.h>
+# include <sys/time.h>
#endif
#include <fcntl.h>
#include <sys/mman.h>
struct log_entry {
int operation;
+ struct timeval tv;
int args[3];
};
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 */
+char logfile[1024]; /* name of our log file */
+char goodfile[1024]; /* name of our test file */
int fd; /* fd for our test file */
off_t file_size = 0;
int fsxgoodfd = 0;
FILE * fsxlogf = NULL;
int badoff = -1;
-int closeopen = 0;
void
void
-log4(int operation, int arg0, int arg1, int arg2)
+log4(int operation, int arg0, int arg1, int arg2, struct timeval *tv)
{
struct log_entry *le;
le = &oplog[logptr];
+ le->tv = *tv;
le->operation = operation;
- if (closeopen)
- le->operation = ~ le->operation;
le->args[0] = arg0;
le->args[1] = arg1;
le->args[2] = arg2;
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: %lu.%06lu ", opnum,
+ 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 <
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 <
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] &&
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])
badoff < lp->args[!!down])
prt("\t******WWWW");
break;
+ case OP_CLOSEOPEN:
+ prt("CLOSE/OPEN");
+ break;
case OP_SKIPPED:
prt("SKIPPED (no operation)");
break;
prt("BOGUS LOG ENTRY (operation code = %d)!",
lp->operation);
}
- if (closeopen)
- prt("\n\t\tCLOSE/OPEN");
prt("\n");
i++;
if (i == LOGSIZE)
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;
}
}
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);
}
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);
}
if (n) {
prt("\t0x%5x\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);
void
doread(unsigned offset, unsigned size)
{
+ struct timeval t;
off_t ret;
unsigned iret;
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);
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);
return;
}
- log4(OP_READ, offset, size, 0);
+ log4(OP_READ, offset, size, 0, &t);
if (testcalls <= simulatedopcount)
return;
(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);
+ prt("%06lu %lu.%06lu read %#08x thru %#08x\t(0x%x bytes)\n",
+ testcalls, t.tv_sec, t.tv_usec, offset, offset + size - 1,
+ size);
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");
void
domapread(unsigned offset, unsigned size)
{
+ struct timeval t;
unsigned pg_offset;
unsigned map_size;
char *p;
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);
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);
return;
}
- log4(OP_MAPREAD, offset, size, 0);
+ log4(OP_MAPREAD, offset, size, 0, &t);
if (testcalls <= simulatedopcount)
return;
(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);
+ prt("%06lu %lu.%06lu mapread %#08x thru %#08x\t(0x%x bytes)\n",
+ testcalls, t.tv_sec, t.tv_usec, offset, offset + size - 1,
+ size);
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);
}
void
dowrite(unsigned offset, unsigned size)
{
+ struct timeval t;
off_t ret;
unsigned iret;
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);
return;
}
- log4(OP_WRITE, offset, size, file_size);
+ log4(OP_WRITE, offset, size, file_size, &t);
gendata(original_buf, good_buf, offset, size);
if (file_size < offset + size) {
(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);
+ prt("%06lu %lu.%06lu write %#08x thru %#08x\t(0x%x bytes)\n",
+ testcalls, t.tv_sec, t.tv_usec, offset, offset + size - 1,
+ size);
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");
void
domapwrite(unsigned offset, unsigned size)
{
+ struct timeval t;
unsigned pg_offset;
unsigned map_size;
off_t cur_filesize;
char *p;
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);
return;
}
cur_filesize = file_size;
- log4(OP_MAPWRITE, offset, size, 0);
+ log4(OP_MAPWRITE, offset, size, 0, &t);
gendata(original_buf, good_buf, offset, size);
if (file_size < offset + size) {
(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);
+ prt("%06lu %lu.%06lu mapwrite %#08x thru %#08x\t(0x%x bytes)\n",
+ testcalls, t.tv_sec, t.tv_usec, offset, offset + size - 1,
+ size);
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;
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);
if (size > file_size)
memset(good_buf + file_size, '\0', size - file_size);
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);
+ prt("%06lu %lu.%06lu trunc from %#08x to %#08x\n",
+ testcalls, t.tv_sec, t.tv_usec, oldsize, size);
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);
+ }
}
void
docloseopen(void)
{
+ struct timeval t;
+
if (testcalls <= simulatedopcount)
return;
+ gettimeofday(&t, NULL);
+ log4(OP_CLOSEOPEN, file_size, (unsigned)file_size, 0, &t);
+
if (debug)
- prt("%lu close/open\n", testcalls);
+ prt("%06lu %lu.%06lu close/open\n", testcalls, t.tv_sec,
+ t.tv_usec);
if (close(fd)) {
prterr("docloseopen: close");
report_failure(180);
}
+ if (!quiet && debug > 1) {
+ gettimeofday(&t, NULL);
+ prt(" %lu.%06lu close done\n", t.tv_sec, t.tv_usec);
+ }
fd = open(fname, O_RDWR, 0);
if (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);
+ }
}
testcalls++;
- if (closeprob)
- closeopen = (rv >> 3) < (1 << 28) / closeprob;
-
if (debugstart > 0 && testcalls >= debugstart)
debug = 1;
}
if (sizechecks && testcalls > simulatedopcount)
check_size();
- if (closeopen)
+ if (closeprob && (rv >> 3) < (1 << 28) / closeprob)
docloseopen();
}
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] "
+"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"
+" fname: this filename is REQUIRED (no default)\n");
exit(90);
}
}
+static const char *basename(const char *path)
+{
+ char *c = strrchr(path, '/');
+
+ return c ? c++ : path;
+}
+
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;
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();
usage();
break;
case 'd':
- debug = 1;
+ debug++;
break;
case 'l':
maxfilelen = getnum(optarg, &endp);
strcat(goodfile, "/");
strncpy(logfile, optarg, sizeof(logfile));
strcat(logfile, "/");
+ dirpath = 1;
break;
case 'R':
mapped_reads = 0;
prterr(fname);
exit(91);
}
- strncat(goodfile, fname, 256);
+ strncat(goodfile, dirpath ? 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 ? basename(fname) : fname, 256);
strcat (logfile, ".fsxlog");
fsxlogf = fopen(logfile, "w");
if (fsxlogf == NULL) {
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);
}
git://git.whamcloud.com / fs / lustre-release.git / blobdiff