Re: [PATCH 00/19] fs: rework and optimize i_version handling in filesystems

[Jeff Layton]

On Wed, 2017-12-13 at 10:05 -0500, J. Bruce Fields wrote:
> This is great, thanks.
> 
> On Wed, Dec 13, 2017 at 09:19:58AM -0500, Jeff Layton wrote:
> > With this, we reduce inode metadata updates across all 3 filesystems
> > down to roughly the frequency of the timestamp granularity, particularly
> > when it's not being queried (the vastly common case).
> > 
> > The pessimal workload here is 1 byte writes, and it helps that
> > significantly. Of course, that's not what we'd consider a real-world
> > workload.
> > 
> > A tiobench-example.fio workload also shows some modest performance
> > gains, and I've gotten mails from the kernel test robot that show some
> > significant performance gains on some microbenchmarks (case-msync-mt in
> > the vm-scalability testsuite to be specific), with an earlier version of
> > this set.
> > 
> > With larger writes, the gains with this patchset mostly vaporize,
> > but it does not seem to cause performance to regress anywhere, AFAICT.
> > 
> > I'm happy to run other workloads if anyone can suggest them.
> > 
> > At this point, the patchset works and does what it's expected to do in
> > my own testing. It seems like it's at least a modest performance win
> > across all 3 major disk-based filesystems. It may also encourage others
> > to implement i_version as well since it reduces the cost.
> 
> Do you have an idea what the remaining cost is?
> 
> Especially in the ext4 case, are you still able to measure any
> difference in performance between the cases where i_version is turned on
> and off, after these patches?

Attached is a fio jobfile + the output from 3 different runs using it
with ext4. This one is using 4k writes. There was no querying of
i_version during the runs.  I've done several runs with each and these
are pretty representative of the results:

old = 4.15-rc3, i_version enabled
ivers = 4.15-rc3 + these patches, i_version enabled
noivers = 4.15-rc3 + these patches, i_version disabled

To snip out the run status lines:

old:
WRITE: bw=85.6MiB/s (89.8MB/s), 9994KiB/s-11.1MiB/s (10.2MB/s-11.7MB/s), io=50.2GiB (53.8GB), run=600001-600001msec

ivers:
WRITE: bw=110MiB/s (115MB/s), 13.5MiB/s-14.2MiB/s (14.1MB/s-14.9MB/s), io=64.3GiB (69.0GB), run=600001-600001msec

noivers:
WRITE: bw=117MiB/s (123MB/s), 14.2MiB/s-15.2MiB/s (14.9MB/s-15.9MB/s), io=68.7GiB (73.8GB), run=600001-600001msec

So, I see some performance degradation with -o iversion compared to not
having it enabled (maybe due to the extra atomic fetches?), but this set
erases most of the difference.

> > 
> > [1]: On ext4 it must be turned on with the i_version mount option,
> >      mostly due to fears of incurring this impact, AFAICT.
> 
> So xfs and btrfs both have i_version updates on by default at this
> point?  (Assuming the filesystem's created with recent enough tools,
> etc.)
> 

Yes. With xfs and btrfs, I don't think you can disable it these days.

