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

From: Jeff Layton
Date: Wed Dec 13 2017 - 17:10:19 EST

On Wed, 2017-12-13 at 15:14 -0500, Jeff Layton wrote:
> 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.
>

...and for completeness, I'm seeing better performance with 4k writes on
xfs with this set as well:


old:
WRITE: bw=86.7MiB/s (90.0MB/s), 9689KiB/s-11.7MiB/s (9921kB/s-12.2MB/s), io=50.8GiB (54.6GB), run=600001-600002msec

new:
WRITE: bw=129MiB/s (136MB/s), 15.8MiB/s-16.6MiB/s (16.6MB/s-17.4MB/s), io=75.9GiB (81.5GB), run=600001-600001msec


btrfs doesn't show much change ... it's possible that that patch isn't
quite right:

old:
WRITE: bw=49.1MiB/s (51.5MB/s), 5656KiB/s-7011KiB/s (5792kB/s-7179kB/s), io=28.8GiB (30.9GB), run=600001-600003msec

new:
WRITE: bw=50.3MiB/s (52.7MB/s), 5753KiB/s-7264KiB/s (5891kB/s-7438kB/s), io=29.5GiB (31.6GB), run=600001-600002msec


This is with the kernel running in a KVM guest, virtio disk in guest
backed by a LVM volume on a bog-standard ssd. Performance
characteristics could be different on a different setup, but I think
this is encouraging.

Note that this patchset requires some prerequisite patches that Andrew
is carrying. The complete series is here for anyone who wants to play
with it:

https://git.kernel.org/pub/scm/linux/kernel/git/jlayton/linux.git/log/?h=iversion

