From: Steven Lang <tirea@google.com>
Date: Tue, 7 Feb 2012 08:42:59 +0000 (+0100)
Subject: Enable completion latency stat collection on verify
X-Git-Tag: fio-2.0.4~50
X-Git-Url: https://git.kernel.dk/?p=fio.git;a=commitdiff_plain;h=6b1190fdf64da94a5d6b22439fa31825160f8734

Enable completion latency stat collection on verify

A patch last year
(http://git.kernel.dk/?p=fio.git;a=commit;f=io_u.c;h=c8eeb9df1f52f28567a5937e141decc6a26ec30b)
changed the behavior of verify loads so they stopped printing
completion latency stats.  (A verify load in this case includes both
rw=*write with verify and do_verify=1 and rw=*read with verify.)

Is there any particular reason that an io_u which is going to be
verified shouldn't have its latency statistics recorded?

This patch re-enables the clat recording.

An example demonstrating the issue here:

$ ./fio --name=test --size=1m --bs=4k --verify=meta --rw=write
test: (g=0): rw=write, bs=4K-4K/4K-4K, ioengine=sync, iodepth=1
fio 2.0.2
Starting 1 process
test: Laying out IO file(s) (1 file(s) / 1MB)

test: (groupid=0, jobs=1): err= 0: pid=27535
  read : io=1024.0KB, bw=1000.0MB/s, iops=256000 , runt=     1msec
    clat percentiles (usec):
     |  1.00th=[    0],  5.00th=[    0], 10.00th=[    0], 20.00th=[    0],
     | 30.00th=[    0], 40.00th=[    0], 50.00th=[    0], 60.00th=[    0],
     | 70.00th=[    0], 80.00th=[    0], 90.00th=[    0], 95.00th=[    0],
     | 99.00th=[    0], 99.50th=[    0], 99.90th=[    0]
  write: io=1024.0KB, bw=341333KB/s, iops=85333 , runt=     3msec
    clat (usec): min=2 , max=13 , avg= 3.30, stdev= 0.78
     lat (usec): min=2 , max=14 , avg= 3.52, stdev= 0.84
    clat percentiles (usec):
     |  1.00th=[    2],  5.00th=[    3], 10.00th=[    3], 20.00th=[    3],
     | 30.00th=[    3], 40.00th=[    3], 50.00th=[    3], 60.00th=[    3],
     | 70.00th=[    3], 80.00th=[    4], 90.00th=[    4], 95.00th=[    4],
     | 99.00th=[    4], 99.50th=[    4], 99.90th=[   13]
    lat (usec) : 4=35.55%, 10=14.26%, 20=0.20%
  cpu          : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=46
  IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=256/w=256/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=1024KB, aggrb=1000.0MB/s, minb=1024.0MB/s,
maxb=1024.0MB/s, mint=1msec, maxt=1msec
  WRITE: io=1024KB, aggrb=341333KB/s, minb=349525KB/s,
maxb=349525KB/s, mint=3msec, maxt=3msec

Note that no clat line is reported for reads and no clat percentiles
are listed.  If a read-only load is then executed, it has the same
thing.

$ ./fio --name=test --size=1m --bs=4k --verify=meta --rw=read
test: (g=0): rw=read, bs=4K-4K/4K-4K, ioengine=sync, iodepth=1
fio 2.0.2
Starting 1 process

test: (groupid=0, jobs=1): err= 0: pid=31694
  read : io=1024.0KB, bw=13653KB/s, iops=3413 , runt=    75msec
    clat percentiles (usec):
     |  1.00th=[    0],  5.00th=[    0], 10.00th=[    0], 20.00th=[    0],
     | 30.00th=[    0], 40.00th=[    0], 50.00th=[    0], 60.00th=[    0],
     | 70.00th=[    0], 80.00th=[    0], 90.00th=[    0], 95.00th=[    0],
     | 99.00th=[    0], 99.50th=[    0], 99.90th=[    0]
  cpu          : usr=0.00%, sys=0.00%, ctx=15, majf=0, minf=36
  IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=256/w=0/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=1024KB, aggrb=13653KB/s, minb=13981KB/s, maxb=13981KB/s,
mint=75msec, maxt=75msec

Signed-off-by: Jens Axboe <axboe@kernel.dk>
---

diff --git a/io_u.c b/io_u.c
index 8a033485..d794f011 100644
--- a/io_u.c
+++ b/io_u.c
@@ -1375,7 +1375,8 @@ static void io_completed(struct thread_data *td, struct io_u *io_u,
 			}
 		}
 
-		if (ramp_time_over(td) && td->runstate == TD_RUNNING) {
+		if (ramp_time_over(td) && (td->runstate == TD_RUNNING ||
+					   td->runstate == TD_VERIFYING)) {
 			account_io_completion(td, io_u, icd, idx, bytes);
 
 			if (__should_check_rate(td, idx)) {