-- 
Jeff Layton <jlayton@xxxxxxxxxx>file1: (g=0): rw=write, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16
...
fio-3.0
Starting 8 processes
Jobs: 8 (f=8): [W(8)][100.0%][r=0KiB/s,w=104MiB/s][r=0,w=26.7k IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1191: Wed Dec 13 14:48:18 2017
  write: IOPS=3478, BW=13.6MiB/s (14.2MB/s)(8152MiB/600001msec)
    slat (usec): min=4, max=1085.0k, avg=240.14, stdev=1750.72
    clat (usec): min=58, max=1088.8k, avg=4143.72, stdev=7043.30
     lat (usec): min=110, max=1088.9k, avg=4387.89, stdev=7296.91
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   12], 99.50th=[   35], 99.90th=[  102], 99.95th=[  136],
     | 99.99th=[  218]
   bw (  KiB/s): min=  993, max=19783, per=12.98%, avg=14575.57, stdev=3800.59, samples=1147
   iops        : min=  248, max= 4945, avg=3643.57, stdev=950.17, samples=1147
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.16%, 4=70.13%, 10=28.59%, 20=0.36%, 50=0.39%
  lat (msec)   : 100=0.25%, 250=0.10%, 500=0.01%, 2000=0.01%
  cpu          : usr=0.95%, sys=89.11%, ctx=452539, majf=0, minf=13
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2086817,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1192: Wed Dec 13 14:48:18 2017
  write: IOPS=3626, BW=14.2MiB/s (14.9MB/s)(8500MiB/600001msec)
    slat (usec): min=6, max=1084.3k, avg=234.36, stdev=1416.96
    clat (usec): min=44, max=1114.2k, avg=3971.34, stdev=5623.69
     lat (usec): min=145, max=1114.5k, avg=4208.76, stdev=5823.63
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    7], 99.50th=[   20], 99.90th=[   78], 99.95th=[  106],
     | 99.99th=[  174]
   bw (  KiB/s): min= 1595, max=21112, per=13.53%, avg=15201.53, stdev=2969.29, samples=1147
   iops        : min=  398, max= 5278, avg=3800.04, stdev=742.34, samples=1147
  lat (usec)   : 50=0.01%, 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.19%, 4=69.92%, 10=29.06%, 20=0.28%, 50=0.27%
  lat (msec)   : 100=0.15%, 250=0.05%, 500=0.01%, 2000=0.01%
  cpu          : usr=0.97%, sys=92.24%, ctx=261214, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2175888,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1193: Wed Dec 13 14:48:18 2017
  write: IOPS=3452, BW=13.5MiB/s (14.1MB/s)(8092MiB/600001msec)
    slat (usec): min=4, max=1154.9k, avg=242.30, stdev=1896.64
    clat (usec): min=64, max=1164.4k, avg=4174.23, stdev=7654.32
     lat (usec): min=109, max=1164.5k, avg=4420.55, stdev=7936.35
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   13], 99.50th=[   36], 99.90th=[  106], 99.95th=[  144],
     | 99.99th=[  275]
   bw (  KiB/s): min=  529, max=21258, per=12.90%, avg=14493.62, stdev=3880.36, samples=1147
   iops        : min=  132, max= 5314, avg=3623.03, stdev=970.10, samples=1147
  lat (usec)   : 100=0.01%, 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.15%, 4=70.16%, 10=28.51%, 20=0.37%, 50=0.40%
  lat (msec)   : 100=0.24%, 250=0.10%, 500=0.01%, 750=0.01%, 2000=0.01%
  cpu          : usr=0.94%, sys=88.67%, ctx=522998, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2071479,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1194: Wed Dec 13 14:48:18 2017
  write: IOPS=3511, BW=13.7MiB/s (14.4MB/s)(8230MiB/600001msec)
    slat (usec): min=4, max=1085.1k, avg=237.86, stdev=1687.05
    clat (usec): min=39, max=1089.1k, avg=4104.43, stdev=6668.41
     lat (usec): min=120, max=1089.4k, avg=4346.31, stdev=6898.94
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   12], 99.50th=[   30], 99.90th=[   96], 99.95th=[  132],
     | 99.99th=[  211]
   bw (  KiB/s): min= 1112, max=19776, per=13.09%, avg=14707.65, stdev=3393.04, samples=1147
   iops        : min=  278, max= 4944, avg=3676.69, stdev=848.28, samples=1147
  lat (usec)   : 50=0.01%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.11%, 4=69.99%, 10=28.82%, 20=0.37%, 50=0.39%
  lat (msec)   : 100=0.19%, 250=0.09%, 500=0.01%, 2000=0.01%
  cpu          : usr=1.00%, sys=89.85%, ctx=413785, majf=0, minf=12
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2106782,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1195: Wed Dec 13 14:48:18 2017
  write: IOPS=3463, BW=13.5MiB/s (14.2MB/s)(8117MiB/600001msec)
    slat (usec): min=4, max=1082.7k, avg=241.60, stdev=1838.26
    clat (usec): min=63, max=1088.4k, avg=4161.37, stdev=7332.29
     lat (usec): min=110, max=1088.7k, avg=4406.97, stdev=7592.92
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   13], 99.50th=[   35], 99.90th=[  107], 99.95th=[  144],
     | 99.99th=[  243]
   bw (  KiB/s): min=  496, max=21619, per=12.93%, avg=14528.62, stdev=3710.11, samples=1147
   iops        : min=  124, max= 5404, avg=3631.78, stdev=927.53, samples=1147
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.15%, 4=70.22%, 10=28.49%, 20=0.38%, 50=0.40%
  lat (msec)   : 100=0.24%, 250=0.10%, 500=0.01%, 750=0.01%, 2000=0.01%
  cpu          : usr=0.99%, sys=88.74%, ctx=465671, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2077865,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1196: Wed Dec 13 14:48:18 2017
  write: IOPS=3550, BW=13.9MiB/s (14.5MB/s)(8321MiB/600001msec)
    slat (usec): min=4, max=1084.5k, avg=234.71, stdev=1655.30
    clat (usec): min=48, max=1089.2k, avg=4059.46, stdev=6479.65
     lat (usec): min=110, max=1089.4k, avg=4298.19, stdev=6697.09
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    5], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    9], 99.50th=[   25], 99.90th=[   88], 99.95th=[  124],
     | 99.99th=[  222]
   bw (  KiB/s): min= 1386, max=19895, per=13.27%, avg=14907.27, stdev=2940.34, samples=1147
   iops        : min=  346, max= 4973, avg=3726.44, stdev=735.09, samples=1147
  lat (usec)   : 50=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.02%
  lat (msec)   : 2=0.12%, 4=69.78%, 10=29.15%, 20=0.34%, 50=0.33%
  lat (msec)   : 100=0.18%, 250=0.07%, 500=0.01%, 750=0.01%, 2000=0.01%
  cpu          : usr=0.98%, sys=90.70%, ctx=321526, majf=0, minf=10
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2130283,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1197: Wed Dec 13 14:48:18 2017
  write: IOPS=3520, BW=13.8MiB/s (14.4MB/s)(8252MiB/600001msec)
    slat (usec): min=4, max=1083.3k, avg=237.04, stdev=1668.77
    clat (usec): min=45, max=1092.4k, avg=4093.45, stdev=6715.18
     lat (usec): min=110, max=1092.6k, avg=4334.50, stdev=6950.68
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   11], 99.50th=[   31], 99.90th=[   95], 99.95th=[  122],
     | 99.99th=[  215]
   bw (  KiB/s): min=  128, max=22949, per=13.16%, avg=14785.06, stdev=3438.70, samples=1147
   iops        : min=   32, max= 5737, avg=3695.90, stdev=859.68, samples=1147
  lat (usec)   : 50=0.01%, 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.15%, 4=70.79%, 10=27.97%, 20=0.35%, 50=0.38%
  lat (msec)   : 100=0.21%, 250=0.08%, 500=0.01%, 750=0.01%, 2000=0.01%
  cpu          : usr=1.00%, sys=89.70%, ctx=410771, majf=0, minf=10
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2112511,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1198: Wed Dec 13 14:48:18 2017
  write: IOPS=3477, BW=13.6MiB/s (14.2MB/s)(8151MiB/600001msec)
    slat (usec): min=4, max=1082.9k, avg=240.13, stdev=1795.84
    clat (usec): min=45, max=1115.8k, avg=4144.14, stdev=7175.43
     lat (usec): min=115, max=1116.1k, avg=4388.33, stdev=7427.75
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   12], 99.50th=[   34], 99.90th=[  103], 99.95th=[  146],
     | 99.99th=[  222]
   bw (  KiB/s): min=  963, max=19951, per=12.99%, avg=14591.74, stdev=3637.39, samples=1147
   iops        : min=  240, max= 4987, avg=3647.55, stdev=909.34, samples=1147
  lat (usec)   : 50=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.15%, 4=70.37%, 10=28.36%, 20=0.38%, 50=0.37%
  lat (msec)   : 100=0.24%, 250=0.10%, 500=0.01%, 2000=0.01%
  cpu          : usr=0.97%, sys=88.97%, ctx=452510, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2086619,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16