--
Jeff Layton <jlayton@xxxxxxxxxx>fio ./seq-write.fio
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=38.0MiB/s][r=0,w=9733 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1153: Wed Dec 13 16:45:33 2017
write: IOPS=1570, BW=6284KiB/s (6435kB/s)(3682MiB/600002msec)
slat (usec): min=11, max=2617.8k, avg=617.26, stdev=17969.35
clat (usec): min=13, max=2676.9k, avg=9558.41, stdev=71784.85
lat (usec): min=235, max=2677.4k, avg=10178.00, stdev=74245.06
clat percentiles (usec):
| 1.00th=[ 865], 5.00th=[ 1336], 10.00th=[ 2008],
| 20.00th=[ 2343], 30.00th=[ 2704], 40.00th=[ 2999],
| 50.00th=[ 3359], 60.00th=[ 3621], 70.00th=[ 4228],
| 80.00th=[ 5014], 90.00th=[ 6128], 95.00th=[ 7111],
| 99.00th=[ 137364], 99.50th=[ 383779], 99.90th=[1082131],
| 99.95th=[1535116], 99.99th=[2365588]
bw ( KiB/s): min= 8, max=44184, per=14.97%, avg=7707.74, stdev=6514.82, samples=980
iops : min= 2, max=11046, avg=1926.59, stdev=1628.66, samples=980
lat (usec) : 20=0.01%, 250=0.04%, 500=0.06%, 750=0.12%, 1000=2.60%
lat (msec) : 2=7.04%, 4=56.36%, 10=31.73%, 20=0.24%, 50=0.36%
lat (msec) : 100=0.30%, 250=0.41%, 500=0.35%, 750=0.16%, 1000=0.09%
lat (msec) : 2000=0.11%, >=2000=0.02%
cpu : usr=0.36%, sys=40.40%, ctx=916341, 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,942585,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=1154: Wed Dec 13 16:45:33 2017
write: IOPS=1438, BW=5753KiB/s (5891kB/s)(3371MiB/600001msec)
slat (usec): min=11, max=2902.8k, avg=676.21, stdev=20444.71
clat (usec): min=23, max=4845.3k, avg=10439.08, stdev=82915.40
lat (usec): min=229, max=4845.5k, avg=11117.62, stdev=85919.93
clat percentiles (usec):
| 1.00th=[ 832], 5.00th=[ 1237], 10.00th=[ 1827],
| 20.00th=[ 2311], 30.00th=[ 2704], 40.00th=[ 2999],
| 50.00th=[ 3261], 60.00th=[ 3490], 70.00th=[ 4015],
| 80.00th=[ 4686], 90.00th=[ 5866], 95.00th=[ 6980],
| 99.00th=[ 183501], 99.50th=[ 425722], 99.90th=[1333789],
| 99.95th=[1971323], 99.99th=[2701132]
bw ( KiB/s): min= 7, max=42276, per=14.19%, avg=7308.17, stdev=6556.14, samples=947
iops : min= 1, max=10569, avg=1826.70, stdev=1638.99, samples=947
lat (usec) : 50=0.01%, 250=0.05%, 500=0.07%, 750=0.18%, 1000=2.94%
lat (msec) : 2=7.98%, 4=58.60%, 10=27.93%, 20=0.26%, 50=0.43%
lat (msec) : 100=0.28%, 250=0.46%, 500=0.40%, 750=0.16%, 1000=0.12%
lat (msec) : 2000=0.10%, >=2000=0.05%
cpu : usr=0.29%, sys=36.57%, ctx=1089177, majf=0, minf=8
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,862978,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=1155: Wed Dec 13 16:45:33 2017
write: IOPS=1485, BW=5942KiB/s (6084kB/s)(3481MiB/600001msec)
slat (usec): min=11, max=3129.5k, avg=654.20, stdev=19347.52
clat (usec): min=38, max=4083.4k, avg=10108.44, stdev=78745.11
lat (usec): min=231, max=4083.7k, avg=10764.95, stdev=81539.21
clat percentiles (usec):
| 1.00th=[ 857], 5.00th=[ 1303], 10.00th=[ 1876],
| 20.00th=[ 2376], 30.00th=[ 2769], 40.00th=[ 3032],
| 50.00th=[ 3326], 60.00th=[ 3621], 70.00th=[ 4293],
| 80.00th=[ 5014], 90.00th=[ 6128], 95.00th=[ 7111],
| 99.00th=[ 149947], 99.50th=[ 408945], 99.90th=[1266680],
| 99.95th=[1769997], 99.99th=[2399142]
bw ( KiB/s): min= 8, max=40801, per=14.48%, avg=7458.17, stdev=6168.79, samples=958
iops : min= 2, max=10200, avg=1864.21, stdev=1542.13, samples=958
lat (usec) : 50=0.01%, 250=0.02%, 500=0.06%, 750=0.27%, 1000=2.63%
lat (msec) : 2=8.13%, 4=55.45%, 10=31.31%, 20=0.25%, 50=0.37%
lat (msec) : 100=0.30%, 250=0.42%, 500=0.35%, 750=0.18%, 1000=0.09%
lat (msec) : 2000=0.11%, >=2000=0.03%
cpu : usr=0.33%, sys=39.00%, ctx=996024, 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,891228,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=1156: Wed Dec 13 16:45:33 2017
write: IOPS=1785, BW=7142KiB/s (7314kB/s)(4185MiB/600001msec)
slat (usec): min=11, max=3142.7k, avg=540.50, stdev=15841.26
clat (usec): min=45, max=3915.5k, avg=8403.58, stdev=63204.82
lat (usec): min=231, max=3915.7k, avg=8946.44, stdev=65380.05
clat percentiles (usec):
| 1.00th=[ 881], 5.00th=[ 1434], 10.00th=[ 2180],
| 20.00th=[ 2442], 30.00th=[ 2868], 40.00th=[ 3195],
| 50.00th=[ 3425], 60.00th=[ 3687], 70.00th=[ 4293],
| 80.00th=[ 4948], 90.00th=[ 6063], 95.00th=[ 6980],
| 99.00th=[ 85459], 99.50th=[ 295699], 99.90th=[1019216],
| 99.95th=[1384121], 99.99th=[2365588]
bw ( KiB/s): min= 16, max=37184, per=16.54%, avg=8516.84, stdev=6147.10, samples=1007
iops : min= 4, max= 9296, avg=2129.02, stdev=1536.76, samples=1007
lat (usec) : 50=0.01%, 250=0.02%, 500=0.06%, 750=0.13%, 1000=1.83%
lat (msec) : 2=5.42%, 4=58.27%, 10=32.49%, 20=0.27%, 50=0.32%
lat (msec) : 100=0.24%, 250=0.37%, 500=0.29%, 750=0.12%, 1000=0.06%
lat (msec) : 2000=0.09%, >=2000=0.02%
cpu : usr=0.39%, sys=46.14%, ctx=811687, 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,1071347,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=1157: Wed Dec 13 16:45:33 2017
write: IOPS=1457, BW=5831KiB/s (5971kB/s)(3417MiB/600001msec)
slat (usec): min=11, max=2990.9k, avg=666.92, stdev=19764.26
clat (usec): min=40, max=3392.7k, avg=10300.16, stdev=78330.46
lat (usec): min=231, max=3392.0k, avg=10969.40, stdev=80982.57
clat percentiles (usec):
| 1.00th=[ 873], 5.00th=[ 1319], 10.00th=[ 1975],
| 20.00th=[ 2311], 30.00th=[ 2737], 40.00th=[ 2999],
| 50.00th=[ 3261], 60.00th=[ 3458], 70.00th=[ 3949],
| 80.00th=[ 4686], 90.00th=[ 5800], 95.00th=[ 6980],
| 99.00th=[ 191890], 99.50th=[ 450888], 99.90th=[1182794],
| 99.95th=[1719665], 99.99th=[2466251]
bw ( KiB/s): min= 8, max=34228, per=14.39%, avg=7411.45, stdev=6196.08, samples=946
iops : min= 2, max= 8557, avg=1852.53, stdev=1548.99, samples=946
lat (usec) : 50=0.01%, 250=0.01%, 500=0.09%, 750=0.26%, 1000=2.29%
lat (msec) : 2=7.98%, 4=60.29%, 10=26.89%, 20=0.26%, 50=0.38%
lat (msec) : 100=0.27%, 250=0.42%, 500=0.42%, 750=0.21%, 1000=0.10%
lat (msec) : 2000=0.12%, >=2000=0.03%
cpu : usr=0.32%, sys=36.90%, ctx=1018693, 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,874628,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=1158: Wed Dec 13 16:45:33 2017
write: IOPS=1649, BW=6597KiB/s (6755kB/s)(3865MiB/600001msec)
slat (usec): min=11, max=3143.6k, avg=586.92, stdev=17474.34
clat (usec): min=39, max=4084.4k, avg=9104.61, stdev=69703.21
lat (usec): min=202, max=4084.6k, avg=9693.89, stdev=72110.31
clat percentiles (usec):
| 1.00th=[ 865], 5.00th=[ 1287], 10.00th=[ 2024],
| 20.00th=[ 2409], 30.00th=[ 2835], 40.00th=[ 3163],
| 50.00th=[ 3392], 60.00th=[ 3654], 70.00th=[ 4228],
| 80.00th=[ 5014], 90.00th=[ 6128], 95.00th=[ 7111],
| 99.00th=[ 119014], 99.50th=[ 354419], 99.90th=[1061159],
| 99.95th=[1635779], 99.99th=[2432697]
bw ( KiB/s): min= 8, max=40905, per=15.54%, avg=8003.47, stdev=6226.76, samples=990
iops : min= 2, max=10226, avg=2000.69, stdev=1556.67, samples=990
lat (usec) : 50=0.01%, 250=0.03%, 500=0.06%, 750=0.13%, 1000=2.61%
lat (msec) : 2=6.82%, 4=56.22%, 10=32.18%, 20=0.27%, 50=0.37%
lat (msec) : 100=0.24%, 250=0.40%, 500=0.32%, 750=0.14%, 1000=0.09%
lat (msec) : 2000=0.09%, >=2000=0.02%
cpu : usr=0.37%, sys=42.71%, ctx=873316, majf=0, minf=8
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,989567,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=1159: Wed Dec 13 16:45:33 2017
write: IOPS=1672, BW=6689KiB/s (6850kB/s)(3920MiB/600001msec)
slat (usec): min=11, max=2633.0k, avg=578.72, stdev=17269.43
clat (usec): min=11, max=3011.0k, avg=8979.73, stdev=68815.08
lat (usec): min=237, max=3012.2k, avg=9560.80, stdev=71137.44
clat percentiles (usec):
| 1.00th=[ 881], 5.00th=[ 1336], 10.00th=[ 1975],
| 20.00th=[ 2376], 30.00th=[ 2802], 40.00th=[ 3064],
| 50.00th=[ 3359], 60.00th=[ 3621], 70.00th=[ 4228],
| 80.00th=[ 4883], 90.00th=[ 6063], 95.00th=[ 7046],
| 99.00th=[ 117965], 99.50th=[ 346031], 99.90th=[1082131],
| 99.95th=[1568670], 99.99th=[2499806]
bw ( KiB/s): min= 8, max=42064, per=15.78%, avg=8128.29, stdev=6379.01, samples=986
iops : min= 2, max=10516, avg=2032.02, stdev=1594.76, samples=986
lat (usec) : 20=0.01%, 250=0.04%, 500=0.07%, 750=0.12%, 1000=2.44%
lat (msec) : 2=7.78%, 4=56.46%, 10=31.22%, 20=0.26%, 50=0.32%
lat (msec) : 100=0.24%, 250=0.40%, 500=0.32%, 750=0.15%, 1000=0.06%
lat (msec) : 2000=0.10%, >=2000=0.02%
cpu : usr=0.35%, sys=43.06%, ctx=957715, majf=0, minf=7
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,1003392,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=1160: Wed Dec 13 16:45:33 2017
write: IOPS=1816, BW=7264KiB/s (7438kB/s)(4256MiB/600001msec)
slat (usec): min=12, max=3142.9k, avg=531.15, stdev=16191.13
clat (usec): min=47, max=3146.2k, avg=8270.14, stdev=63500.94
lat (usec): min=240, max=3146.4k, avg=8803.63, stdev=65645.85
clat percentiles (usec):
| 1.00th=[ 873], 5.00th=[ 1401], 10.00th=[ 2114],
| 20.00th=[ 2409], 30.00th=[ 2802], 40.00th=[ 3064],
| 50.00th=[ 3359], 60.00th=[ 3621], 70.00th=[ 4228],
| 80.00th=[ 4883], 90.00th=[ 5997], 95.00th=[ 6980],
| 99.00th=[ 74974], 99.50th=[ 287310], 99.90th=[1002439],
| 99.95th=[1434452], 99.99th=[2365588]
bw ( KiB/s): min= 8, max=26781, per=17.00%, avg=8756.18, stdev=6125.17, samples=998
iops : min= 2, max= 6695, avg=2188.69, stdev=1531.26, samples=998
lat (usec) : 50=0.01%, 250=0.01%, 500=0.02%, 750=0.12%, 1000=2.32%
lat (msec) : 2=5.61%, 4=58.24%, 10=31.92%, 20=0.27%, 50=0.35%
lat (msec) : 100=0.22%, 250=0.38%, 500=0.27%, 750=0.12%, 1000=0.06%
lat (msec) : 2000=0.09%, >=2000=0.01%
cpu : usr=0.39%, sys=46.33%, ctx=803875, 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,1089611,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=50.3MiB/s (52.7MB/s), 5753KiB/s-7264KiB/s (5891kB/s-7438kB/s), io=29.5GiB (31.6GB), run=600001-600002msec
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
file1: Laying out IO file (1 file / 10240MiB)
Jobs: 8 (f=8): [W(8)][100.0%][r=0KiB/s,w=23.9MiB/s][r=0,w=6130 IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1219: Wed Dec 13 16:25:59 2017
write: IOPS=1737, BW=6949KiB/s (7116kB/s)(4072MiB/600003msec)
slat (usec): min=12, max=4505.4k, avg=556.60, stdev=17945.08
clat (usec): min=37, max=4509.3k, avg=8637.16, stdev=71426.10
lat (usec): min=261, max=4509.5k, avg=9196.04, stdev=73807.97
clat percentiles (usec):
| 1.00th=[ 873], 5.00th=[ 1336], 10.00th=[ 1762],
| 20.00th=[ 2343], 30.00th=[ 2769], 40.00th=[ 2999],
| 50.00th=[ 3326], 60.00th=[ 3523], 70.00th=[ 4015],
| 80.00th=[ 4752], 90.00th=[ 5997], 95.00th=[ 6980],
| 99.00th=[ 74974], 99.50th=[ 308282], 99.90th=[1098908],
| 99.95th=[1518339], 99.99th=[2600469]
bw ( KiB/s): min= 8, max=38012, per=17.25%, avg=8670.43, stdev=6123.73, samples=962
iops : min= 2, max= 9503, avg=2167.52, stdev=1530.93, samples=962
lat (usec) : 50=0.01%, 250=0.01%, 500=0.03%, 750=0.16%, 1000=2.57%
lat (msec) : 2=8.62%, 4=58.13%, 10=28.77%, 20=0.27%, 50=0.27%
lat (msec) : 100=0.24%, 250=0.32%, 500=0.29%, 750=0.12%, 1000=0.07%
lat (msec) : 2000=0.10%, >=2000=0.02%
cpu : usr=0.40%, sys=43.14%, ctx=761137, 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,1042323,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 16:25:59 2017
write: IOPS=1523, BW=6094KiB/s (6240kB/s)(3571MiB/600001msec)
slat (usec): min=11, max=3106.5k, avg=636.61, stdev=19297.35
clat (usec): min=8, max=3326.4k, avg=9841.72, stdev=76303.68
lat (usec): min=153, max=3326.7k, avg=10480.72, stdev=78931.46
clat percentiles (usec):
| 1.00th=[ 881], 5.00th=[ 1336], 10.00th=[ 2024],
| 20.00th=[ 2343], 30.00th=[ 2802], 40.00th=[ 3064],
| 50.00th=[ 3359], 60.00th=[ 3589], 70.00th=[ 4146],
| 80.00th=[ 4752], 90.00th=[ 5866], 95.00th=[ 6915],
| 99.00th=[ 135267], 99.50th=[ 425722], 99.90th=[1182794],
| 99.95th=[1551893], 99.99th=[2600469]
bw ( KiB/s): min= 8, max=37835, per=15.13%, avg=7604.81, stdev=6137.33, samples=963
iops : min= 2, max= 9458, avg=1900.95, stdev=1534.30, samples=963
lat (usec) : 10=0.01%, 250=0.03%, 500=0.08%, 750=0.18%, 1000=2.16%
lat (msec) : 2=7.24%, 4=57.60%, 10=30.73%, 20=0.28%, 50=0.36%
lat (msec) : 100=0.23%, 250=0.35%, 500=0.31%, 750=0.19%, 1000=0.09%
lat (msec) : 2000=0.14%, >=2000=0.02%
cpu : usr=0.34%, sys=39.27%, ctx=1024014, 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,914111,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 16:25:59 2017
write: IOPS=1579, BW=6317KiB/s (6468kB/s)(3701MiB/600001msec)
slat (usec): min=11, max=3378.7k, avg=613.95, stdev=19369.95
clat (usec): min=30, max=3382.7k, avg=9505.30, stdev=77110.08
lat (usec): min=236, max=3382.0k, avg=10121.57, stdev=79761.57
clat percentiles (usec):
| 1.00th=[ 889], 5.00th=[ 1385], 10.00th=[ 2040],
| 20.00th=[ 2376], 30.00th=[ 2769], 40.00th=[ 3032],
| 50.00th=[ 3326], 60.00th=[ 3589], 70.00th=[ 4178],
| 80.00th=[ 4817], 90.00th=[ 6063], 95.00th=[ 6980],
| 99.00th=[ 111674], 99.50th=[ 383779], 99.90th=[1233126],
| 99.95th=[1551893], 99.99th=[2835350]
bw ( KiB/s): min= 8, max=32344, per=15.92%, avg=7999.22, stdev=6196.12, samples=950
iops : min= 2, max= 8086, avg=1999.49, stdev=1549.00, samples=950
lat (usec) : 50=0.01%, 250=0.01%, 500=0.06%, 750=0.14%, 1000=1.96%
lat (msec) : 2=7.38%, 4=57.50%, 10=31.13%, 20=0.25%, 50=0.32%
lat (msec) : 100=0.23%, 250=0.35%, 500=0.30%, 750=0.14%, 1000=0.08%
lat (msec) : 2000=0.13%, >=2000=0.03%
cpu : usr=0.36%, sys=40.24%, ctx=845216, 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,947496,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 16:25:59 2017
write: IOPS=1504, BW=6019KiB/s (6163kB/s)(3527MiB/600003msec)
slat (usec): min=11, max=3352.6k, avg=645.71, stdev=19845.49
clat (usec): min=28, max=3701.9k, avg=9978.31, stdev=79408.41
lat (usec): min=237, max=3702.1k, avg=10626.31, stdev=82130.21
clat percentiles (usec):
| 1.00th=[ 857], 5.00th=[ 1336], 10.00th=[ 1975],
| 20.00th=[ 2343], 30.00th=[ 2802], 40.00th=[ 3032],
| 50.00th=[ 3326], 60.00th=[ 3556], 70.00th=[ 4113],
| 80.00th=[ 4752], 90.00th=[ 5997], 95.00th=[ 7046],
| 99.00th=[ 132645], 99.50th=[ 434111], 99.90th=[1283458],
| 99.95th=[1619002], 99.99th=[2600469]
bw ( KiB/s): min= 7, max=35528, per=15.28%, avg=7681.10, stdev=5994.99, samples=940
iops : min= 1, max= 8882, avg=1920.22, stdev=1498.76, samples=940
lat (usec) : 50=0.01%, 250=0.01%, 500=0.03%, 750=0.14%, 1000=2.58%
lat (msec) : 2=7.65%, 4=57.94%, 10=29.71%, 20=0.30%, 50=0.35%
lat (msec) : 100=0.22%, 250=0.34%, 500=0.29%, 750=0.18%, 1000=0.10%
lat (msec) : 2000=0.15%, >=2000=0.03%
cpu : usr=0.32%, sys=38.58%, ctx=962514, 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,902859,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 16:25:59 2017
write: IOPS=1752, BW=7011KiB/s (7179kB/s)(4108MiB/600002msec)
slat (usec): min=12, max=4505.4k, avg=550.95, stdev=16994.58
clat (usec): min=29, max=5045.7k, avg=8568.87, stdev=68091.35
lat (usec): min=241, max=5045.9k, avg=9122.18, stdev=70418.08
clat percentiles (usec):
| 1.00th=[ 889], 5.00th=[ 1483], 10.00th=[ 2180],
| 20.00th=[ 2442], 30.00th=[ 2900], 40.00th=[ 3195],
| 50.00th=[ 3392], 60.00th=[ 3621], 70.00th=[ 4146],
| 80.00th=[ 4817], 90.00th=[ 5997], 95.00th=[ 6915],
| 99.00th=[ 78119], 99.50th=[ 320865], 99.90th=[1027605],
| 99.95th=[1417675], 99.99th=[2533360]
bw ( KiB/s): min= 8, max=35574, per=16.97%, avg=8529.81, stdev=6213.26, samples=989
iops : min= 2, max= 8893, avg=2132.10, stdev=1553.27, samples=989
lat (usec) : 50=0.01%, 250=0.02%, 500=0.07%, 750=0.08%, 1000=1.69%
lat (msec) : 2=5.78%, 4=59.87%, 10=30.81%, 20=0.25%, 50=0.29%
lat (msec) : 100=0.21%, 250=0.33%, 500=0.30%, 750=0.11%, 1000=0.08%
lat (msec) : 2000=0.09%, >=2000=0.02%
cpu : usr=0.42%, sys=44.71%, ctx=804193, 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,1051592,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 16:25:59 2017
write: IOPS=1457, BW=5831KiB/s (5971kB/s)(3417MiB/600001msec)
slat (usec): min=11, max=3408.5k, avg=667.13, stdev=20675.53
clat (usec): min=31, max=3731.3k, avg=10298.98, stdev=83065.95
lat (usec): min=220, max=3731.4k, avg=10968.38, stdev=85913.83
clat percentiles (usec):
| 1.00th=[ 824], 5.00th=[ 1254], 10.00th=[ 1500],
| 20.00th=[ 2278], 30.00th=[ 2573], 40.00th=[ 2933],
| 50.00th=[ 3195], 60.00th=[ 3425], 70.00th=[ 3851],
| 80.00th=[ 4621], 90.00th=[ 5932], 95.00th=[ 6980],
| 99.00th=[ 160433], 99.50th=[ 446694], 99.90th=[1300235],
| 99.95th=[1736442], 99.99th=[2902459]
bw ( KiB/s): min= 8, max=35558, per=15.21%, avg=7644.58, stdev=6275.71, samples=918
iops : min= 2, max= 8889, avg=1910.82, stdev=1568.89, samples=918
lat (usec) : 50=0.01%, 250=0.01%, 500=0.09%, 750=0.16%, 1000=3.44%
lat (msec) : 2=8.67%, 4=59.58%, 10=26.04%, 20=0.23%, 50=0.35%
lat (msec) : 100=0.26%, 250=0.38%, 500=0.35%, 750=0.16%, 1000=0.12%
lat (msec) : 2000=0.14%, >=2000=0.03%
cpu : usr=0.30%, sys=36.04%, ctx=992046, majf=0, minf=8
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,874718,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 16:25:59 2017
write: IOPS=1595, BW=6382KiB/s (6535kB/s)(3739MiB/600001msec)
slat (usec): min=11, max=3222.8k, avg=607.54, stdev=18877.57
clat (usec): min=27, max=3226.6k, avg=9412.18, stdev=74707.16
lat (usec): min=167, max=3226.8k, avg=10022.04, stdev=77241.60
clat percentiles (usec):
| 1.00th=[ 873], 5.00th=[ 1336], 10.00th=[ 1975],
| 20.00th=[ 2311], 30.00th=[ 2737], 40.00th=[ 2999],
| 50.00th=[ 3326], 60.00th=[ 3523], 70.00th=[ 4080],
| 80.00th=[ 4817], 90.00th=[ 5997], 95.00th=[ 6915],
| 99.00th=[ 113771], 99.50th=[ 362808], 99.90th=[1199571],
| 99.95th=[1535116], 99.99th=[2600469]
bw ( KiB/s): min= 8, max=37675, per=16.03%, avg=8055.05, stdev=6107.68, samples=953
iops : min= 2, max= 9418, avg=2013.42, stdev=1526.91, samples=953
lat (usec) : 50=0.01%, 250=0.06%, 500=0.06%, 750=0.14%, 1000=2.53%
lat (msec) : 2=7.54%, 4=57.91%, 10=29.88%, 20=0.23%, 50=0.37%
lat (msec) : 100=0.25%, 250=0.33%, 500=0.35%, 750=0.12%, 1000=0.09%
lat (msec) : 2000=0.13%, >=2000=0.02%
cpu : usr=0.36%, sys=40.54%, ctx=986375, 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,957247,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=1226: Wed Dec 13 16:25:59 2017
write: IOPS=1413, BW=5656KiB/s (5792kB/s)(3314MiB/600001msec)
slat (usec): min=11, max=3209.1k, avg=688.54, stdev=20245.71
clat (usec): min=43, max=3396.6k, avg=10618.11, stdev=82474.16
lat (usec): min=234, max=3396.8k, avg=11308.90, stdev=85346.97
clat percentiles (usec):
| 1.00th=[ 848], 5.00th=[ 1221], 10.00th=[ 1565],
| 20.00th=[ 2311], 30.00th=[ 2737], 40.00th=[ 3032],
| 50.00th=[ 3326], 60.00th=[ 3523], 70.00th=[ 4113],
| 80.00th=[ 4817], 90.00th=[ 6128], 95.00th=[ 7111],
| 99.00th=[ 185598], 99.50th=[ 488637], 99.90th=[1317012],
| 99.95th=[1702888], 99.99th=[2768241]
bw ( KiB/s): min= 8, max=40056, per=14.11%, avg=7089.66, stdev=6368.59, samples=960
iops : min= 2, max=10014, avg=1772.08, stdev=1592.12, samples=960
lat (usec) : 50=0.01%, 250=0.01%, 500=0.19%, 750=0.18%, 1000=3.21%
lat (msec) : 2=9.05%, 4=55.64%, 10=29.63%, 20=0.27%, 50=0.35%
lat (msec) : 100=0.24%, 250=0.37%, 500=0.38%, 750=0.22%, 1000=0.10%
lat (msec) : 2000=0.15%, >=2000=0.03%
cpu : usr=0.31%, sys=36.04%, ctx=914036, 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,848399,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=49.1MiB/s (51.5MB/s), 5656KiB/s-7011KiB/s (5792kB/s-7179kB/s), io=28.8GiB (30.9GB), run=600001-600003msec
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
file1: Laying out IO file (1 file / 10240MiB)
Jobs: 8 (f=8): [W(8)][100.0%][r=0KiB/s,w=102MiB/s][r=0,w=26.1k IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1360: Wed Dec 13 16:02:00 2017
write: IOPS=4178, BW=16.3MiB/s (17.1MB/s)(9793MiB/600001msec)
slat (usec): min=3, max=765706, avg=201.29, stdev=1529.42
clat (usec): min=60, max=769481, avg=3609.99, stdev=6000.14
lat (usec): min=109, max=769867, avg=3815.72, stdev=6202.11
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 12], 99.90th=[ 51], 99.95th=[ 74],
| 99.99th=[ 313]
bw ( KiB/s): min= 609, max=22883, per=12.66%, avg=16780.35, stdev=3058.72, samples=1198
iops : min= 152, max= 5720, avg=4194.72, stdev=764.69, samples=1198
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.09%, 4=87.62%, 10=11.70%, 20=0.25%, 50=0.22%
lat (msec) : 100=0.07%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.26%, sys=92.80%, ctx=216533, 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,2507016,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=1361: Wed Dec 13 16:02:00 2017
write: IOPS=4101, BW=16.0MiB/s (16.8MB/s)(9612MiB/600001msec)
slat (usec): min=3, max=832923, avg=205.39, stdev=1646.45
clat (usec): min=62, max=837254, avg=3677.76, stdev=6496.35
lat (usec): min=106, max=837548, avg=3887.67, stdev=6720.67
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 7], 99.50th=[ 19], 99.90th=[ 69], 99.95th=[ 95],
| 99.99th=[ 313]
bw ( KiB/s): min= 384, max=22156, per=12.41%, avg=16450.03, stdev=3574.82, samples=1198
iops : min= 96, max= 5539, avg=4112.29, stdev=893.71, samples=1198
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.09%, 4=88.25%, 10=10.87%, 20=0.29%, 50=0.31%
lat (msec) : 100=0.12%, 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.27%, sys=91.00%, ctx=322342, majf=0, minf=8
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,2460684,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=1362: Wed Dec 13 16:02:00 2017
write: IOPS=4158, BW=16.2MiB/s (17.0MB/s)(9747MiB/600001msec)
slat (usec): min=3, max=829989, avg=201.98, stdev=1546.44
clat (usec): min=82, max=833896, avg=3627.01, stdev=6048.97
lat (usec): min=108, max=834076, avg=3833.49, stdev=6252.83
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 14], 99.90th=[ 57], 99.95th=[ 83],
| 99.99th=[ 300]
bw ( KiB/s): min= 1611, max=43503, per=12.60%, avg=16705.43, stdev=3274.39, samples=1198
iops : min= 402, max=10875, avg=4176.00, stdev=818.59, samples=1198
lat (usec) : 100=0.01%, 250=0.11%, 500=0.03%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.11%, 4=87.72%, 10=11.40%, 20=0.25%, 50=0.25%
lat (msec) : 100=0.09%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.27%, sys=92.33%, ctx=253025, 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,2495350,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=1363: Wed Dec 13 16:02:00 2017
write: IOPS=4254, BW=16.6MiB/s (17.4MB/s)(9972MiB/600001msec)
slat (usec): min=5, max=766806, avg=203.17, stdev=1368.21
clat (usec): min=131, max=771002, avg=3541.83, stdev=5341.13
lat (usec): min=138, max=771300, avg=3748.35, stdev=5520.27
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 8], 99.90th=[ 36], 99.95th=[ 54],
| 99.99th=[ 300]
bw ( KiB/s): min= 1731, max=22701, per=12.88%, avg=17083.49, stdev=2671.55, samples=1198
iops : min= 432, max= 5675, avg=4270.50, stdev=667.85, samples=1198
lat (usec) : 250=0.05%, 500=0.02%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.18%, 4=87.04%, 10=12.26%, 20=0.20%, 50=0.16%
lat (msec) : 100=0.04%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.21%, sys=94.41%, ctx=145712, 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,2552889,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=1364: Wed Dec 13 16:02:00 2017
write: IOPS=4055, BW=15.8MiB/s (16.6MB/s)(9506MiB/600001msec)
slat (usec): min=3, max=847054, avg=208.13, stdev=1715.47
clat (usec): min=55, max=850110, avg=3718.75, stdev=6733.35
lat (usec): min=105, max=850414, avg=3931.37, stdev=6968.33
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 8], 99.50th=[ 22], 99.90th=[ 75], 99.95th=[ 110],
| 99.99th=[ 317]
bw ( KiB/s): min= 907, max=22252, per=12.29%, avg=16300.78, stdev=3677.63, samples=1197
iops : min= 226, max= 5563, avg=4074.82, stdev=919.42, samples=1197
lat (usec) : 100=0.01%, 250=0.04%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.12%, 4=87.75%, 10=11.24%, 20=0.31%, 50=0.33%
lat (msec) : 100=0.14%, 250=0.04%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.31%, sys=90.45%, ctx=396245, 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,2433447,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=1365: Wed Dec 13 16:02:00 2017
write: IOPS=4125, BW=16.1MiB/s (16.9MB/s)(9668MiB/600001msec)
slat (usec): min=3, max=766661, avg=204.36, stdev=1540.93
clat (usec): min=102, max=771014, avg=3656.38, stdev=6059.01
lat (usec): min=107, max=771384, avg=3865.18, stdev=6265.22
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 17], 99.90th=[ 63], 99.95th=[ 86],
| 99.99th=[ 300]
bw ( KiB/s): min= 1691, max=22549, per=12.49%, avg=16557.28, stdev=3511.44, samples=1198
iops : min= 422, max= 5637, avg=4138.97, stdev=877.87, samples=1198
lat (usec) : 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.09%, 4=87.64%, 10=11.51%, 20=0.30%, 50=0.29%
lat (msec) : 100=0.11%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.23%, sys=91.80%, ctx=295015, 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,2475045,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=1366: Wed Dec 13 16:02:00 2017
write: IOPS=4142, BW=16.2MiB/s (16.0MB/s)(9709MiB/600001msec)
slat (usec): min=3, max=769630, avg=202.97, stdev=1605.67
clat (usec): min=74, max=773586, avg=3641.33, stdev=6337.34
lat (usec): min=106, max=773767, avg=3848.80, stdev=6552.80
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 15], 99.90th=[ 58], 99.95th=[ 86],
| 99.99th=[ 334]
bw ( KiB/s): min= 224, max=22995, per=12.55%, avg=16640.38, stdev=3320.37, samples=1198
iops : min= 56, max= 5748, avg=4159.72, stdev=830.10, samples=1198
lat (usec) : 100=0.01%, 250=0.02%, 500=0.01%, 750=0.03%, 1000=0.01%
lat (msec) : 2=0.12%, 4=87.95%, 10=11.21%, 20=0.26%, 50=0.27%
lat (msec) : 100=0.09%, 250=0.03%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.33%, sys=91.99%, ctx=297864, 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,2485419,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=1367: Wed Dec 13 16:02:00 2017
write: IOPS=4130, BW=16.1MiB/s (16.9MB/s)(9681MiB/600001msec)
slat (usec): min=3, max=836059, avg=203.03, stdev=1560.64
clat (usec): min=60, max=839666, avg=3651.98, stdev=6149.70
lat (usec): min=110, max=839905, avg=3859.61, stdev=6358.90
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 3],
| 30.00th=[ 4], 40.00th=[ 4], 50.00th=[ 4], 60.00th=[ 4],
| 70.00th=[ 4], 80.00th=[ 4], 90.00th=[ 5], 95.00th=[ 5],
| 99.00th=[ 6], 99.50th=[ 16], 99.90th=[ 62], 99.95th=[ 87],
| 99.99th=[ 334]
bw ( KiB/s): min= 937, max=22484, per=12.50%, avg=16579.11, stdev=3330.88, samples=1198
iops : min= 234, max= 5621, avg=4144.45, stdev=832.70, samples=1198
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.09%, 4=87.88%, 10=11.33%, 20=0.26%, 50=0.27%
lat (msec) : 100=0.10%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
cpu : usr=1.28%, sys=91.92%, ctx=290466, 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,2478319,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=129MiB/s (136MB/s), 15.8MiB/s-16.6MiB/s (16.6MB/s-17.4MB/s), io=75.9GiB (81.5GB), run=600001-600001msec

