Pretty-up the 'make check' output

Reasonable output from 'make check' now looks roughly like this.  The
big change is the consolidation of the all the zpion test results in
to a single table which can be easily scanned for failures/problems.

==================================== ZTEST ====================================

5 vdevs, 7 datasets, 23 threads, 300 seconds...
Pass   1,  SIGKILL,   1 ENOSPC, 13.8% of  238M used,  17% done,    4m07s to go
Pass   2,  SIGKILL,   1 ENOSPC, 23.7% of  238M used,  38% done,    3m04s to go
Pass   3,  SIGKILL,   0 ENOSPC, 27.0% of  238M used,  66% done,    1m42s to go
Pass   4,  SIGKILL,   0 ENOSPC, 27.4% of  238M used,  75% done,    1m14s to go
Pass   5,  SIGKILL,   0 ENOSPC, 27.9% of  238M used,  89% done,      32s to go
Pass   6, Complete,   0 ENOSPC, 14.0% of  476M used, 100% done,       0s to go
5 killed, 1 completed, 83% kill rate

==================================== ZPIOS ====================================

status    name        id        wr-data wr-ch   wr-bw   rd-data rd-ch   rd-bw
-------------------------------------------------------------------------------
PASS:     file-raid0   0        64m     64      13.04m  64m     64    842.22m
PASS:     file-raid10  0        64m     64      134.19m 64m     64    842.22m
PASS:     file-raidz   0        64m     64      87.56m  64m     64    853.45m
PASS:     file-raidz2  0        64m     64      134.19m 64m     64    853.45m
PASS:     lo-raid0     0        64m     64      429.59m 64m     64    14.63m
PASS:     lo-raid10    0        64m     64      397.57m 64m     64    771.19m
PASS:     lo-raidz     0        64m     64      206.48m 64m     64    688.27m
PASS:     lo-raidz2    0        64m     64      14.34m  64m     64    711.21m
This commit is contained in:
Brian Behlendorf 2009-07-21 14:41:35 -07:00
parent 41c17d43e3
commit efb9868b69
10 changed files with 145 additions and 83 deletions

View File