Run status group 0 (all jobs):
  WRITE: bw=110MiB/s (115MB/s), 13.5MiB/s-14.2MiB/s (14.1MB/s-14.9MB/s), io=64.3GiB (69.0GB), run=600001-600001msec

Disk stats (read/write):
  vdb: ios=0/46063, merge=0/6986, ticks=0/2294756, in_queue=1430067, util=8.76%
file1: (g=0): rw=write, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16
...
fio-3.0
Starting 8 processes
Jobs: 8 (f=8): [W(8)][100.0%][r=0KiB/s,w=123MiB/s][r=0,w=31.5k IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1218: Wed Dec 13 14:58:41 2017
  write: IOPS=3839, BW=14.0MiB/s (15.7MB/s)(8999MiB/600001msec)
    slat (usec): min=4, max=369392, avg=227.73, stdev=1229.83
    clat (usec): min=113, max=373025, avg=3923.34, stdev=4848.17
     lat (usec): min=118, max=373433, avg=4154.83, stdev=5012.74
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    6], 99.50th=[   17], 99.90th=[   79], 99.95th=[  111],
     | 99.99th=[  194]
   bw (  KiB/s): min= 3732, max=22216, per=12.82%, avg=15393.36, stdev=2641.49, samples=1200
   iops        : min=  933, max= 5554, avg=3847.98, stdev=660.39, samples=1200
  lat (usec)   : 250=0.04%, 500=0.01%, 750=0.01%, 1000=0.03%
  lat (msec)   : 2=0.28%, 4=70.76%, 10=28.16%, 20=0.26%, 50=0.25%
  lat (msec)   : 100=0.13%, 250=0.06%, 500=0.01%
  cpu          : usr=1.07%, sys=91.99%, ctx=265847, majf=0, minf=12
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2303836,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1219: Wed Dec 13 14:58:41 2017
  write: IOPS=3640, BW=14.2MiB/s (14.9MB/s)(8533MiB/600001msec)
    slat (usec): min=4, max=367205, avg=242.26, stdev=1701.75
    clat (usec): min=105, max=400086, avg=4137.17, stdev=6855.07
     lat (usec): min=110, max=400553, avg=4383.15, stdev=7106.79
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   11], 99.50th=[   35], 99.90th=[  112], 99.95th=[  148],
     | 99.99th=[  241]
   bw (  KiB/s): min=  264, max=23358, per=12.15%, avg=14587.82, stdev=3928.56, samples=1200
   iops        : min=   66, max= 5839, avg=3646.64, stdev=982.14, samples=1200
  lat (usec)   : 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.03%
  lat (msec)   : 2=0.22%, 4=70.42%, 10=28.26%, 20=0.29%, 50=0.37%
  lat (msec)   : 100=0.25%, 250=0.11%, 500=0.01%
  cpu          : usr=0.98%, sys=88.04%, ctx=464380, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2184434,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1220: Wed Dec 13 14:58:41 2017
  write: IOPS=3808, BW=14.9MiB/s (15.6MB/s)(8925MiB/600001msec)
    slat (usec): min=4, max=348744, avg=230.25, stdev=1217.66
    clat (usec): min=110, max=353791, avg=3955.93, stdev=4810.70
     lat (usec): min=115, max=354077, avg=4189.87, stdev=4976.17
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    8], 99.50th=[   22], 99.90th=[   79], 99.95th=[  104],
     | 99.99th=[  180]
   bw (  KiB/s): min= 1360, max=21672, per=12.71%, avg=15258.19, stdev=2808.41, samples=1200
   iops        : min=  340, max= 5418, avg=3814.23, stdev=702.12, samples=1200
  lat (usec)   : 250=0.04%, 500=0.01%, 750=0.01%, 1000=0.04%
  lat (msec)   : 2=0.25%, 4=70.75%, 10=28.05%, 20=0.32%, 50=0.32%
  lat (msec)   : 100=0.15%, 250=0.05%, 500=0.01%
  cpu          : usr=1.03%, sys=91.51%, ctx=315742, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2284898,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1221: Wed Dec 13 14:58:41 2017
  write: IOPS=3699, BW=14.4MiB/s (15.2MB/s)(8670MiB/600001msec)
    slat (usec): min=4, max=384286, avg=237.31, stdev=1556.89
    clat (usec): min=69, max=456496, avg=4071.97, stdev=6252.37
     lat (usec): min=109, max=456673, avg=4313.09, stdev=6477.02
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   10], 99.50th=[   31], 99.90th=[  104], 99.95th=[  136],
     | 99.99th=[  211]
   bw (  KiB/s): min=  793, max=24016, per=12.35%, avg=14826.33, stdev=3502.09, samples=1200
   iops        : min=  198, max= 6004, avg=3706.22, stdev=875.53, samples=1200
  lat (usec)   : 100=0.01%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.03%
  lat (msec)   : 2=0.26%, 4=70.92%, 10=27.75%, 20=0.31%, 50=0.36%
  lat (msec)   : 100=0.22%, 250=0.10%, 500=0.01%
  cpu          : usr=1.03%, sys=89.25%, ctx=473168, majf=0, minf=12
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2219487,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1222: Wed Dec 13 14:58:41 2017
  write: IOPS=3625, BW=14.2MiB/s (14.9MB/s)(8498MiB/600001msec)
    slat (usec): min=4, max=375714, avg=243.16, stdev=1737.37
    clat (usec): min=59, max=387462, avg=4154.04, stdev=7013.84
     lat (usec): min=109, max=387723, avg=4400.98, stdev=7271.32
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   13], 99.50th=[   39], 99.90th=[  116], 99.95th=[  153],
     | 99.99th=[  236]
   bw (  KiB/s): min=  729, max=21739, per=12.09%, avg=14519.35, stdev=3986.29, samples=1200
   iops        : min=  182, max= 5434, avg=3629.62, stdev=996.59, samples=1200
  lat (usec)   : 100=0.01%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.03%
  lat (msec)   : 2=0.28%, 4=70.67%, 10=27.86%, 20=0.33%, 50=0.40%
  lat (msec)   : 100=0.25%, 250=0.13%, 500=0.01%
  cpu          : usr=1.03%, sys=87.52%, ctx=510004, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2175576,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1223: Wed Dec 13 14:58:41 2017
  write: IOPS=3891, BW=15.2MiB/s (15.9MB/s)(9120MiB/600001msec)
    slat (usec): min=4, max=256927, avg=228.15, stdev=981.91
    clat (usec): min=55, max=268950, avg=3869.74, stdev=3893.99
     lat (usec): min=145, max=300244, avg=4100.95, stdev=4027.72
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    6], 99.50th=[   15], 99.90th=[   65], 99.95th=[   90],
     | 99.99th=[  148]
   bw (  KiB/s): min= 1638, max=22276, per=12.99%, avg=15599.33, stdev=2421.87, samples=1200
   iops        : min=  409, max= 5569, avg=3899.47, stdev=605.49, samples=1200
  lat (usec)   : 100=0.01%, 250=0.05%, 500=0.02%, 750=0.02%, 1000=0.05%
  lat (msec)   : 2=0.34%, 4=70.12%, 10=28.76%, 20=0.26%, 50=0.24%
  lat (msec)   : 100=0.11%, 250=0.03%, 500=0.01%
  cpu          : usr=1.06%, sys=93.28%, ctx=212422, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2334616,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1224: Wed Dec 13 14:58:41 2017
  write: IOPS=3707, BW=14.5MiB/s (15.2MB/s)(8689MiB/600001msec)
    slat (usec): min=4, max=356512, avg=237.42, stdev=1554.30
    clat (usec): min=42, max=376204, avg=4063.23, stdev=6248.90
     lat (usec): min=109, max=376508, avg=4304.36, stdev=6472.77
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[   10], 99.50th=[   31], 99.90th=[   99], 99.95th=[  132],
     | 99.99th=[  239]
   bw (  KiB/s): min= 1124, max=22706, per=12.40%, avg=14881.48, stdev=3507.39, samples=1200
   iops        : min=  281, max= 5676, avg=3719.98, stdev=876.86, samples=1200
  lat (usec)   : 50=0.01%, 250=0.05%, 500=0.02%, 750=0.01%, 1000=0.03%
  lat (msec)   : 2=0.34%, 4=70.57%, 10=28.00%, 20=0.28%, 50=0.37%
  lat (msec)   : 100=0.22%, 250=0.09%, 500=0.01%
  cpu          : usr=1.02%, sys=89.30%, ctx=437871, majf=0, minf=10
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2224313,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1225: Wed Dec 13 14:58:41 2017
  write: IOPS=3799, BW=14.8MiB/s (15.6MB/s)(8905MiB/600001msec)
    slat (usec): min=4, max=361544, avg=230.35, stdev=1332.97
    clat (usec): min=51, max=368069, avg=3965.33, stdev=5387.38
     lat (usec): min=110, max=368366, avg=4199.48, stdev=5581.52
    clat percentiles (msec):
     |  1.00th=[    3],  5.00th=[    3], 10.00th=[    3], 20.00th=[    4],
     | 30.00th=[    4], 40.00th=[    4], 50.00th=[    4], 60.00th=[    4],
     | 70.00th=[    4], 80.00th=[    5], 90.00th=[    5], 95.00th=[    5],
     | 99.00th=[    7], 99.50th=[   21], 99.90th=[   89], 99.95th=[  123],
     | 99.99th=[  197]
   bw (  KiB/s): min=  963, max=22292, per=12.69%, avg=15237.54, stdev=3142.05, samples=1200
   iops        : min=  240, max= 5573, avg=3809.02, stdev=785.52, samples=1200
  lat (usec)   : 100=0.01%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.02%
  lat (msec)   : 2=0.23%, 4=71.18%, 10=27.77%, 20=0.26%, 50=0.27%
  lat (msec)   : 100=0.16%, 250=0.08%, 500=0.01%
  cpu          : usr=1.01%, sys=91.25%, ctx=341973, majf=0, minf=10
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,2279628,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16

