summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJens Axboe <axboe@suse.de>2005-12-07 19:40:29 +0100
committerJens Axboe <axboe@suse.de>2005-12-07 19:40:29 +0100
commit28f0d681668aaccb4f4a937b7771c313662685b0 (patch)
tree2fe75d19c00392cd7737f077ecb61764b44a72a4
parent19ec784771d707cde23b6f494b36cc84e673cf63 (diff)
[PATCH] fio: split up and improve output stats
-rw-r--r--fio-ini.c6
-rw-r--r--fio.c243
-rw-r--r--fio.h25
3 files changed, 167 insertions, 107 deletions
diff --git a/fio-ini.c b/fio-ini.c
index 748a29c..093b9b3 100644
--- a/fio-ini.c
+++ b/fio-ini.c
@@ -206,9 +206,9 @@ static int add_job(struct thread_data *td, const char *jobname, int prioclass,
sem_init(&td->mutex, 0, 0);
- td->clat_stat.min_val = ULONG_MAX;
- td->slat_stat.min_val = ULONG_MAX;
- td->bw_stat.min_val = ULONG_MAX;
+ td->clat_stat[0].min_val = td->clat_stat[1].min_val = ULONG_MAX;
+ td->slat_stat[0].min_val = td->slat_stat[1].min_val = ULONG_MAX;
+ td->bw_stat[0].min_val = td->bw_stat[1].min_val = ULONG_MAX;
if (td->min_bs == -1U)
td->min_bs = td->bs;
diff --git a/fio.c b/fio.c
index e166f49..5f7d53d 100644
--- a/fio.c
+++ b/fio.c
@@ -253,8 +253,8 @@ static unsigned int get_next_buflen(struct thread_data *td)
buflen = (buflen + td->min_bs - 1) & ~(td->min_bs - 1);
}
- if (buflen > td->io_size - td->this_io_bytes)
- buflen = td->io_size - td->this_io_bytes;
+ if (buflen > td->io_size - td->this_io_bytes[td->ddir])
+ buflen = td->io_size - td->this_io_bytes[td->ddir];
return buflen;
}
@@ -286,35 +286,35 @@ static void add_log_sample(struct thread_data *td, struct io_log *iolog,
iolog->nr_samples++;
}
-static void add_clat_sample(struct thread_data *td, unsigned long msec)
+static void add_clat_sample(struct thread_data *td, int ddir,unsigned long msec)
{
- add_stat_sample(&td->clat_stat, msec);
+ add_stat_sample(&td->clat_stat[ddir], msec);
if (td->lat_log)
add_log_sample(td, td->lat_log, msec);
}
-static void add_slat_sample(struct thread_data *td, unsigned long msec)
+static void add_slat_sample(struct thread_data *td, int ddir,unsigned long msec)
{
- add_stat_sample(&td->slat_stat, msec);
+ add_stat_sample(&td->slat_stat[ddir], msec);
}
-static void add_bw_sample(struct thread_data *td)
+static void add_bw_sample(struct thread_data *td, int ddir)
{
- unsigned long spent = mtime_since_now(&td->stat_sample_time);
+ unsigned long spent = mtime_since_now(&td->stat_sample_time[ddir]);
unsigned long rate;
if (spent < td->bw_avg_time)
return;
- rate = (td->this_io_bytes - td->stat_io_bytes) / spent;
- add_stat_sample(&td->bw_stat, rate);
+ rate = (td->this_io_bytes[ddir] - td->stat_io_bytes[ddir]) / spent;
+ add_stat_sample(&td->bw_stat[ddir], rate);
if (td->bw_log)
add_log_sample(td, td->bw_log, rate);
- gettimeofday(&td->stat_sample_time, NULL);
- td->stat_io_bytes = td->this_io_bytes;
+ gettimeofday(&td->stat_sample_time[ddir], NULL);
+ td->stat_io_bytes[ddir] = td->this_io_bytes[ddir];
}
/*
@@ -385,6 +385,7 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
{
unsigned long spent;
unsigned long rate;
+ int ddir = td->ddir;
/*
* allow a 2 second settle period in the beginning
@@ -400,7 +401,7 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
if (spent < td->ratecycle)
return 0;
- rate = (td->this_io_bytes - td->rate_bytes) / spent;
+ rate = (td->this_io_bytes[ddir] - td->rate_bytes) / spent;
if (rate < td->ratemin) {
printf("Client%d: min rate %d not met, got %ldKiB/sec\n", td->thread_number, td->ratemin, rate);
if (rate_quit)
@@ -409,7 +410,7 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
}
}
- td->rate_bytes = td->this_io_bytes;
+ td->rate_bytes = td->this_io_bytes[ddir];
memcpy(&td->lastrate, now, sizeof(*now));
return 0;
}
@@ -729,48 +730,55 @@ static int io_u_queue(struct thread_data *td, struct io_u *io_u)
#define iocb_time(iocb) ((unsigned long) (iocb)->data)
-static int ios_completed(struct thread_data *td, int nr, int *err)
+static void io_completed(struct thread_data *td, struct io_u *io_u,
+ struct io_completion_data *icd)
{
- unsigned long msec;
- struct io_u *io_u;
struct timeval e;
- int i, bytes_done;
-
- if (err)
- *err = 0;
+ unsigned long msec;
gettimeofday(&e, NULL);
- for (i = 0, bytes_done = 0; i < nr; i++) {
- io_u = td->io_event(td, i);
+ if (!io_u->error) {
+ int idx = io_u->ddir;
- if (!io_u->error) {
- td->io_blocks++;
- td->io_bytes += (io_u->buflen - io_u->resid);
- td->this_io_bytes += (io_u->buflen - io_u->resid);
+ td->io_blocks[idx]++;
+ td->io_bytes[idx] += (io_u->buflen - io_u->resid);
+ td->this_io_bytes[idx] += (io_u->buflen - io_u->resid);
- msec = mtime_since(&io_u->issue_time, &e);
+ msec = mtime_since(&io_u->issue_time, &e);
+
+ add_clat_sample(td, io_u->ddir, msec);
+ add_bw_sample(td, io_u->ddir);
+
+ if (td_write(td) && io_u->ddir == DDIR_WRITE)
+ log_io_piece(td, io_u);
+
+ icd->bytes_done[idx] += (io_u->buflen - io_u->resid);
+ } else
+ icd->error = io_u->error;
+}
- add_clat_sample(td, msec);
- add_bw_sample(td);
+static void ios_completed(struct thread_data *td,struct io_completion_data *icd)
+{
+ struct io_u *io_u;
+ int i;
- if (td_write(td))
- log_io_piece(td, io_u);
+ icd->error = 0;
+ icd->bytes_done[0] = icd->bytes_done[1] = 0;
- bytes_done += (io_u->buflen - io_u->resid);
- } else if (err)
- *err = io_u->error;
+ for (i = 0; i < icd->nr; i++) {
+ io_u = td->io_event(td, i);
+ io_completed(td, io_u, icd);
put_io_u(td, io_u);
}
-
- return bytes_done;
}
static void cleanup_pending_aio(struct thread_data *td)
{
struct timespec ts = { .tv_sec = 0, .tv_nsec = 0};
struct list_head *entry, *n;
+ struct io_completion_data icd;
struct io_u *io_u;
int r;
@@ -778,8 +786,10 @@ static void cleanup_pending_aio(struct thread_data *td)
* get immediately available events, if any
*/
r = io_u_getevents(td, 0, td->cur_depth, &ts);
- if (r > 0)
- ios_completed(td, r, NULL);
+ if (r > 0) {
+ icd.nr = r;
+ ios_completed(td, &icd);
+ }
/*
* now cancel remaining active events
@@ -796,8 +806,10 @@ static void cleanup_pending_aio(struct thread_data *td)
if (td->cur_depth) {
r = io_u_getevents(td, td->cur_depth, td->cur_depth, NULL);
- if (r > 0)
- ios_completed(td, r, NULL);
+ if (r > 0) {
+ icd.nr = r;
+ ios_completed(td, &icd);
+ }
}
}
@@ -819,6 +831,7 @@ static void do_verify(struct thread_data *td)
{
struct timeval t;
struct io_u *io_u, *v_io_u = NULL;
+ struct io_completion_data icd;
int ret;
td_set_runstate(td, TD_VERIFYING);
@@ -853,7 +866,7 @@ static void do_verify(struct thread_data *td)
}
/*
- * we have one pending to verify, do that while the next
+ * we have one pending to verify, do that while
* we are doing io on the next one
*/
if (do_io_u_verify(td, &v_io_u))
@@ -867,8 +880,12 @@ static void do_verify(struct thread_data *td)
}
v_io_u = td->io_event(td, 0);
- if (v_io_u->error) {
- td_verror(td, v_io_u->error);
+ icd.nr = 1;
+ icd.error = 0;
+ io_completed(td, v_io_u, &icd);
+
+ if (icd.error) {
+ td_verror(td, icd.error);
put_io_u(td, v_io_u);
v_io_u = NULL;
break;
@@ -894,15 +911,15 @@ static void do_verify(struct thread_data *td)
static void do_io(struct thread_data *td)
{
+ struct io_completion_data icd;
struct timeval s, e;
unsigned long usec;
- while (td->this_io_bytes < td->io_size) {
+ while (td->this_io_bytes[td->ddir] < td->io_size) {
struct timespec ts = { .tv_sec = 0, .tv_nsec = 0};
struct timespec *timeout;
- int ret, min_evts = 0, err;
+ int ret, min_evts = 0;
struct io_u *io_u;
- unsigned int bytes_done;
if (td->terminate)
break;
@@ -921,7 +938,7 @@ static void do_io(struct thread_data *td)
}
gettimeofday(&io_u->issue_time, NULL);
- add_slat_sample(td, mtime_since(&io_u->start_time, &io_u->issue_time));
+ add_slat_sample(td, io_u->ddir, mtime_since(&io_u->start_time, &io_u->issue_time));
if (td->cur_depth < td->iodepth) {
timeout = &ts;
min_evts = 0;
@@ -937,9 +954,10 @@ static void do_io(struct thread_data *td)
} else if (!ret)
continue;
- bytes_done = ios_completed(td, ret, &err);
- if (err) {
- td_verror(td, err);
+ icd.nr = ret;
+ ios_completed(td, &icd);
+ if (icd.error) {
+ td_verror(td, icd.error);
break;
}
@@ -951,7 +969,7 @@ static void do_io(struct thread_data *td)
gettimeofday(&e, NULL);
usec = utime_since(&s, &e);
- rate_throttle(td, usec, bytes_done);
+ rate_throttle(td, usec, icd.bytes_done[td->ddir]);
if (check_min_rate(td, &e)) {
td_verror(td, ENOMEM);
@@ -965,7 +983,7 @@ static void do_io(struct thread_data *td)
usec_sleep(td, td->thinktime);
if (should_fsync(td) && td->fsync_blocks &&
- (td->io_blocks % td->fsync_blocks) == 0)
+ (td->io_blocks[DDIR_WRITE] % td->fsync_blocks) == 0)
sync_td(td);
}
@@ -1585,8 +1603,8 @@ static void clear_io_state(struct thread_data *td)
td->cur_off = 0;
td->last_bytes = 0;
- td->stat_io_bytes = 0;
- td->this_io_bytes = 0;
+ td->stat_io_bytes[0] = td->stat_io_bytes[1] = 0;
+ td->this_io_bytes[0] = td->this_io_bytes[1] = 0;
if (td->file_map)
memset(td->file_map, 0, td->num_maps * sizeof(long));
@@ -1594,7 +1612,7 @@ static void clear_io_state(struct thread_data *td)
static void update_rusage_stat(struct thread_data *td)
{
- if (!td->runtime)
+ if (!(td->runtime[0] + td->runtime[1]))
return;
getrusage(RUSAGE_SELF, &td->ru_end);
@@ -1659,7 +1677,7 @@ static void *thread_main(void *data)
do_io(td);
- td->runtime += mtime_since_now(&td->start);
+ td->runtime[td->ddir] += mtime_since_now(&td->start);
update_rusage_stat(td);
if (td->error || td->terminate)
@@ -1669,9 +1687,12 @@ static void *thread_main(void *data)
continue;
clear_io_state(td);
+ gettimeofday(&td->start, NULL);
do_verify(td);
+ td->runtime[DDIR_READ] += mtime_since_now(&td->start);
+
if (td->error || td->terminate)
break;
}
@@ -1735,37 +1756,57 @@ static int calc_lat(struct io_stat *is, unsigned long *min, unsigned long *max,
n = (double) is->samples;
*mean = (double) is->val / n;
*dev = sqrt(((double) is->val_sq - (*mean * *mean) / n) / (n - 1));
+ if (!(*min + *max) && !(*mean + *dev))
+ return 0;
+
return 1;
}
-static void show_thread_status(struct thread_data *td,
- struct group_run_stats *rs)
+static void show_ddir_status(struct thread_data *td, struct group_run_stats *rs,
+ int ddir)
{
- unsigned long min, max, bw = 0;
- double mean, dev, usr_cpu, sys_cpu;
+ char *ddir_str[] = { "read ", "write" };
+ unsigned long min, max, bw;
+ double mean, dev;
- if (!td->io_bytes && !td->error)
+ if (!td->runtime[ddir])
return;
- if (td->runtime)
- bw = td->io_bytes / td->runtime;
+ bw = td->io_bytes[ddir] / td->runtime[ddir];
+ printf(" %s: io=%6luMiB, bw=%6luKiB/s, runt=%6lumsec\n", ddir_str[ddir], td->io_bytes[ddir] >> 20, bw, td->runtime[ddir]);
+
+ if (calc_lat(&td->slat_stat[ddir], &min, &max, &mean, &dev))
+ printf(" slat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev);
- printf("Client%d (g=%d): err=%2d, io=%6luMiB, bw=%6luKiB/s, runt=%6lumsec\n", td->thread_number, td->groupid, td->error, td->io_bytes >> 20, bw, td->runtime);
+ if (calc_lat(&td->clat_stat[ddir], &min, &max, &mean, &dev))
+ printf(" clat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev);
- if (calc_lat(&td->slat_stat, &min, &max, &mean, &dev))
- printf(" slat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev);
- if (calc_lat(&td->clat_stat, &min, &max, &mean, &dev))
- printf(" clat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev);
- if (calc_lat(&td->bw_stat, &min, &max, &mean, &dev)) {
+ if (calc_lat(&td->bw_stat[ddir], &min, &max, &mean, &dev)) {
double p_of_agg;
- p_of_agg = mean * 100 / (double) rs->agg[td->ddir];
- printf(" bw (KiB/s) : min=%5lu, max=%5lu, per=%3.2f%%, avg=%5.02f, dev=%5.02f\n", min, max, p_of_agg, mean, dev);
+ p_of_agg = mean * 100 / (double) rs->agg[ddir];
+ printf(" bw (KiB/s) : min=%5lu, max=%5lu, per=%3.2f%%, avg=%5.02f, dev=%5.02f\n", min, max, p_of_agg, mean, dev);
}
+}
+
+static void show_thread_status(struct thread_data *td,
+ struct group_run_stats *rs)
+{
+ double usr_cpu, sys_cpu;
- if (td->runtime) {
- usr_cpu = (double) td->usr_time * 100 / (double) td->runtime;
- sys_cpu = (double) td->sys_time * 100 / (double) td->runtime;
+ if (!(td->io_bytes[0] + td->io_bytes[1]) && !td->error)
+ return;
+
+ printf("Client%d (g=%d): err=%2d:\n", td->thread_number, td->groupid, td->error);
+
+ show_ddir_status(td, rs, td->ddir);
+ show_ddir_status(td, rs, td->ddir ^ 1);
+
+ if (td->runtime[0] + td->runtime[1]) {
+ double runt = td->runtime[0] + td->runtime[1];
+
+ usr_cpu = (double) td->usr_time * 100 / runt;
+ sys_cpu = (double) td->sys_time * 100 / runt;
} else {
usr_cpu = 0;
sys_cpu = 0;
@@ -1835,12 +1876,11 @@ static void print_thread_status(void)
m_rate += td->ratemin;
}
- /*
- * doesn't quite work for verify, as it doesn't bump the
- * io counters. will fix that later.
- */
bytes_total += td->total_io_size;
- bytes_done += td->io_bytes;
+ if (td->verify)
+ bytes_total += td->total_io_size;
+
+ bytes_done += td->io_bytes[DDIR_READ] +td->io_bytes[DDIR_WRITE];
check_str_update(td);
}
@@ -2011,7 +2051,7 @@ static void run_threads(void)
static void show_group_stats(struct group_run_stats *rs, int id)
{
- printf("\nRun status group %d:\n", id);
+ printf("\nRun status group %d (all jobs):\n", id);
if (rs->max_run[DDIR_READ])
printf(" READ: io=%luMiB, aggrb=%lu, minb=%lu, maxb=%lu, mint=%lumsec, maxt=%lumsec\n", rs->io_mb[0], rs->agg[0], rs->min_bw[0], rs->max_bw[0], rs->min_run[0], rs->max_run[0]);
@@ -2057,7 +2097,7 @@ static void show_run_stats(void)
}
for (i = 0; i < thread_number; i++) {
- unsigned long bw = 0;
+ unsigned long rbw, wbw;
td = &threads[i];
@@ -2068,19 +2108,32 @@ static void show_run_stats(void)
rs = &runstats[td->groupid];
- if (td->runtime < rs->min_run[td->ddir])
- rs->min_run[td->ddir] = td->runtime;
- if (td->runtime > rs->max_run[td->ddir])
- rs->max_run[td->ddir] = td->runtime;
-
- if (td->runtime)
- bw = td->io_bytes / td->runtime;
- if (bw < rs->min_bw[td->ddir])
- rs->min_bw[td->ddir] = bw;
- if (bw > rs->max_bw[td->ddir])
- rs->max_bw[td->ddir] = bw;
-
- rs->io_mb[td->ddir] += td->io_bytes >> 20;
+ if (td->runtime[0] < rs->min_run[0] || !rs->min_run[0])
+ rs->min_run[0] = td->runtime[0];
+ if (td->runtime[0] > rs->max_run[0])
+ rs->max_run[0] = td->runtime[0];
+ if (td->runtime[1] < rs->min_run[1] || !rs->min_run[1])
+ rs->min_run[1] = td->runtime[1];
+ if (td->runtime[1] > rs->max_run[1])
+ rs->max_run[1] = td->runtime[1];
+
+ rbw = wbw = 0;
+ if (td->runtime[0])
+ rbw = td->io_bytes[0] / td->runtime[0];
+ if (td->runtime[1])
+ wbw = td->io_bytes[1] / td->runtime[1];
+
+ if (rbw < rs->min_bw[0])
+ rs->min_bw[0] = rbw;
+ if (wbw < rs->min_bw[1])
+ rs->min_bw[1] = wbw;
+ if (rbw > rs->max_bw[0])
+ rs->max_bw[0] = rbw;
+ if (wbw > rs->max_bw[1])
+ rs->max_bw[1] = wbw;
+
+ rs->io_mb[0] += td->io_bytes[0] >> 20;
+ rs->io_mb[1] += td->io_bytes[1] >> 20;
}
for (i = 0; i < groupid + 1; i++) {
diff --git a/fio.h b/fio.h
index 2853c4f..600c3be 100644
--- a/fio.h
+++ b/fio.h
@@ -168,13 +168,13 @@ struct thread_data {
unsigned long rate_bytes;
struct timeval lastrate;
- unsigned long runtime; /* sec */
+ unsigned long runtime[2]; /* msec */
unsigned long long io_size;
unsigned long long total_io_size;
- unsigned long io_blocks;
- unsigned long io_bytes;
- unsigned long this_io_bytes;
+ unsigned long io_blocks[2];
+ unsigned long io_bytes[2];
+ unsigned long this_io_bytes[2];
unsigned long last_bytes;
sem_t mutex;
@@ -185,12 +185,12 @@ struct thread_data {
/*
* bandwidth and latency stats
*/
- struct io_stat clat_stat; /* completion latency */
- struct io_stat slat_stat; /* submission latency */
+ struct io_stat clat_stat[2]; /* completion latency */
+ struct io_stat slat_stat[2]; /* submission latency */
+ struct io_stat bw_stat[2]; /* bandwidth stats */
- struct io_stat bw_stat; /* bandwidth stats */
- unsigned long stat_io_bytes;
- struct timeval stat_sample_time;
+ unsigned long stat_io_bytes[2];
+ struct timeval stat_sample_time[2];
struct io_log *lat_log;
struct io_log *bw_log;
@@ -293,6 +293,13 @@ struct disk_util {
struct timeval time;
};
+struct io_completion_data {
+ int nr; /* input */
+
+ int error; /* output */
+ unsigned long bytes_done[2]; /* output */
+};
+
#define DISK_UTIL_MSEC (250)
#endif