From 30061b974a501c5cdfd84ab21b98d990455c84f8 Mon Sep 17 00:00:00 2001 From: Jens Axboe Date: Tue, 17 Apr 2007 13:31:34 +0200 Subject: [PATCH] Log and dump short ios Signed-off-by: Jens Axboe --- HOWTO | 3 +++ fio.c | 4 ++++ fio.h | 1 + stat.c | 5 ++++- 4 files changed, 12 insertions(+), 1 deletion(-) diff --git a/HOWTO b/HOWTO index 08a2b68d..aeb87ddb 100644 --- a/HOWTO +++ b/HOWTO @@ -684,6 +684,7 @@ Client1 (g=0): err= 0: bw (KiB/s) : min= 0, max= 1196, per=51.00%, avg=664.02, stdev=681.68 cpu : usr=1.49%, sys=0.25%, ctx=7969 IO depths : 1=0.1%, 2=0.3%, 4=0.5%, 8=99.0%, 16=0.0%, 32=0.0%, >32=0.0% + issued r/w: total=0/32768, short=0/0 lat (msec): 2=1.6%, 4=0.0%, 10=3.2%, 20=12.8%, 50=38.4%, 100=24.8%, lat (msec): 250=15.2%, 500=0.0%, 750=0.0%, 1000=0.0%, >=2048=0.0% @@ -715,6 +716,8 @@ IO depths= The distribution of io depths over the job life time. The 16= entries includes depths up to that value but higher than the previous entry. In other words, it covers the range from 16 to 31. +IO issued= The number of read/write requests issued, and how many + of them were short. IO latencies= The distribution of IO completion latencies. This is the time from when IO leaves fio and when it gets completed. The numbers follow the same pattern as the IO depths, diff --git a/fio.c b/fio.c index 296ac343..60a2a1b9 100644 --- a/fio.c +++ b/fio.c @@ -348,6 +348,8 @@ static void do_verify(struct thread_data *td) io_u->offset += bytes; f->last_completed_pos = io_u->offset; + td->ts.short_io_u[io_u->ddir]++; + if (io_u->offset == f->real_file_size) goto sync_done; @@ -464,6 +466,8 @@ static void do_io(struct thread_data *td) io_u->offset += bytes; f->last_completed_pos = io_u->offset; + td->ts.short_io_u[io_u->ddir]++; + if (io_u->offset == f->real_file_size) goto sync_done; diff --git a/fio.h b/fio.h index 9c398a20..0893a209 100644 --- a/fio.h +++ b/fio.h @@ -333,6 +333,7 @@ struct thread_stat { unsigned int io_u_map[FIO_IO_U_MAP_NR]; unsigned int io_u_lat[FIO_IO_U_LAT_NR]; unsigned long total_io_u[2]; + unsigned long short_io_u[2]; unsigned long long io_bytes[2]; unsigned long runtime[2]; diff --git a/stat.c b/stat.c index 3a785eed..0c2e01b4 100644 --- a/stat.c +++ b/stat.c @@ -225,6 +225,7 @@ static void show_thread_status(struct thread_stat *ts, stat_calc_lat(ts, io_u_lat); log_info(" IO depths : 1=%3.1f%%, 2=%3.1f%%, 4=%3.1f%%, 8=%3.1f%%, 16=%3.1f%%, 32=%3.1f%%, >=64=%3.1f%%\n", io_u_dist[0], io_u_dist[1], io_u_dist[2], io_u_dist[3], io_u_dist[4], io_u_dist[5], io_u_dist[6]); + log_info(" issued r/w: total=%lu/%lu, short=%lu/%lu\n", ts->total_io_u[0], ts->total_io_u[1], ts->short_io_u[0], ts->short_io_u[1]); log_info(" lat (msec): 2=%3.2f%%, 4=%3.2f%%, 10=%3.2f%%, 20=%3.2f%%, 50=%3.2f%%, 100=%3.2f%%\n", io_u_lat[0], io_u_lat[1], io_u_lat[2], io_u_lat[3], io_u_lat[4], io_u_lat[5]); log_info(" lat (msec): 250=%3.2f%%, 500=%3.2f%%, 750=%3.2f%%, 1000=%3.2f%%, >=2000=%3.2f%%\n", io_u_lat[6], io_u_lat[7], io_u_lat[8], io_u_lat[9], io_u_lat[10]); @@ -431,8 +432,10 @@ void show_run_stats(void) for (k = 0; k < FIO_IO_U_LAT_NR; k++) ts->io_u_lat[k] += td->ts.io_u_lat[k]; - for (k = 0; k <= DDIR_WRITE; k++) + for (k = 0; k <= DDIR_WRITE; k++) { ts->total_io_u[k] += td->ts.total_io_u[k]; + ts->short_io_u[k] += td->ts.short_io_u[k]; + } ts->total_run_time += td->ts.total_run_time; } -- 2.25.1