@ -82,6 +82,7 @@ typedef struct cmd_args {
range_repeat_t S; /* Regionsize */ range_repeat_t S; /* Regionsize */
const char *pool; /* Pool */ const char *pool; /* Pool */
const char *name; /* Name */
uint32_t flags; /* Flags */ uint32_t flags; /* Flags */
uint32_t io_type; /* DMUIO only */ uint32_t io_type; /* DMUIO only */
uint32_t verbose; /* Verbose */ uint32_t verbose; /* Verbose */
@ -113,7 +114,7 @@ int set_lhi(char *pattern, range_repeat_t *range, char *optarg,
int set_noise(uint64_t *noise, char *optarg, char *arg); int set_noise(uint64_t *noise, char *optarg, char *arg);
int set_load_params(cmd_args_t *args, char *optarg); int set_load_params(cmd_args_t *args, char *optarg);
int check_mutual_exclusive_command_lines(uint32_t flag, char *arg); int check_mutual_exclusive_command_lines(uint32_t flag, char *arg);
void print_stats_header(void); void print_stats_header(cmd_args_t *args);
void print_stats(cmd_args_t *args, zpios_cmd_t *cmd); void print_stats(cmd_args_t *args, zpios_cmd_t *cmd);
#endif /* _ZPIOS_H */ #endif /* _ZPIOS_H */

View File

@ -45,7 +45,7 @@
#include "zpios.h" #include "zpios.h"
static const char short_opt[] = "t:l:h:e:n:i:j:k:o:m:q:r:c:a:b:g:s:A:B:C:" static const char short_opt[] = "t:l:h:e:n:i:j:k:o:m:q:r:c:a:b:g:s:A:B:C:"
"L:p:xP:R:G:I:N:T:VzOfHv?"; "L:p:M:xP:R:G:I:N:T:VzOfHv?";
static const struct option long_opt[] = { static const struct option long_opt[] = {
{"threadcount", required_argument, 0, 't' }, {"threadcount", required_argument, 0, 't' },
{"threadcount_low", required_argument, 0, 'l' }, {"threadcount_low", required_argument, 0, 'l' },
@ -69,6 +69,7 @@ static const struct option long_opt[] = {
{"regionsize_incr", required_argument, 0, 'C' }, {"regionsize_incr", required_argument, 0, 'C' },
{"load", required_argument, 0, 'L' }, {"load", required_argument, 0, 'L' },
{"pool", required_argument, 0, 'p' }, {"pool", required_argument, 0, 'p' },
{"name", required_argument, 0, 'M' },
{"cleanup", no_argument, 0, 'x' }, {"cleanup", no_argument, 0, 'x' },
{"prerun", required_argument, 0, 'P' }, {"prerun", required_argument, 0, 'P' },
{"postrun", required_argument, 0, 'R' }, {"postrun", required_argument, 0, 'R' },
@ -118,6 +119,7 @@ usage(void)
" --regionsize_incr -C =value\n" " --regionsize_incr -C =value\n"
" --load -L =dmuio|ssf|fpp\n" " --load -L =dmuio|ssf|fpp\n"
" --pool -p =pool name\n" " --pool -p =pool name\n"
" --name -M =test name\n"
" --cleanup -x\n" " --cleanup -x\n"
" --prerun -P =pre-command\n" " --prerun -P =pre-command\n"
" --postrun -R =post-command\n" " --postrun -R =post-command\n"
@ -255,6 +257,9 @@ args_init(int argc, char **argv)
case 'p': /* --pool */ case 'p': /* --pool */
args->pool = optarg; args->pool = optarg;
break; break;
case 'M':
args->name = optarg;
break;
case 'x': /* --cleanup */ case 'x': /* --cleanup */
args->flags |= DMU_REMOVE; args->flags |= DMU_REMOVE;
break; break;
@ -615,7 +620,7 @@ main(int argc, char **argv)
if (args->verbose) if (args->verbose)
fprintf(stdout, "%s", zpios_version); fprintf(stdout, "%s", zpios_version);
print_stats_header(); print_stats_header(args);
rc = run_thread_counts(args); rc = run_thread_counts(args);
out: out:
if (args != NULL) if (args != NULL)

View File

@ -293,7 +293,7 @@ check_mutual_exclusive_command_lines(uint32_t flag, char *arg)
return 0; return 0;
} }
if ((flag & (FLAG_LOW | FLAG_HIGH | FLAG_INCR)) && !(flag & FLAG_SET)) { if ((flag & (FLAG_LOW | FLAG_HIGH | FLAG_INCR)) && !(flag & FLAG_SET)){
if (flag != (FLAG_LOW | FLAG_HIGH | FLAG_INCR)) { if (flag != (FLAG_LOW | FLAG_HIGH | FLAG_INCR)) {
fprintf(stderr, "Error: One or more values missing " fprintf(stderr, "Error: One or more values missing "
"from --%s_low, --%s_high, --%s_incr.\n", "from --%s_low, --%s_high, --%s_incr.\n",
@ -306,14 +306,24 @@ check_mutual_exclusive_command_lines(uint32_t flag, char *arg)
} }
void void
print_stats_header(void) print_stats_header(cmd_args_t *args)
{ {
printf("ret-code id\tth-cnt\trg-cnt\trg-sz\tch-sz\toffset\trg-no\tch-no\t" if (args->verbose) {
"th-dly\tflags\ttime\tcr-time\trm-time\twr-time\t" printf("status name id\tth-cnt\trg-cnt\trg-sz\t"
"rd-time\twr-data\twr-ch\twr-bw\trd-data\trd-ch\trd-bw\n"); "ch-sz\toffset\trg-no\tch-no\tth-dly\tflags\ttime\t"
printf("------------------------------------------------------------" "cr-time\trm-time\twr-time\trd-time\twr-data\twr-ch\t"
"------------------------------------------------------------" "wr-bw\trd-data\trd-ch\trd-bw\n");
"-----------------------------------------------------------\n"); printf("------------------------------------------------"
"------------------------------------------------"
"------------------------------------------------"
"----------------------------------------------\n");
} else {
printf("status name id\t"
"wr-data\twr-ch\twr-bw\t"
"rd-data\trd-ch\trd-bw\n");
printf("-----------------------------------------"
"--------------------------------------\n");
}
} }
static void static void
@ -324,11 +334,14 @@ print_stats_human_readable(cmd_args_t *args, zpios_cmd_t *cmd)
char str[KMGT_SIZE]; char str[KMGT_SIZE];
if (args->rc) if (args->rc)
printf("FAILED: %3d ", args->rc); printf("FAIL: %3d ", args->rc);
else else
printf("PASSED: %3d ", args->rc); printf("PASS: ");
printf("%u\t", cmd->cmd_id); printf("%-12s", args->name ? args->name : ZPIOS_NAME);
printf("%2u\t", cmd->cmd_id);
if (args->verbose) {
printf("%u\t", cmd->cmd_thread_count); printf("%u\t", cmd->cmd_thread_count);
printf("%u\t", cmd->cmd_region_count); printf("%u\t", cmd->cmd_region_count);
printf("%s\t", uint64_to_kmgt(str, cmd->cmd_region_size)); printf("%s\t", uint64_to_kmgt(str, cmd->cmd_region_size));
@ -338,6 +351,7 @@ print_stats_human_readable(cmd_args_t *args, zpios_cmd_t *cmd)
printf("%s\t", uint64_to_kmgt(str, cmd->cmd_chunk_noise)); printf("%s\t", uint64_to_kmgt(str, cmd->cmd_chunk_noise));
printf("%s\t", uint64_to_kmgt(str, cmd->cmd_thread_delay)); printf("%s\t", uint64_to_kmgt(str, cmd->cmd_thread_delay));
printf("%s\t", print_flags(str, cmd->cmd_flags)); printf("%s\t", print_flags(str, cmd->cmd_flags));
}
if (args->rc) { if (args->rc) {
printf("\n"); printf("\n");
@ -351,11 +365,13 @@ print_stats_human_readable(cmd_args_t *args, zpios_cmd_t *cmd)
cr_time = zpios_timespec_to_double(summary_stats->cr_time.delta); cr_time = zpios_timespec_to_double(summary_stats->cr_time.delta);
rm_time = zpios_timespec_to_double(summary_stats->rm_time.delta); rm_time = zpios_timespec_to_double(summary_stats->rm_time.delta);
if (args->verbose) {
printf("%.2f\t", t_time); printf("%.2f\t", t_time);
printf("%.3f\t", cr_time); printf("%.3f\t", cr_time);
printf("%.3f\t", rm_time); printf("%.3f\t", rm_time);
printf("%.2f\t", wr_time); printf("%.2f\t", wr_time);
printf("%.2f\t", rd_time); printf("%.2f\t", rd_time);
}
printf("%s\t", uint64_to_kmgt(str, summary_stats->wr_data)); printf("%s\t", uint64_to_kmgt(str, summary_stats->wr_data));
printf("%s\t", uint64_to_kmgt(str, summary_stats->wr_chunks)); printf("%s\t", uint64_to_kmgt(str, summary_stats->wr_chunks));
@ -374,11 +390,14 @@ print_stats_table(cmd_args_t *args, zpios_cmd_t *cmd)
double wr_time, rd_time; double wr_time, rd_time;
if (args->rc) if (args->rc)
printf("FAILED: %3d ", args->rc); printf("FAIL: %3d ", args->rc);
else else
printf("PASSED: %3d ", args->rc); printf("PASS: ");
printf("%u\t", cmd->cmd_id); printf("%-12s", args->name ? args->name : ZPIOS_NAME);
printf("%2u\t", cmd->cmd_id);
if (args->verbose) {
printf("%u\t", cmd->cmd_thread_count); printf("%u\t", cmd->cmd_thread_count);
printf("%u\t", cmd->cmd_region_count); printf("%u\t", cmd->cmd_region_count);
printf("%llu\t", (long long unsigned)cmd->cmd_region_size); printf("%llu\t", (long long unsigned)cmd->cmd_region_size);
@ -388,6 +407,7 @@ print_stats_table(cmd_args_t *args, zpios_cmd_t *cmd)
printf("%u\t", cmd->cmd_chunk_noise); printf("%u\t", cmd->cmd_chunk_noise);
printf("%u\t", cmd->cmd_thread_delay); printf("%u\t", cmd->cmd_thread_delay);
printf("0x%x\t", cmd->cmd_flags); printf("0x%x\t", cmd->cmd_flags);
}
if (args->rc) { if (args->rc) {
printf("\n"); printf("\n");
@ -398,6 +418,7 @@ print_stats_table(cmd_args_t *args, zpios_cmd_t *cmd)
wr_time = zpios_timespec_to_double(summary_stats->wr_time.delta); wr_time = zpios_timespec_to_double(summary_stats->wr_time.delta);
rd_time = zpios_timespec_to_double(summary_stats->rd_time.delta); rd_time = zpios_timespec_to_double(summary_stats->rd_time.delta);
if (args->verbose) {
printf("%ld.%02ld\t", printf("%ld.%02ld\t",
(long)summary_stats->total_time.delta.ts_sec, (long)summary_stats->total_time.delta.ts_sec,
(long)summary_stats->total_time.delta.ts_nsec); (long)summary_stats->total_time.delta.ts_nsec);
@ -413,6 +434,7 @@ print_stats_table(cmd_args_t *args, zpios_cmd_t *cmd)
printf("%ld.%02ld\t", printf("%ld.%02ld\t",
(long)summary_stats->rd_time.delta.ts_sec, (long)summary_stats->rd_time.delta.ts_sec,
(long)summary_stats->rd_time.delta.ts_nsec); (long)summary_stats->rd_time.delta.ts_nsec);
}
printf("%lld\t", (long long unsigned)summary_stats->wr_data); printf("%lld\t", (long long unsigned)summary_stats->wr_data);
printf("%lld\t", (long long unsigned)summary_stats->wr_chunks); printf("%lld\t", (long long unsigned)summary_stats->wr_chunks);

View File

@ -7,14 +7,25 @@ ZTEST=${top_builddir}/cmd/ztest/ztest
ZPIOS=${top_srcdir}/scripts/zpios.sh ZPIOS=${top_srcdir}/scripts/zpios.sh
check: check:
$(ZFS) -v @$(ZFS) -v
$(ZTEST) -V @echo
$(ZPIOS) -c file-raid0 -t tiny @echo -n "===================================="
$(ZPIOS) -c file-raid10 -t tiny @echo -n " ZTEST "
$(ZPIOS) -c file-raidz -t tiny @echo "===================================="
$(ZPIOS) -c file-raidz2 -t tiny @echo
$(ZPIOS) -c lo-raid0 -t tiny @$(ZTEST) -V
$(ZPIOS) -c lo-raid10 -t tiny @echo
$(ZPIOS) -c lo-raidz -t tiny @echo -n "===================================="
$(ZPIOS) -c lo-raidz2 -t tiny @echo -n " ZPIOS "
$(ZFS) -vu @echo "===================================="
@echo
@$(ZPIOS) -c file-raid0 -t tiny
@$(ZPIOS) -c file-raid10 -t tiny | tail -1
@$(ZPIOS) -c file-raidz -t tiny | tail -1
@$(ZPIOS) -c file-raidz2 -t tiny | tail -1
@$(ZPIOS) -c lo-raid0 -t tiny | tail -1
@$(ZPIOS) -c lo-raid10 -t tiny | tail -1
@$(ZPIOS) -c lo-raidz -t tiny | tail -1
@$(ZPIOS) -c lo-raidz2 -t tiny | tail -1
@echo
@$(ZFS) -vu

View File

@ -23,6 +23,7 @@
# --regionsize_incr -C =value # --regionsize_incr -C =value
# --load -L =dmuio|ssf|fpp # --load -L =dmuio|ssf|fpp
# --pool -p =pool name # --pool -p =pool name
# --name -M =test name
# --cleanup -x # --cleanup -x
# --prerun -P =pre-command # --prerun -P =pre-command
# --postrun -R =post-command # --postrun -R =post-command
@ -40,21 +41,25 @@
ZPIOS_CMD="${CMDDIR}/zpios/zpios \ ZPIOS_CMD="${CMDDIR}/zpios/zpios \
--load=dmuio \ --load=dmuio \
--pool=${ZPOOL_NAME} \ --pool=${ZPOOL_NAME} \
--name=${ZPOOL_CONFIG} \
--threadcount=16 \ --threadcount=16 \
--regioncount=8192 \ --regioncount=8192 \
--regionsize=4M \ --regionsize=4M \
--chunksize=1M \ --chunksize=1M \
--offset=4M \ --offset=4M \
--cleanup \ --cleanup \
--verbose \
--human-readable \ --human-readable \
${ZPIOS_OPTIONS}" ${ZPIOS_OPTIONS}"
zpios_start() { zpios_start() {
if [ ${VERBOSE} ]; then
ZPIOS_CMD="${ZPIOS_CMD} --verbose"
echo ${ZPIOS_CMD} echo ${ZPIOS_CMD}
fi
${ZPIOS_CMD} || exit 1 ${ZPIOS_CMD} || exit 1
} }
zpios_stop() { zpios_stop() {
echo [ ${VERBOSE} ] && echo
} }

View File

@ -23,6 +23,7 @@
# --regionsize_incr -C =value # --regionsize_incr -C =value
# --load -L =dmuio|ssf|fpp # --load -L =dmuio|ssf|fpp
# --pool -p =pool name # --pool -p =pool name
# --name -M =test name
# --cleanup -x # --cleanup -x
# --prerun -P =pre-command # --prerun -P =pre-command
# --postrun -R =post-command # --postrun -R =post-command
@ -41,21 +42,25 @@
ZPIOS_CMD="${CMDDIR}/zpios/zpios \ ZPIOS_CMD="${CMDDIR}/zpios/zpios \
--load=dmuio \ --load=dmuio \
--pool=${ZPOOL_NAME} \ --pool=${ZPOOL_NAME} \
--name=${ZPOOL_CONFIG} \
--threadcount=1 \ --threadcount=1 \
--regioncount=16 \ --regioncount=16 \
--regionsize=4M \ --regionsize=4M \
--chunksize=1M \ --chunksize=1M \
--offset=4M \ --offset=4M \
--cleanup \ --cleanup \
--verbose \
--human-readable \ --human-readable \
${ZPIOS_OPTIONS}" ${ZPIOS_OPTIONS}"
zpios_start() { zpios_start() {
if [ ${VERBOSE} ]; then
ZPIOS_CMD="${ZPIOS_CMD} --verbose"
echo ${ZPIOS_CMD} echo ${ZPIOS_CMD}
fi
${ZPIOS_CMD} || exit 1 ${ZPIOS_CMD} || exit 1
} }
zpios_stop() { zpios_stop() {
echo [ ${VERBOSE} ] && echo
} }

View File

@ -23,6 +23,7 @@
# --regionsize_incr -C =value # --regionsize_incr -C =value
# --load -L =dmuio|ssf|fpp # --load -L =dmuio|ssf|fpp
# --pool -p =pool name # --pool -p =pool name
# --name -M =test name
# --cleanup -x # --cleanup -x
# --prerun -P =pre-command # --prerun -P =pre-command
# --postrun -R =post-command # --postrun -R =post-command
@ -40,21 +41,25 @@
ZPIOS_CMD="${CMDDIR}/zpios/zpios \ ZPIOS_CMD="${CMDDIR}/zpios/zpios \
--load=dmuio \ --load=dmuio \
--pool=${ZPOOL_NAME} \ --pool=${ZPOOL_NAME} \
--name=${ZPOOL_CONFIG} \
--threadcount=1,2,4,8,16,32,64,128,256 \ --threadcount=1,2,4,8,16,32,64,128,256 \
--regioncount=65536 \ --regioncount=65536 \
--regionsize=4M \ --regionsize=4M \
--chunksize=1M \ --chunksize=1M \
--offset=4M \ --offset=4M \
--cleanup \ --cleanup \
--verbose \
--human-readable \ --human-readable \
${ZPIOS_OPTIONS}" ${ZPIOS_OPTIONS}"
zpios_start() { zpios_start() {
if [ ${VERBOSE} ]; then
ZPIOS_CMD="${ZPIOS_CMD} --verbose"
echo ${ZPIOS_CMD} echo ${ZPIOS_CMD}
fi
${ZPIOS_CMD} || exit 1 ${ZPIOS_CMD} || exit 1
} }
zpios_stop() { zpios_stop() {
echo [ ${VERBOSE} ] && echo
} }

View File

@ -23,6 +23,7 @@
# --regionsize_incr -C =value # --regionsize_incr -C =value
# --load -L =dmuio|ssf|fpp # --load -L =dmuio|ssf|fpp
# --pool -p =pool name # --pool -p =pool name
# --name -M =test name
# --cleanup -x # --cleanup -x
# --prerun -P =pre-command # --prerun -P =pre-command
# --postrun -R =post-command # --postrun -R =post-command
@ -40,21 +41,25 @@
ZPIOS_CMD="${CMDDIR}/zpios/zpios \ ZPIOS_CMD="${CMDDIR}/zpios/zpios \
--load=dmuio \ --load=dmuio \
--pool=${ZPOOL_NAME} \ --pool=${ZPOOL_NAME} \
--name=${ZPOOL_CONFIG} \
--threadcount=256 \ --threadcount=256 \
--regioncount=65536 \ --regioncount=65536 \
--regionsize=4M \ --regionsize=4M \
--chunksize=1M \ --chunksize=1M \
--offset=4M \ --offset=4M \
--cleanup \ --cleanup \
--verbose \
--human-readable \ --human-readable \
${ZPIOS_OPTIONS}" ${ZPIOS_OPTIONS}"
zpios_start() { zpios_start() {
if [ ${VERBOSE} ]; then
ZPIOS_CMD="${ZPIOS_CMD} --verbose"
echo ${ZPIOS_CMD} echo ${ZPIOS_CMD}
fi
${ZPIOS_CMD} || exit 1 ${ZPIOS_CMD} || exit 1
} }
zpios_stop() { zpios_stop() {
echo [ ${VERBOSE} ] && echo
} }

View File

@ -23,6 +23,7 @@
# --regionsize_incr -C =value # --regionsize_incr -C =value
# --load -L =dmuio|ssf|fpp # --load -L =dmuio|ssf|fpp
# --pool -p =pool name # --pool -p =pool name
# --name -M =test name
# --cleanup -x # --cleanup -x
# --prerun -P =pre-command # --prerun -P =pre-command
# --postrun -R =post-command # --postrun -R =post-command
@ -40,21 +41,25 @@
ZPIOS_CMD="${CMDDIR}/zpios/zpios \ ZPIOS_CMD="${CMDDIR}/zpios/zpios \
--load=dmuio \ --load=dmuio \
--pool=${ZPOOL_NAME} \ --pool=${ZPOOL_NAME} \
--name=${ZPOOL_CONFIG} \
--threadcount=4 \ --threadcount=4 \
--regioncount=1024 \ --regioncount=1024 \
--regionsize=4M \ --regionsize=4M \
--chunksize=1M \ --chunksize=1M \
--offset=4M \ --offset=4M \
--cleanup \ --cleanup \
--verbose \
--human-readable \ --human-readable \
${ZPIOS_OPTIONS}" ${ZPIOS_OPTIONS}"
zpios_start() { zpios_start() {
if [ ${VERBOSE} ]; then
ZPIOS_CMD="${ZPIOS_CMD} --verbose"
echo ${ZPIOS_CMD} echo ${ZPIOS_CMD}
fi
${ZPIOS_CMD} || exit 1 ${ZPIOS_CMD} || exit 1
} }
zpios_stop() { zpios_stop() {
echo [ ${VERBOSE} ] && echo
} }

View File

@ -233,8 +233,6 @@ if [ ${PROFILE} ]; then
zpios_profile_start zpios_profile_start
fi fi
echo
echo "${DATE}"
zpios_start zpios_start
zpios_stop zpios_stop