diff options
author | Jens Axboe <jaxboe@fusionio.com> | 2010-06-24 09:59:34 +0200 |
---|---|---|
committer | Jens Axboe <jaxboe@fusionio.com> | 2010-06-24 09:59:34 +0200 |
commit | 02af09886db695e5ea2b7fd2a632733955f3c03f (patch) | |
tree | 1dfff423ded9c623ebf01aea24720800bd24f5f8 | |
parent | 2fa55e93d8895e0645df3e50baae82d15d9beea4 (diff) | |
download | fio-02af09886db695e5ea2b7fd2a632733955f3c03f.tar.gz |
Add total latency log
We log submission and completion latencies, also log total latencies.
This makes it easier to graph and make histograms, if you care only
about the complete latency.
Signed-off-by: Jens Axboe <jaxboe@fusionio.com>
-rw-r--r-- | HOWTO | 22 | ||||
-rw-r--r-- | fio.1 | 11 | ||||
-rw-r--r-- | fio.c | 7 | ||||
-rw-r--r-- | fio.h | 3 | ||||
-rwxr-xr-x | fio_generate_plots | 18 | ||||
-rw-r--r-- | init.c | 2 | ||||
-rw-r--r-- | io_u.c | 6 | ||||
-rw-r--r-- | iolog.h | 2 | ||||
-rw-r--r-- | options.c | 9 | ||||
-rw-r--r-- | stat.c | 34 |
10 files changed, 101 insertions, 13 deletions
@@ -976,15 +976,16 @@ write_bw_log=str If given, write a bandwidth log of the jobs in this job filename. For this option, the postfix is _bw.log. write_lat_log=str Same as write_bw_log, except that this option stores io - completion latencies instead. If no filename is given - with this option, the default filename of "jobname_type.log" - is used. Even if the filename is given, fio will still - append the type of log. So if one specifies + submission, completion, and total latencies instead. If no + filename is given with this option, the default filename of + "jobname_type.log" is used. Even if the filename is given, + fio will still append the type of log. So if one specifies write_lat_log=foo - The actual log names will be foo_clat.log and foo_slat.log. - This helps fio_generate_plot fine the logs automatically. + The actual log names will be foo_slat.log, foo_slat.log, + and foo_lat.log. This helps fio_generate_plot fine the logs + automatically. lockmem=int Pin down the specified amount of memory with mlock(2). Can potentially be used instead of removing memory or booting @@ -1008,18 +1009,21 @@ cpuchunks=int If the job is a CPU cycle eater, split the load into disk_util=bool Generate disk utilization statistics, if the platform supports it. Defaults to on. -disable_clat=bool Disable measurements of completion latency numbers. Useful +disable_lat=bool Disable measurements of total latency numbers. Useful only for cutting back the number of calls to gettimeofday, as that does impact performance at really high IOPS rates. Note that to really get rid of a large amount of these calls, this option must be used with disable_slat and disable_bw as well. +disable_clat=bool Disable measurements of completion latency numbers. See + disable_lat. + disable_slat=bool Disable measurements of submission latency numbers. See - disable_clat. + disable_slat. disable_bw=bool Disable measurements of throughput/bandwidth numbers. See - disable_clat. + disable_lat. gtod_reduce=bool Enable all of the gettimeofday() reducing options (disable_clat, disable_slat, disable_bw) plus reduce @@ -722,17 +722,20 @@ Same as \fBwrite_bw_log\fR, but writes I/O completion latencies. If no filename is given with this option, the default filename of "jobname_type.log" is used. Even if the filename is given, fio will still append the type of log. .TP -.B disable_clat \fR=\fPbool -Disable measurements of completion latency numbers. Useful only for cutting +.B disable_lat \fR=\fPbool +Disable measurements of total latency numbers. Useful only for cutting back the number of calls to gettimeofday, as that does impact performance at really high IOPS rates. Note that to really get rid of a large amount of these calls, this option must be used with disable_slat and disable_bw as well. .TP +.B disable_clat \fR=\fPbool +Disable measurements of submission latency numbers. See \fBdisable_lat\fR. +.TP .B disable_slat \fR=\fPbool -Disable measurements of submission latency numbers. See \fBdisable_clat\fR. +Disable measurements of submission latency numbers. See \fBdisable_lat\fR. .TP .B disable_bw_measurement \fR=\fPbool -Disable measurements of throughput/bandwidth numbers. See \fBdisable_clat\fR. +Disable measurements of throughput/bandwidth numbers. See \fBdisable_lat\fR. .TP .BI lockmem \fR=\fPint Pin the specified amount of memory with \fBmlock\fR\|(2). Can be used to @@ -1177,6 +1177,13 @@ static void *thread_main(void *data) } else finish_log(td, td->ts.bw_log, "bw"); } + if (td->ts.lat_log) { + if (td->o.lat_log_file) { + finish_log_named(td, td->ts.lat_log, + td->o.lat_log_file, "lat"); + } else + finish_log(td, td->ts.lat_log, "lat"); + } if (td->ts.slat_log) { if (td->o.lat_log_file) { finish_log_named(td, td->ts.slat_log, @@ -80,6 +80,7 @@ struct thread_stat { struct io_log *slat_log; struct io_log *clat_log; + struct io_log *lat_log; struct io_log *bw_log; /* @@ -87,6 +88,7 @@ struct thread_stat { */ struct io_stat clat_stat[2]; /* completion latency */ struct io_stat slat_stat[2]; /* submission latency */ + struct io_stat lat_stat[2]; /* total latency */ struct io_stat bw_stat[2]; /* bandwidth stats */ unsigned long long stat_io_bytes[2]; @@ -235,6 +237,7 @@ struct thread_options { unsigned int zero_buffers; unsigned int refill_buffers; unsigned int time_based; + unsigned int disable_lat; unsigned int disable_clat; unsigned int disable_slat; unsigned int disable_bw; diff --git a/fio_generate_plots b/fio_generate_plots index ff479a7d..611f49fc 100755 --- a/fio_generate_plots +++ b/fio_generate_plots @@ -68,3 +68,21 @@ if [ "$PLOT_LINE"x != "x" ]; then echo Making clat logs $PLOT_LINE echo "set title 'Completion latency - $TITLE'; set xlabel 'time (msec)'; set ylabel 'latency (msec)'; set terminal png; set output '$TITLE-clat.png'; plot " $PLOT_LINE | $GNUPLOT - fi + +PLOT_LINE="" +for i in *_lat.log; do + if [ ! -r $i ]; then + continue + fi + PT=$(echo $i | sed s/_lat.log//g) + if [ "$PLOT_LINE"x != "x" ]; then + PLOT_LINE=$PLOT_LINE", " + fi + + PLOT_LINE=$PLOT_LINE"'$i' title '$PT' with lines" +done + +if [ "$PLOT_LINE"x != "x" ]; then + echo Making lat logs $PLOT_LINE + echo "set title 'Latency - $TITLE'; set xlabel 'time (msec)'; set ylabel 'latency (msec)'; set terminal png; set output '$TITLE-lat.png'; plot " $PLOT_LINE | $GNUPLOT - +fi @@ -555,6 +555,7 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num) td->ts.clat_stat[0].min_val = td->ts.clat_stat[1].min_val = ULONG_MAX; td->ts.slat_stat[0].min_val = td->ts.slat_stat[1].min_val = ULONG_MAX; + td->ts.lat_stat[0].min_val = td->ts.lat_stat[1].min_val = ULONG_MAX; td->ts.bw_stat[0].min_val = td->ts.bw_stat[1].min_val = ULONG_MAX; td->ddir_nr = td->o.ddir_nr; @@ -573,6 +574,7 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num) goto err; if (td->o.write_lat_log) { + setup_log(&td->ts.lat_log); setup_log(&td->ts.slat_log); setup_log(&td->ts.clat_log); } @@ -1079,7 +1079,13 @@ static void io_completed(struct thread_data *td, struct io_u *io_u, if (!td->o.disable_clat || !td->o.disable_bw) lusec = utime_since(&io_u->issue_time, &icd->time); + if (!td->o.disable_lat) { + unsigned long tusec; + tusec = utime_since(&io_u->start_time, + &icd->time); + add_lat_sample(td, idx, tusec, bytes); + } if (!td->o.disable_clat) { add_clat_sample(td, idx, lusec, bytes); io_u_mark_latency(td, lusec); @@ -75,6 +75,8 @@ extern void write_iolog_close(struct thread_data *); /* * Logging */ +extern void add_lat_sample(struct thread_data *, enum fio_ddir, unsigned long, + unsigned int); extern void add_clat_sample(struct thread_data *, enum fio_ddir, unsigned long, unsigned int); extern void add_slat_sample(struct thread_data *, enum fio_ddir, unsigned long, @@ -710,6 +710,7 @@ static int str_gtod_reduce_cb(void *data, int *il) struct thread_data *td = data; int val = *il; + td->o.disable_lat = !!val; td->o.disable_clat = !!val; td->o.disable_slat = !!val; td->o.disable_bw = !!val; @@ -1792,6 +1793,14 @@ static struct fio_option options[FIO_MAX_OPTS] = { .def = "0", }, { + .name = "disable_lat", + .type = FIO_OPT_BOOL, + .off1 = td_var_offset(disable_lat), + .help = "Disable latency numbers", + .parent = "gtod_reduce", + .def = "0", + }, + { .name = "disable_clat", .type = FIO_OPT_BOOL, .off1 = td_var_offset(disable_clat), @@ -210,6 +210,22 @@ static void show_ddir_status(struct group_run_stats *rs, struct thread_stat *ts, free(minp); free(maxp); } + if (calc_lat(&ts->lat_stat[ddir], &min, &max, &mean, &dev)) { + const char *base = "(usec)"; + char *minp, *maxp; + + if (!usec_to_msec(&min, &max, &mean, &dev)) + base = "(msec)"; + + minp = num2str(min, 6, 1, 0); + maxp = num2str(max, 6, 1, 0); + + log_info(" lat %s: min=%s, max=%s, avg=%5.02f," + " stdev=%5.02f\n", base, minp, maxp, mean, dev); + + free(minp); + free(maxp); + } if (calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev)) { double p_of_agg; @@ -371,6 +387,11 @@ static void show_ddir_status_terse(struct thread_stat *ts, else log_info(";%lu;%lu;%f;%f", 0UL, 0UL, 0.0, 0.0); + if (calc_lat(&ts->lat_stat[ddir], &min, &max, &mean, &dev)) + log_info(";%lu;%lu;%f;%f", min, max, mean, dev); + else + log_info(";%lu;%lu;%f;%f", 0UL, 0UL, 0.0, 0.0); + if (calc_lat(&ts->bw_stat[ddir], &min, &max, &mean, &dev)) { double p_of_agg; @@ -498,6 +519,7 @@ void show_run_stats(void) memset(ts, 0, sizeof(*ts)); for (j = 0; j <= DDIR_WRITE; j++) { + ts->lat_stat[j].min_val = -1UL; ts->clat_stat[j].min_val = -1UL; ts->slat_stat[j].min_val = -1UL; ts->bw_stat[j].min_val = -1UL; @@ -559,6 +581,7 @@ void show_run_stats(void) for (l = 0; l <= DDIR_WRITE; l++) { sum_stat(&ts->clat_stat[l], &td->ts.clat_stat[l], idx); sum_stat(&ts->slat_stat[l], &td->ts.slat_stat[l], idx); + sum_stat(&ts->lat_stat[l], &td->ts.lat_stat[l], idx); sum_stat(&ts->bw_stat[l], &td->ts.bw_stat[l], idx); ts->stat_io_bytes[l] += td->ts.stat_io_bytes[l]; @@ -742,6 +765,17 @@ void add_slat_sample(struct thread_data *td, enum fio_ddir ddir, add_log_sample(td, ts->slat_log, usec, ddir, bs); } +void add_lat_sample(struct thread_data *td, enum fio_ddir ddir, + unsigned long usec, unsigned int bs) +{ + struct thread_stat *ts = &td->ts; + + add_stat_sample(&ts->lat_stat[ddir], usec); + + if (ts->lat_log) + add_log_sample(td, ts->lat_log, usec, ddir, bs); +} + void add_bw_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs, struct timeval *t) { |