Run status group 0 (all jobs):
  WRITE: bw=117MiB/s (123MB/s), 14.2MiB/s-15.2MiB/s (14.9MB/s-15.9MB/s), io=68.7GiB (73.8GB), run=600001-600001msec

Disk stats (read/write):
  vdb: ios=1/50323, merge=0/451, ticks=0/1016470, in_queue=362769, util=5.81%
file1: (g=0): rw=write, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16
...
fio-3.0
Starting 8 processes
Jobs: 8 (f=8): [W(8)][100.0%][r=0KiB/s,w=82.1MiB/s][r=0,w=21.0k IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1178: Wed Dec 13 14:21:23 2017
  write: IOPS=2809, BW=10.0MiB/s (11.5MB/s)(6584MiB/600001msec)
    slat (usec): min=5, max=1731.0k, avg=321.00, stdev=4481.26
    clat (usec): min=76, max=1736.5k, avg=5171.63, stdev=17687.91
     lat (usec): min=141, max=1736.8k, avg=5495.42, stdev=18290.97
    clat percentiles (usec):
     |  1.00th=[  1860],  5.00th=[  2409], 10.00th=[  2802], 20.00th=[  3195],
     | 30.00th=[  3556], 40.00th=[  3818], 50.00th=[  4015], 60.00th=[  4228],
     | 70.00th=[  4490], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6063],
     | 99.00th=[ 14484], 99.50th=[ 69731], 99.90th=[250610], 99.95th=[337642],
     | 99.99th=[574620]
   bw (  KiB/s): min=    8, max=24673, per=13.42%, avg=11763.36, stdev=3943.17, samples=1148
   iops        : min=    2, max= 6168, avg=2940.54, stdev=985.79, samples=1148
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.03%, 1000=0.12%
  lat (msec)   : 2=1.21%, 4=47.10%, 10=50.36%, 20=0.29%, 50=0.26%
  lat (msec)   : 100=0.21%, 250=0.29%, 500=0.09%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.68%, sys=79.81%, ctx=652388, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1685538,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1179: Wed Dec 13 14:21:23 2017
  write: IOPS=2557, BW=9.99MiB/s (10.5MB/s)(5993MiB/600001msec)
    slat (usec): min=5, max=1827.2k, avg=355.53, stdev=5641.37
    clat (usec): min=54, max=1833.8k, avg=5680.10, stdev=22700.65
     lat (usec): min=139, max=1834.2k, avg=6038.34, stdev=23494.13
    clat percentiles (usec):
     |  1.00th=[  1778],  5.00th=[  2343], 10.00th=[  2704], 20.00th=[  3097],
     | 30.00th=[  3490], 40.00th=[  3752], 50.00th=[  3982], 60.00th=[  4178],
     | 70.00th=[  4424], 80.00th=[  4817], 90.00th=[  5407], 95.00th=[  6128],
     | 99.00th=[ 35390], 99.50th=[122160], 99.90th=[320865], 99.95th=[387974],
     | 99.99th=[918553]
   bw (  KiB/s): min=   24, max=26497, per=12.28%, avg=10761.46, stdev=4879.74, samples=1143
   iops        : min=    6, max= 6624, avg=2690.01, stdev=1219.92, samples=1143
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.03%, 1000=0.14%
  lat (msec)   : 2=1.48%, 4=49.67%, 10=47.13%, 20=0.31%, 50=0.34%
  lat (msec)   : 100=0.29%, 250=0.42%, 500=0.15%, 750=0.02%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.63%, sys=72.85%, ctx=984304, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1534249,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1180: Wed Dec 13 14:21:23 2017
  write: IOPS=2817, BW=11.0MiB/s (11.5MB/s)(6604MiB/600001msec)
    slat (usec): min=5, max=1751.3k, avg=320.34, stdev=4558.52
    clat (usec): min=69, max=1755.7k, avg=5156.99, stdev=18063.06
     lat (usec): min=138, max=1755.0k, avg=5480.10, stdev=18680.79
    clat percentiles (usec):
     |  1.00th=[  1876],  5.00th=[  2409], 10.00th=[  2802], 20.00th=[  3195],
     | 30.00th=[  3556], 40.00th=[  3785], 50.00th=[  4015], 60.00th=[  4228],
     | 70.00th=[  4490], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6063],
     | 99.00th=[ 14353], 99.50th=[ 67634], 99.90th=[263193], 99.95th=[337642],
     | 99.99th=[683672]
   bw (  KiB/s): min=   80, max=20811, per=13.49%, avg=11827.88, stdev=3987.58, samples=1146
   iops        : min=   20, max= 5202, avg=2956.61, stdev=996.89, samples=1146
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.04%, 1000=0.12%
  lat (msec)   : 2=1.20%, 4=48.00%, 10=49.47%, 20=0.30%, 50=0.27%
  lat (msec)   : 100=0.20%, 250=0.29%, 500=0.09%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.66%, sys=79.82%, ctx=604829, majf=0, minf=10
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1690561,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1181: Wed Dec 13 14:21:23 2017
  write: IOPS=2837, BW=11.1MiB/s (11.6MB/s)(6651MiB/600001msec)
    slat (usec): min=5, max=1700.6k, avg=317.64, stdev=4338.76
    clat (usec): min=36, max=1704.3k, avg=5119.44, stdev=16972.87
     lat (usec): min=148, max=1704.8k, avg=5439.85, stdev=17539.15
    clat percentiles (usec):
     |  1.00th=[  1975],  5.00th=[  2507], 10.00th=[  2835], 20.00th=[  3261],
     | 30.00th=[  3589], 40.00th=[  3851], 50.00th=[  4047], 60.00th=[  4293],
     | 70.00th=[  4555], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6063],
     | 99.00th=[ 13829], 99.50th=[ 62129], 99.90th=[240124], 99.95th=[320865],
     | 99.99th=[608175]
   bw (  KiB/s): min=   48, max=23214, per=13.56%, avg=11881.25, stdev=3784.78, samples=1148
   iops        : min=   12, max= 5803, avg=2970.05, stdev=946.19, samples=1148
  lat (usec)   : 50=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.10%
  lat (msec)   : 2=0.96%, 4=46.54%, 10=51.25%, 20=0.27%, 50=0.30%
  lat (msec)   : 100=0.21%, 250=0.26%, 500=0.08%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.66%, sys=80.94%, ctx=559902, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1702735,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1182: Wed Dec 13 14:21:23 2017
  write: IOPS=2498, BW=9994KiB/s (10.2MB/s)(5856MiB/600001msec)
    slat (usec): min=5, max=1758.3k, avg=364.78, stdev=5607.81
    clat (usec): min=51, max=1763.5k, avg=5813.05, stdev=22946.68
     lat (usec): min=137, max=1763.8k, avg=6180.47, stdev=23776.43
    clat percentiles (usec):
     |  1.00th=[  1745],  5.00th=[  2376], 10.00th=[  2769], 20.00th=[  3228],
     | 30.00th=[  3589], 40.00th=[  3818], 50.00th=[  4015], 60.00th=[  4228],
     | 70.00th=[  4490], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6128],
     | 99.00th=[ 39060], 99.50th=[128451], 99.90th=[341836], 99.95th=[434111],
     | 99.99th=[826278]
   bw (  KiB/s): min=    8, max=23134, per=11.96%, avg=10486.76, stdev=5172.17, samples=1146
   iops        : min=    2, max= 5783, avg=2621.32, stdev=1293.02, samples=1146
  lat (usec)   : 100=0.01%, 250=0.03%, 500=0.01%, 750=0.03%, 1000=0.13%
  lat (msec)   : 2=1.44%, 4=47.17%, 10=49.65%, 20=0.28%, 50=0.33%
  lat (msec)   : 100=0.29%, 250=0.42%, 500=0.17%, 750=0.02%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.63%, sys=72.48%, ctx=1079470, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1499031,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1183: Wed Dec 13 14:21:23 2017
  write: IOPS=2743, BW=10.7MiB/s (11.2MB/s)(6429MiB/600001msec)
    slat (usec): min=5, max=1738.5k, avg=330.39, stdev=4825.27
    clat (usec): min=46, max=1743.0k, avg=5295.46, stdev=19183.60
     lat (usec): min=138, max=1744.3k, avg=5628.41, stdev=19855.76
    clat percentiles (usec):
     |  1.00th=[  1860],  5.00th=[  2343], 10.00th=[  2737], 20.00th=[  3130],
     | 30.00th=[  3523], 40.00th=[  3785], 50.00th=[  3982], 60.00th=[  4178],
     | 70.00th=[  4424], 80.00th=[  4817], 90.00th=[  5342], 95.00th=[  6063],
     | 99.00th=[ 18744], 99.50th=[ 83362], 99.90th=[267387], 99.95th=[379585],
     | 99.99th=[675283]
   bw (  KiB/s): min=   64, max=23616, per=13.09%, avg=11474.50, stdev=4531.36, samples=1149
   iops        : min=   16, max= 5904, avg=2868.36, stdev=1132.85, samples=1149
  lat (usec)   : 50=0.01%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.20%
  lat (msec)   : 2=1.28%, 4=48.96%, 10=48.23%, 20=0.32%, 50=0.30%
  lat (msec)   : 100=0.25%, 250=0.31%, 500=0.10%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.63%, sys=77.48%, ctx=758312, majf=0, minf=9
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1645817,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1184: Wed Dec 13 14:21:23 2017
  write: IOPS=2850, BW=11.1MiB/s (11.7MB/s)(6680MiB/600001msec)
    slat (usec): min=5, max=1758.4k, avg=316.41, stdev=4456.60
    clat (usec): min=61, max=1763.5k, avg=5098.26, stdev=17493.16
     lat (usec): min=140, max=1763.7k, avg=5417.38, stdev=18076.15
    clat percentiles (usec):
     |  1.00th=[  1942],  5.00th=[  2442], 10.00th=[  2802], 20.00th=[  3228],
     | 30.00th=[  3589], 40.00th=[  3818], 50.00th=[  4047], 60.00th=[  4228],
     | 70.00th=[  4490], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6063],
     | 99.00th=[ 13042], 99.50th=[ 58983], 99.90th=[248513], 99.95th=[333448],
     | 99.99th=[599786]
   bw (  KiB/s): min=   32, max=21843, per=13.64%, avg=11953.28, stdev=3732.91, samples=1147
   iops        : min=    8, max= 5460, avg=2987.95, stdev=933.22, samples=1147
  lat (usec)   : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.17%
  lat (msec)   : 2=1.03%, 4=47.02%, 10=50.64%, 20=0.30%, 50=0.29%
  lat (msec)   : 100=0.19%, 250=0.25%, 500=0.08%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.70%, sys=80.63%, ctx=521547, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1710059,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16