Disk stats (read/write):
vdb: ios=1/27804, merge=0/1743, ticks=1/4511916, in_queue=3364804, util=25.86%
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.2MiB/s][r=0,w=21.0k IOPS][eta 00m:00s]
file1: (groupid=0, jobs=1): err= 0: pid=1131: Wed Dec 13 16:14:21 2017
write: IOPS=2908, BW=11.4MiB/s (11.9MB/s)(6816MiB/600001msec)
slat (usec): min=5, max=787176, avg=316.82, stdev=3687.41
clat (usec): min=74, max=1056.3k, avg=5171.76, stdev=14861.09
lat (usec): min=135, max=1056.7k, avg=5491.61, stdev=15383.15
clat percentiles (usec):
| 1.00th=[ 1532], 5.00th=[ 2311], 10.00th=[ 2573], 20.00th=[ 2933],
| 30.00th=[ 3294], 40.00th=[ 3556], 50.00th=[ 3818], 60.00th=[ 4047],
| 70.00th=[ 4359], 80.00th=[ 4686], 90.00th=[ 5342], 95.00th=[ 5997],
| 99.00th=[ 38536], 99.50th=[ 89654], 99.90th=[225444], 99.95th=[278922],
| 99.99th=[505414]
bw ( KiB/s): min= 16, max=37683, per=13.12%, avg=11655.03, stdev=4424.17, samples=1199
iops : min= 4, max= 9420, avg=2913.44, stdev=1106.04, samples=1199
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.05%, 1000=0.23%
lat (msec) : 2=1.64%, 4=56.03%, 10=39.78%, 20=0.79%, 50=0.63%
lat (msec) : 100=0.40%, 250=0.37%, 500=0.07%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.79%, sys=74.80%, ctx=868689, 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,1744871,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=1132: Wed Dec 13 16:14:21 2017
write: IOPS=2802, BW=10.9MiB/s (11.5MB/s)(6567MiB/600001msec)
slat (usec): min=5, max=1163.8k, avg=329.51, stdev=4078.35
clat (usec): min=52, max=1271.4k, avg=5367.10, stdev=16476.69
lat (usec): min=140, max=1271.5k, avg=5699.81, stdev=17066.63
clat percentiles (usec):
| 1.00th=[ 1336], 5.00th=[ 2278], 10.00th=[ 2573], 20.00th=[ 2900],
| 30.00th=[ 3261], 40.00th=[ 3490], 50.00th=[ 3752], 60.00th=[ 4015],
| 70.00th=[ 4293], 80.00th=[ 4621], 90.00th=[ 5276], 95.00th=[ 6063],
| 99.00th=[ 47449], 99.50th=[106431], 99.90th=[254804], 99.95th=[316670],
| 99.99th=[463471]
bw ( KiB/s): min= 96, max=34464, per=12.64%, avg=11225.62, stdev=4880.80, samples=1198
iops : min= 24, max= 8616, avg=2806.20, stdev=1220.20, samples=1198
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.06%, 1000=0.33%
lat (msec) : 2=1.78%, 4=57.81%, 10=37.44%, 20=0.85%, 50=0.73%
lat (msec) : 100=0.44%, 250=0.42%, 500=0.10%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.79%, sys=71.65%, ctx=1044041, 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,1681268,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=1133: Wed Dec 13 16:14:21 2017
write: IOPS=2985, BW=11.7MiB/s (12.2MB/s)(6997MiB/600001msec)
slat (usec): min=5, max=748162, avg=307.69, stdev=3307.29
clat (usec): min=60, max=775858, avg=5038.81, stdev=13095.28
lat (usec): min=165, max=776031, avg=5349.64, stdev=13543.69
clat percentiles (usec):
| 1.00th=[ 1483], 5.00th=[ 2311], 10.00th=[ 2573], 20.00th=[ 2933],
| 30.00th=[ 3294], 40.00th=[ 3523], 50.00th=[ 3785], 60.00th=[ 4047],
| 70.00th=[ 4293], 80.00th=[ 4686], 90.00th=[ 5342], 95.00th=[ 5997],
| 99.00th=[ 36439], 99.50th=[ 82314], 99.90th=[204473], 99.95th=[246416],
| 99.99th=[404751]
bw ( KiB/s): min= 24, max=35440, per=13.46%, avg=11951.36, stdev=3904.50, samples=1200
iops : min= 6, max= 8860, avg=2987.58, stdev=976.12, samples=1200
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.04%, 1000=0.23%
lat (msec) : 2=1.69%, 4=56.62%, 10=39.10%, 20=0.82%, 50=0.68%
lat (msec) : 100=0.41%, 250=0.35%, 500=0.04%, 750=0.01%, 1000=0.01%
cpu : usr=0.84%, sys=76.03%, ctx=786053, 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,1791122,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=1134: Wed Dec 13 16:14:21 2017
write: IOPS=2774, BW=10.8MiB/s (11.4MB/s)(6502MiB/600001msec)
slat (usec): min=6, max=1165.7k, avg=332.59, stdev=4092.38
clat (usec): min=62, max=1168.9k, avg=5421.32, stdev=16731.39
lat (usec): min=142, max=1169.2k, avg=5757.12, stdev=17348.61
clat percentiles (usec):
| 1.00th=[ 1467], 5.00th=[ 2311], 10.00th=[ 2606], 20.00th=[ 2966],
| 30.00th=[ 3294], 40.00th=[ 3556], 50.00th=[ 3818], 60.00th=[ 4047],
| 70.00th=[ 4359], 80.00th=[ 4686], 90.00th=[ 5342], 95.00th=[ 6063],
| 99.00th=[ 47449], 99.50th=[105382], 99.90th=[258999], 99.95th=[320865],
| 99.99th=[476054]
bw ( KiB/s): min= 8, max=40232, per=12.54%, avg=11136.08, stdev=4803.28, samples=1197
iops : min= 2, max=10058, avg=2783.74, stdev=1200.81, samples=1197
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.07%, 1000=0.25%
lat (msec) : 2=1.71%, 4=55.77%, 10=39.67%, 20=0.81%, 50=0.73%
lat (msec) : 100=0.43%, 250=0.42%, 500=0.10%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.74%, sys=71.57%, ctx=949754, 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,1664518,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=1135: Wed Dec 13 16:14:21 2017
write: IOPS=2692, BW=10.5MiB/s (11.0MB/s)(6311MiB/600002msec)
slat (usec): min=6, max=951339, avg=344.14, stdev=4217.19
clat (usec): min=45, max=955624, avg=5584.63, stdev=17319.60
lat (usec): min=144, max=955868, avg=5931.93, stdev=17960.09
clat percentiles (usec):
| 1.00th=[ 1713], 5.00th=[ 2311], 10.00th=[ 2573], 20.00th=[ 2933],
| 30.00th=[ 3261], 40.00th=[ 3523], 50.00th=[ 3785], 60.00th=[ 4015],
| 70.00th=[ 4293], 80.00th=[ 4621], 90.00th=[ 5276], 95.00th=[ 6063],
| 99.00th=[ 60031], 99.50th=[121111], 99.90th=[256902], 99.95th=[312476],
| 99.99th=[497026]
bw ( KiB/s): min= 48, max=23743, per=12.17%, avg=10806.28, stdev=5068.49, samples=1197
iops : min= 12, max= 5935, avg=2701.33, stdev=1267.12, samples=1197
lat (usec) : 50=0.01%, 250=0.02%, 500=0.01%, 750=0.05%, 1000=0.23%
lat (msec) : 2=1.45%, 4=57.54%, 10=37.96%, 20=0.85%, 50=0.77%
lat (msec) : 100=0.49%, 250=0.53%, 500=0.10%, 750=0.01%, 1000=0.01%
cpu : usr=0.73%, sys=69.40%, ctx=1092449, 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,1615619,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=1136: Wed Dec 13 16:14:21 2017
write: IOPS=2808, BW=10.0MiB/s (11.5MB/s)(6582MiB/600001msec)
slat (usec): min=5, max=1164.6k, avg=328.77, stdev=4029.61
clat (usec): min=69, max=1167.1k, avg=5355.39, stdev=16199.32
lat (usec): min=133, max=1167.3k, avg=5687.28, stdev=16774.26
clat percentiles (usec):
| 1.00th=[ 1729], 5.00th=[ 2343], 10.00th=[ 2606], 20.00th=[ 2966],
| 30.00th=[ 3326], 40.00th=[ 3556], 50.00th=[ 3818], 60.00th=[ 4047],
| 70.00th=[ 4293], 80.00th=[ 4621], 90.00th=[ 5276], 95.00th=[ 5997],
| 99.00th=[ 46400], 99.50th=[102237], 99.90th=[235930], 99.95th=[299893],
| 99.99th=[497026]
bw ( KiB/s): min= 32, max=21088, per=12.69%, avg=11272.85, stdev=4574.15, samples=1197
iops : min= 8, max= 5272, avg=2817.91, stdev=1143.53, samples=1197
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.03%, 1000=0.23%
lat (msec) : 2=1.43%, 4=56.67%, 10=39.15%, 20=0.79%, 50=0.71%
lat (msec) : 100=0.45%, 250=0.42%, 500=0.08%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.77%, sys=72.24%, ctx=899175, 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,1684919,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=1137: Wed Dec 13 16:14:21 2017
write: IOPS=2813, BW=10.0MiB/s (11.5MB/s)(6593MiB/600001msec)
slat (usec): min=5, max=585328, avg=328.40, stdev=3937.41
clat (usec): min=134, max=626978, avg=5346.05, stdev=15758.18
lat (usec): min=141, max=627505, avg=5677.59, stdev=16313.91
clat percentiles (usec):
| 1.00th=[ 1418], 5.00th=[ 2278], 10.00th=[ 2573], 20.00th=[ 2933],
| 30.00th=[ 3294], 40.00th=[ 3556], 50.00th=[ 3818], 60.00th=[ 4047],
| 70.00th=[ 4293], 80.00th=[ 4686], 90.00th=[ 5407], 95.00th=[ 6063],
| 99.00th=[ 42730], 99.50th=[104334], 99.90th=[250610], 99.95th=[316670],
| 99.99th=[459277]
bw ( KiB/s): min= 104, max=22252, per=12.67%, avg=11258.18, stdev=4395.06, samples=1200
iops : min= 26, max= 5563, avg=2814.34, stdev=1098.77, samples=1200
lat (usec) : 250=0.03%, 500=0.02%, 750=0.08%, 1000=0.27%
lat (msec) : 2=1.71%, 4=55.92%, 10=39.49%, 20=0.86%, 50=0.71%
lat (msec) : 100=0.38%, 250=0.42%, 500=0.10%, 750=0.01%
cpu : usr=0.74%, sys=72.58%, ctx=934703, majf=0, minf=8
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,1687883,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=1138: Wed Dec 13 16:14:21 2017
write: IOPS=2422, BW=9689KiB/s (9921kB/s)(5677MiB/600001msec)
slat (usec): min=5, max=836561, avg=385.80, stdev=5028.24
clat (usec): min=83, max=911210, avg=6206.53, stdev=20455.78
lat (usec): min=143, max=911433, avg=6595.48, stdev=21201.82
clat percentiles (usec):
| 1.00th=[ 1303], 5.00th=[ 2245], 10.00th=[ 2540], 20.00th=[ 2900],
| 30.00th=[ 3294], 40.00th=[ 3556], 50.00th=[ 3818], 60.00th=[ 4047],
| 70.00th=[ 4359], 80.00th=[ 4752], 90.00th=[ 5473], 95.00th=[ 6259],
| 99.00th=[ 86508], 99.50th=[149947], 99.90th=[295699], 99.95th=[354419],
| 99.99th=[549454]
bw ( KiB/s): min= 48, max=28440, per=10.94%, avg=9712.94, stdev=5482.06, samples=1198
iops : min= 12, max= 7110, avg=2428.04, stdev=1370.51, samples=1198
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.03%, 1000=0.36%
lat (msec) : 2=2.00%, 4=55.19%, 10=39.22%, 20=0.84%, 50=0.84%
lat (msec) : 100=0.61%, 250=0.73%, 500=0.14%, 750=0.01%, 1000=0.01%
cpu : usr=0.66%, sys=63.84%, ctx=1410998, 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,1453347,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=86.7MiB/s (90.0MB/s), 9689KiB/s-11.7MiB/s (9921kB/s-12.2MB/s), io=50.8GiB (54.6GB), run=600001-600002msec

Disk stats (read/write):
vdb: ios=0/39272, merge=0/258, ticks=0/3274077, in_queue=2287355, util=22.13%