From 8355119b7ef7007b0a251654602584eec000f958 Mon Sep 17 00:00:00 2001 From: Sitsofe Wheeler Date: Wed, 30 Aug 2017 20:08:00 +0100 Subject: [PATCH] stat: fix shifted windowed logging when using multiple directions When using log_avg_msec and multiple I/O directions, the results recorded for the directions other than the first are attributed to the wrong time. This is demonstrated by the following: sudo modprobe null_blk completion_nsec=100000000 irqmode=2 sudo ./fio --bs=4k --direct=1 --ioengine=libaio --log_avg_msec=1000 \ --runtime=2s --disable_lat=1 --disable_bw_measurement=1 \ --filename=/dev/nullb0 --write_iops_log=shiftedlog --rw=rw \ --name=shiftedlog results in this: cat shiftedlog_iops.1.log 1000, 5, 0, 0 2000, 6, 0, 0 2000, 4, 1, 0 2256, 4, 1, 0 shiftedlog_iops.1.log is missing an entry at 1000ms for for the write direction (1) because the sample has been misattributed to 2000ms (the third row) due to iolog->avg_last being shared by all directions. Fix the shifting by turning iolog->avg_last into an array indexed by direction and only update the windowed stats for the current direction from add_log_sample(). Fixes https://github.com/axboe/fio/issues/410 . Reported-by: Kris Davis Signed-off-by: Sitsofe Wheeler --- iolog.h | 2 +- stat.c | 12 ++++++------ 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/iolog.h b/iolog.h index d157fa28..bc3a0b5f 100644 --- a/iolog.h +++ b/iolog.h @@ -117,7 +117,7 @@ struct io_log { */ struct io_stat avg_window[DDIR_RWDIR_CNT]; unsigned long avg_msec; - unsigned long avg_last; + unsigned long avg_last[DDIR_RWDIR_CNT]; /* * Windowed latency histograms, for keeping track of when we need to diff --git a/stat.c b/stat.c index 91c74abe..63353cc0 100644 --- a/stat.c +++ b/stat.c @@ -2159,7 +2159,7 @@ static void __add_log_sample(struct io_log *iolog, union io_sample_data data, if (iolog->disabled) return; if (flist_empty(&iolog->io_logs)) - iolog->avg_last = t; + iolog->avg_last[ddir] = t; cur_log = get_cur_log(iolog); if (cur_log) { @@ -2290,9 +2290,9 @@ static long add_log_sample(struct thread_data *td, struct io_log *iolog, * If period hasn't passed, adding the above sample is all we * need to do. */ - this_window = elapsed - iolog->avg_last; - if (elapsed < iolog->avg_last) - return iolog->avg_last - elapsed; + this_window = elapsed - iolog->avg_last[ddir]; + if (elapsed < iolog->avg_last[ddir]) + return iolog->avg_last[ddir] - elapsed; else if (this_window < iolog->avg_msec) { int diff = iolog->avg_msec - this_window; @@ -2300,9 +2300,9 @@ static long add_log_sample(struct thread_data *td, struct io_log *iolog, return diff; } - _add_stat_to_log(iolog, elapsed, td->o.log_max != 0); + __add_stat_to_log(iolog, ddir, elapsed, td->o.log_max != 0); - iolog->avg_last = elapsed - (this_window - iolog->avg_msec); + iolog->avg_last[ddir] = elapsed - (this_window - iolog->avg_msec); return iolog->avg_msec; } -- 2.25.1