file1: (groupid=0, jobs=1): err= 0: pid=1185: Wed Dec 13 14:21:23 2017
  write: IOPS=2798, BW=10.9MiB/s (11.5MB/s)(6559MiB/600001msec)
    slat (usec): min=5, max=1848.6k, avg=322.54, stdev=4583.84
    clat (usec): min=38, max=1854.1k, avg=5191.27, stdev=18112.72
     lat (usec): min=141, max=1854.5k, avg=5516.58, stdev=18734.21
    clat percentiles (usec):
     |  1.00th=[  1909],  5.00th=[  2409], 10.00th=[  2769], 20.00th=[  3163],
     | 30.00th=[  3556], 40.00th=[  3785], 50.00th=[  4015], 60.00th=[  4228],
     | 70.00th=[  4490], 80.00th=[  4883], 90.00th=[  5407], 95.00th=[  6063],
     | 99.00th=[ 16057], 99.50th=[ 70779], 99.90th=[270533], 99.95th=[358613],
     | 99.99th=[616563]
   bw (  KiB/s): min=   80, max=23390, per=13.36%, avg=11711.75, stdev=4136.20, samples=1148
   iops        : min=   20, max= 5847, avg=2927.75, stdev=1034.06, samples=1148
  lat (usec)   : 50=0.01%, 250=0.01%, 500=0.01%, 750=0.02%, 1000=0.14%
  lat (msec)   : 2=1.13%, 4=48.61%, 10=48.88%, 20=0.29%, 50=0.29%
  lat (msec)   : 100=0.22%, 250=0.28%, 500=0.10%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2000=0.01%
  cpu          : usr=0.69%, sys=79.14%, ctx=652094, majf=0, minf=11
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwt: total=0,1679114,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16

Run status group 0 (all jobs):
  WRITE: bw=85.6MiB/s (89.8MB/s), 9994KiB/s-11.1MiB/s (10.2MB/s-11.7MB/s), io=50.2GiB (53.8GB), run=600001-600001msec

Disk stats (read/write):
  vdb: ios=0/32561, merge=0/6598, ticks=0/5542527, in_queue=3752820, util=15.70%
; fio-seq-write.job for fiotest

[global]
name=fio-seq-write
rw=write
bs=4k
direct=0
time_based=1
runtime=600
numjobs=8

[file1]
filename=/mnt/test/fio.out
size=10G
ioengine=libaio
iodepth=16