Fio Baseline Profiles Improved
This post just shows how I broke the fio job profile I’ve been using into smaller individual files and modified them to take device to test as an environment variable from the command line. There really is not much more to say, and my attention has turned to recovering an array damaged by an unintended power outage that was my own fault while tracing cables.
Fio Job Profiles
Sequential reads using big blocks.
rbb.fio
; -- Read Big Blocks --
[global]
description="Sequential big block reads"
directory=${DIRECTORY}
filename=test.file
ioengine=libaio
stonewall
size=2g
io_size=10g
direct=1
group_reporting=1
runtime=60
log_avg_msec=500
write_bw_log
write_iops_log
write_lat_log
rw=read
blocksize=1024k
iodepth=32
fsync=10000
; reads big blocks job
[job0.0-rbb]
[job0.1-rbb]
[job0.2-rbb]
[job0.3-rbb]Sequential writes using big blocks.
wbb.fio
; -- Write Big Blocks --
[global]
description="Sequential big block writes"
directory=${DIRECTORY}
filename=test.file
ioengine=libaio
stonewall
size=2g
io_size=10g
direct=1
group_reporting=1
runtime=60
log_avg_msec=500
write_bw_log
write_iops_log
write_lat_log
rw=write
blocksize=1024k
iodepth=32
fsync=10000
; write big blocks job
[job0.0-wbb]
[job0.1-wbb]
[job0.2-wbb]
[job0.3-wbb]Random reads using small 4k blocks.
wbb.fio
; -- Random Read 4k Blocks --
[global]
description="Random 4K block reads"
directory=${DIRECTORY}
filename=test.file
ioengine=libaio
stonewall
size=2g
io_size=10g
direct=1
group_reporting=1
runtime=60
log_avg_msec=500
write_bw_log
write_iops_log
write_lat_log
rw=randread
blocksize=4k
iodepth=1
fsync=1
; reads 4k blocks job
[job0.0-r4b]
[job0.1-r4b]
[job0.2-r4b]
[job0.3-r4b]Random writes using small 4k blocks.
w4b.fio
; -- Random Write 4k Blocks --
[global]
description="Random 4K block writes"
directory=${DIRECTORY}
filename=test.file
ioengine=libaio
stonewall
size=2g
io_size=10g
direct=1
group_reporting=1
runtime=60
log_avg_msec=500
write_bw_log
write_iops_log
write_lat_log
blocksize=4k
rw=randwrite
iodepth=1
fsync=1
; writes 4k blocks job
[job0.0-w4b]
[job0.1-w4b]
[job0.2-w4b]
[job0.3-w4b]Putting It to the Test
Not to put it to the test, in the example bleo I call the execution of each of the profiles, each of which repeats four time for a duration of 60 seconds per test job. As a result I expect the overall testing to take about 16 minnutes to complete. Logs are written so that graphs can be generated if desired.
Notes:
- I am testing the perfomance of the disks behind
/mnt/dasd3/by specifying in the environment variable DIRECTORY. - I am running
fiofrom a subdirectory under where the job profiles are stored so the generated logs are stored in the same subdirectory and not intermingled with the job profiles. timecommand not required. I just wanted to know how long it took to complete for comparison agains my expectation of 16 minutes.
Here is the command I use:
time sudo DIRECTORY="/mnt/dasd3/" fio ../rbb.fio ../wbb.fio ../r4b.fio ../w4b.fio
$ time sudo DIRECTORY="/mnt/dasd3" fio ../rbb.fio ../wbb.fio ../r4b.fio ../w4b.fio
job0.0-rbb: (g=0): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.1-rbb: (g=1): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.2-rbb: (g=2): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.3-rbb: (g=3): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.0-wbb: (g=4): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.1-wbb: (g=5): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.2-wbb: (g=6): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.3-wbb: (g=7): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
job0.0-r4b: (g=8): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.1-r4b: (g=9): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.2-r4b: (g=10): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.3-r4b: (g=11): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.0-w4b: (g=12): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.1-w4b: (g=13): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.2-w4b: (g=14): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
job0.3-w4b: (g=15): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.27
Starting 16 processes
Jobs: 1 (f=1): [_(8),r(1),P(7)][33.7%][r=20KiB/s,w=48.0MiB/s][r=5,w=48 IOPS][eta 15m:5Jobs: 1 (f=1): [_(8),r(1),P(7)][33.7%][r=212KiB/s][r=53 IOPS][eta 15m:58s] Jo
bs: 1 (f=1): [_(15),w(1)][51.8%][w=120KiB/s][w=30 IOPS][eta 15m:00s]
job0.0-rbb: (groupid=0, jobs=1): err= 0: pid=1213572: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block reads"]
read: IOPS=96, BW=96.0MiB/s (101MB/s)(5792MiB/60311msec)
slat (usec): min=11, max=4507, avg=35.06, stdev=61.49
clat (msec): min=24, max=2182, avg=332.96, stdev=57.44
lat (msec): min=29, max=2182, avg=333.00, stdev=57.43
clat percentiles (msec):
| 1.00th=[ 213], 5.00th=[ 305], 10.00th=[ 305], 20.00th=[ 313],
| 30.00th=[ 317], 40.00th=[ 321], 50.00th=[ 326], 60.00th=[ 334],
| 70.00th=[ 338], 80.00th=[ 347], 90.00th=[ 368], 95.00th=[ 380],
| 99.00th=[ 542], 99.50th=[ 592], 99.90th=[ 793], 99.95th=[ 885],
| 99.99th=[ 2198]
bw ( KiB/s): min=77824, max=108761, per=99.86%, avg=98199.30, stdev=6406.14, samples=120
iops : min= 76, max= 106, avg=95.80, stdev= 6.26, samples=120
lat (msec) : 50=0.10%, 100=0.29%, 250=0.83%, 500=97.58%, 750=0.98%
lat (msec) : 1000=0.17%, >=2000=0.03%
cpu : usr=0.18%, sys=0.74%, ctx=5816, majf=0, minf=551
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.4%, 16=0.8%, 32=98.4%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=5792,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.1-rbb: (groupid=1, jobs=1): err= 0: pid=1214142: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block reads"]
read: IOPS=95, BW=95.4MiB/s (100.0MB/s)(5754MiB/60338msec)
slat (usec): min=12, max=463, avg=36.54, stdev=20.90
clat (msec): min=32, max=640, avg=335.33, stdev=39.62
lat (msec): min=32, max=640, avg=335.36, stdev=39.61
clat percentiles (msec):
| 1.00th=[ 213], 5.00th=[ 305], 10.00th=[ 305], 20.00th=[ 317],
| 30.00th=[ 317], 40.00th=[ 326], 50.00th=[ 334], 60.00th=[ 338],
| 70.00th=[ 347], 80.00th=[ 355], 90.00th=[ 372], 95.00th=[ 380],
| 99.00th=[ 456], 99.50th=[ 550], 99.90th=[ 617], 99.95th=[ 634],
| 99.99th=[ 642]
bw ( KiB/s): min=65536, max=131334, per=99.79%, avg=97447.00, stdev=8112.86, samples=120
iops : min= 64, max= 128, avg=95.06, stdev= 7.92, samples=120
lat (msec) : 50=0.10%, 100=0.28%, 250=0.82%, 500=98.05%, 750=0.75%
cpu : usr=0.19%, sys=0.78%, ctx=5780, majf=0, minf=552
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.4%, 16=0.8%, 32=98.4%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=5754,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.2-rbb: (groupid=2, jobs=1): err= 0: pid=1214707: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block reads"]
read: IOPS=94, BW=94.3MiB/s (98.9MB/s)(5688MiB/60314msec)
slat (usec): min=12, max=390, avg=35.79, stdev=19.55
clat (msec): min=29, max=688, avg=339.08, stdev=43.22
lat (msec): min=29, max=688, avg=339.12, stdev=43.22
clat percentiles (msec):
| 1.00th=[ 241], 5.00th=[ 305], 10.00th=[ 309], 20.00th=[ 317],
| 30.00th=[ 321], 40.00th=[ 326], 50.00th=[ 334], 60.00th=[ 338],
| 70.00th=[ 347], 80.00th=[ 359], 90.00th=[ 376], 95.00th=[ 409],
| 99.00th=[ 489], 99.50th=[ 567], 99.90th=[ 651], 99.95th=[ 667],
| 99.99th=[ 693]
bw ( KiB/s): min=32768, max=149803, per=100.00%, avg=96632.87, stdev=10267.98, samples=120
iops : min= 32, max= 146, avg=94.27, stdev=10.00, samples=120
lat (msec) : 50=0.07%, 100=0.18%, 250=0.83%, 500=98.07%, 750=0.86%
cpu : usr=0.23%, sys=0.70%, ctx=5715, majf=0, minf=551
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.4%, 16=0.8%, 32=98.4%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=5688,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.3-rbb: (groupid=3, jobs=1): err= 0: pid=1215053: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block reads"]
read: IOPS=93, BW=93.8MiB/s (98.3MB/s)(5654MiB/60307msec)
slat (usec): min=11, max=2629, avg=37.00, stdev=40.55
clat (msec): min=27, max=1535, avg=341.07, stdev=65.71
lat (msec): min=28, max=1535, avg=341.11, stdev=65.71
clat percentiles (msec):
| 1.00th=[ 153], 5.00th=[ 305], 10.00th=[ 305], 20.00th=[ 313],
| 30.00th=[ 317], 40.00th=[ 326], 50.00th=[ 330], 60.00th=[ 338],
| 70.00th=[ 342], 80.00th=[ 363], 90.00th=[ 397], 95.00th=[ 426],
| 99.00th=[ 625], 99.50th=[ 718], 99.90th=[ 793], 99.95th=[ 835],
| 99.99th=[ 1536]
bw ( KiB/s): min=55296, max=129282, per=99.92%, avg=95927.39, stdev=10298.08, samples=120
iops : min= 54, max= 126, avg=93.58, stdev=10.05, samples=120
lat (msec) : 50=0.07%, 100=0.25%, 250=2.14%, 500=95.49%, 750=1.80%
lat (msec) : 1000=0.21%, 2000=0.04%
cpu : usr=0.25%, sys=0.71%, ctx=5683, majf=0, minf=551
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.4%, 16=0.8%, 32=98.4%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=5654,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.0-wbb: (groupid=4, jobs=1): err= 0: pid=1215791: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block writes"]
write: IOPS=83, BW=83.1MiB/s (87.1MB/s)(5014MiB/60336msec); 0 zone resets
slat (usec): min=23, max=431946, avg=751.92, stdev=15352.09
clat (msec): min=55, max=2004, avg=384.03, stdev=147.40
lat (msec): min=55, max=2004, avg=384.79, stdev=146.89
clat percentiles (msec):
| 1.00th=[ 112], 5.00th=[ 188], 10.00th=[ 245], 20.00th=[ 296],
| 30.00th=[ 321], 40.00th=[ 342], 50.00th=[ 368], 60.00th=[ 388],
| 70.00th=[ 414], 80.00th=[ 456], 90.00th=[ 531], 95.00th=[ 625],
| 99.00th=[ 911], 99.50th=[ 1070], 99.90th=[ 1418], 99.95th=[ 1653],
| 99.99th=[ 2005]
bw ( KiB/s): min=16384, max=120832, per=99.97%, avg=85067.03, stdev=18325.85, samples=119
iops : min= 16, max= 118, avg=82.98, stdev=17.88, samples=119
lat (msec) : 100=0.82%, 250=10.09%, 500=76.33%, 750=10.07%, 1000=1.95%
lat (msec) : 2000=0.72%, >=2000=0.02%
cpu : usr=0.42%, sys=0.18%, ctx=1955, majf=0, minf=24
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.5%, 16=1.0%, 32=98.1%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=0,5014,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.1-wbb: (groupid=5, jobs=1): err= 0: pid=1217558: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block writes"]
write: IOPS=85, BW=85.2MiB/s (89.3MB/s)(5149MiB/60443msec); 0 zone resets
slat (usec): min=23, max=512661, avg=827.30, stdev=16233.82
clat (msec): min=43, max=1864, avg=374.48, stdev=127.98
lat (msec): min=43, max=1865, avg=375.31, stdev=127.40
clat percentiles (msec):
| 1.00th=[ 104], 5.00th=[ 190], 10.00th=[ 245], 20.00th=[ 292],
| 30.00th=[ 326], 40.00th=[ 342], 50.00th=[ 363], 60.00th=[ 384],
| 70.00th=[ 405], 80.00th=[ 443], 90.00th=[ 510], 95.00th=[ 592],
| 99.00th=[ 785], 99.50th=[ 911], 99.90th=[ 1318], 99.95th=[ 1502],
| 99.99th=[ 1871]
bw ( KiB/s): min=30781, max=129024, per=100.00%, avg=87241.47, stdev=16863.95, samples=120
iops : min= 30, max= 126, avg=85.10, stdev=16.45, samples=120
lat (msec) : 50=0.06%, 100=0.89%, 250=9.94%, 500=78.19%, 750=9.71%
lat (msec) : 1000=0.87%, 2000=0.33%
cpu : usr=0.39%, sys=0.22%, ctx=1989, majf=0, minf=24
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.5%, 16=0.9%, 32=98.2%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=0,5149,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.2-wbb: (groupid=6, jobs=1): err= 0: pid=1219180: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block writes"]
write: IOPS=85, BW=85.0MiB/s (89.1MB/s)(5119MiB/60216msec); 0 zone resets
slat (usec): min=20, max=543710, avg=878.79, stdev=17448.98
clat (msec): min=43, max=1525, avg=375.36, stdev=125.27
lat (msec): min=43, max=1525, avg=376.24, stdev=124.77
clat percentiles (msec):
| 1.00th=[ 108], 5.00th=[ 194], 10.00th=[ 245], 20.00th=[ 292],
| 30.00th=[ 321], 40.00th=[ 342], 50.00th=[ 363], 60.00th=[ 384],
| 70.00th=[ 409], 80.00th=[ 443], 90.00th=[ 523], 95.00th=[ 592],
| 99.00th=[ 776], 99.50th=[ 885], 99.90th=[ 1099], 99.95th=[ 1183],
| 99.99th=[ 1519]
bw ( KiB/s): min=32833, max=131072, per=100.00%, avg=87087.52, stdev=17283.25, samples=119
iops : min= 32, max= 128, avg=84.94, stdev=16.87, samples=119
lat (msec) : 50=0.04%, 100=0.78%, 250=9.87%, 500=77.89%, 750=10.18%
lat (msec) : 1000=1.00%, 2000=0.25%
cpu : usr=0.34%, sys=0.27%, ctx=1956, majf=0, minf=22
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.5%, 16=0.9%, 32=98.2%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=0,5119,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.3-wbb: (groupid=7, jobs=1): err= 0: pid=1220654: Sun Oct 17 11:18:32 2021
Description : ["Sequential big block writes"]
write: IOPS=84, BW=84.7MiB/s (88.8MB/s)(5108MiB/60330msec); 0 zone resets
slat (usec): min=23, max=469524, avg=872.64, stdev=17184.25
clat (msec): min=51, max=2055, avg=376.83, stdev=124.23
lat (msec): min=51, max=2055, avg=377.70, stdev=123.88
clat percentiles (msec):
| 1.00th=[ 115], 5.00th=[ 201], 10.00th=[ 243], 20.00th=[ 296],
| 30.00th=[ 326], 40.00th=[ 347], 50.00th=[ 363], 60.00th=[ 388],
| 70.00th=[ 414], 80.00th=[ 451], 90.00th=[ 510], 95.00th=[ 575],
| 99.00th=[ 760], 99.50th=[ 927], 99.90th=[ 1200], 99.95th=[ 1385],
| 99.99th=[ 2056]
bw ( KiB/s): min=20480, max=129282, per=99.98%, avg=86681.95, stdev=17762.55, samples=120
iops : min= 20, max= 126, avg=84.55, stdev=17.32, samples=120
lat (msec) : 100=0.72%, 250=10.16%, 500=78.19%, 750=9.87%, 1000=0.76%
lat (msec) : 2000=0.27%, >=2000=0.02%
cpu : usr=0.36%, sys=0.23%, ctx=2023, majf=0, minf=21
IO depths : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.5%, 16=0.9%, 32=98.2%, >=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=99.9%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=0,5108,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
job0.0-r4b: (groupid=8, jobs=1): err= 0: pid=1222134: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block reads"]
read: IOPS=139, BW=560KiB/s (573kB/s)(32.8MiB/60005msec)
slat (usec): min=12, max=212, avg=34.07, stdev= 7.80
clat (usec): min=93, max=339833, avg=7104.46, stdev=7078.87
lat (usec): min=106, max=339851, avg=7139.67, stdev=7078.98
clat percentiles (usec):
| 1.00th=[ 1893], 5.00th=[ 2507], 10.00th=[ 2966], 20.00th=[ 3884],
| 30.00th=[ 4752], 40.00th=[ 5604], 50.00th=[ 6456], 60.00th=[ 7308],
| 70.00th=[ 8225], 80.00th=[ 9110], 90.00th=[ 9896], 95.00th=[ 10552],
| 99.00th=[ 28181], 99.50th=[ 35390], 99.90th=[ 64750], 99.95th=[100140],
| 99.99th=[341836]
bw ( KiB/s): min= 168, max= 705, per=100.00%, avg=560.56, stdev=124.52, samples=119
iops : min= 42, max= 176, avg=140.01, stdev=31.08, samples=119
lat (usec) : 100=0.01%, 250=0.04%, 500=0.10%, 750=0.01%
lat (msec) : 2=1.08%, 4=20.06%, 10=69.24%, 20=7.03%, 50=2.29%
lat (msec) : 100=0.08%, 250=0.04%, 500=0.02%
cpu : usr=0.25%, sys=1.13%, ctx=8418, majf=0, minf=25
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 rwts: total=8398,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.1-r4b: (groupid=9, jobs=1): err= 0: pid=1223488: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block reads"]
read: IOPS=144, BW=580KiB/s (593kB/s)(34.0MiB/60001msec)
slat (usec): min=12, max=123, avg=34.44, stdev= 6.90
clat (usec): min=211, max=280938, avg=6861.22, stdev=6906.01
lat (usec): min=250, max=280973, avg=6896.78, stdev=6906.34
clat percentiles (usec):
| 1.00th=[ 1942], 5.00th=[ 2507], 10.00th=[ 2966], 20.00th=[ 3818],
| 30.00th=[ 4686], 40.00th=[ 5538], 50.00th=[ 6456], 60.00th=[ 7308],
| 70.00th=[ 8094], 80.00th=[ 8979], 90.00th=[ 9765], 95.00th=[ 10290],
| 99.00th=[ 29754], 99.50th=[ 34866], 99.90th=[ 90702], 99.95th=[139461],
| 99.99th=[278922]
bw ( KiB/s): min= 88, max= 721, per=99.91%, avg=579.99, stdev=95.17, samples=119
iops : min= 22, max= 180, avg=144.87, stdev=23.70, samples=119
lat (usec) : 250=0.02%, 500=0.10%
lat (msec) : 2=1.13%, 4=20.72%, 10=70.76%, 20=5.84%, 50=1.27%
lat (msec) : 100=0.07%, 250=0.07%, 500=0.02%
cpu : usr=0.16%, sys=1.26%, ctx=8715, majf=0, minf=25
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 rwts: total=8693,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.2-r4b: (groupid=10, jobs=1): err= 0: pid=1225294: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block reads"]
read: IOPS=146, BW=586KiB/s (600kB/s)(34.3MiB/60004msec)
slat (usec): min=13, max=194, avg=34.26, stdev= 7.57
clat (usec): min=276, max=262949, avg=6786.41, stdev=6240.62
lat (usec): min=302, max=262970, avg=6821.82, stdev=6240.79
clat percentiles (usec):
| 1.00th=[ 1942], 5.00th=[ 2507], 10.00th=[ 2966], 20.00th=[ 3785],
| 30.00th=[ 4621], 40.00th=[ 5473], 50.00th=[ 6390], 60.00th=[ 7242],
| 70.00th=[ 8029], 80.00th=[ 8848], 90.00th=[ 9765], 95.00th=[ 10290],
| 99.00th=[ 28443], 99.50th=[ 34866], 99.90th=[ 67634], 99.95th=[160433],
| 99.99th=[263193]
bw ( KiB/s): min= 248, max= 697, per=100.00%, avg=586.18, stdev=78.21, samples=119
iops : min= 62, max= 174, avg=146.40, stdev=19.51, samples=119
lat (usec) : 500=0.18%, 1000=0.01%
lat (msec) : 2=0.94%, 4=21.30%, 10=70.14%, 20=6.10%, 50=1.18%
lat (msec) : 100=0.08%, 250=0.05%, 500=0.01%
cpu : usr=0.30%, sys=1.13%, ctx=8810, majf=0, minf=25
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 rwts: total=8789,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.3-r4b: (groupid=11, jobs=1): err= 0: pid=1226862: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block reads"]
read: IOPS=148, BW=594KiB/s (608kB/s)(34.8MiB/60003msec)
slat (usec): min=12, max=143, avg=34.29, stdev= 7.20
clat (usec): min=240, max=249427, avg=6690.50, stdev=5831.92
lat (usec): min=268, max=249465, avg=6725.93, stdev=5831.87
clat percentiles (msec):
| 1.00th=[ 3], 5.00th=[ 3], 10.00th=[ 3], 20.00th=[ 4],
| 30.00th=[ 5], 40.00th=[ 6], 50.00th=[ 7], 60.00th=[ 8],
| 70.00th=[ 9], 80.00th=[ 9], 90.00th=[ 10], 95.00th=[ 11],
| 99.00th=[ 22], 99.50th=[ 36], 99.90th=[ 65], 99.95th=[ 79],
| 99.99th=[ 249]
bw ( KiB/s): min= 264, max= 689, per=99.96%, avg=594.27, stdev=70.68, samples=119
iops : min= 66, max= 172, avg=148.41, stdev=17.63, samples=119
lat (usec) : 250=0.02%, 500=0.07%
lat (msec) : 2=0.82%, 4=21.44%, 10=70.79%, 20=5.79%, 50=0.94%
lat (msec) : 100=0.09%, 250=0.04%
cpu : usr=0.32%, sys=1.15%, ctx=8929, majf=0, minf=25
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 rwts: total=8914,0,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.0-w4b: (groupid=12, jobs=1): err= 0: pid=1228307: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block writes"]
write: IOPS=28, BW=114KiB/s (117kB/s)(6864KiB/60007msec); 0 zone resets
slat (usec): min=19, max=101, avg=38.99, stdev= 7.04
clat (msec): min=7, max=253, avg=12.66, stdev= 8.47
lat (msec): min=7, max=253, avg=12.70, stdev= 8.47
clat percentiles (msec):
| 1.00th=[ 8], 5.00th=[ 8], 10.00th=[ 9], 20.00th=[ 10],
| 30.00th=[ 11], 40.00th=[ 11], 50.00th=[ 12], 60.00th=[ 13],
| 70.00th=[ 14], 80.00th=[ 15], 90.00th=[ 16], 95.00th=[ 19],
| 99.00th=[ 32], 99.50th=[ 40], 99.90th=[ 148], 99.95th=[ 253],
| 99.99th=[ 253]
bw ( KiB/s): min= 40, max= 136, per=99.66%, avg=114.39, stdev=20.72, samples=119
iops : min= 10, max= 34, avg=28.60, stdev= 5.18, samples=119
lat (msec) : 10=28.79%, 20=67.07%, 50=3.79%, 100=0.17%, 250=0.12%
lat (msec) : 500=0.06%
fsync/fdatasync/sync_file_range:
sync (nsec): min=300, max=5299, avg=613.85, stdev=204.02
sync percentiles (nsec):
| 1.00th=[ 310], 5.00th=[ 326], 10.00th=[ 434], 20.00th=[ 532],
| 30.00th=[ 532], 40.00th=[ 532], 50.00th=[ 548], 60.00th=[ 580],
| 70.00th=[ 652], 80.00th=[ 756], 90.00th=[ 852], 95.00th=[ 948],
| 99.00th=[ 1112], 99.50th=[ 1160], 99.90th=[ 1336], 99.95th=[ 5280],
| 99.99th=[ 5280]
cpu : usr=0.20%, sys=0.28%, ctx=3442, majf=0, minf=24
IO depths : 1=199.9%, 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 rwts: total=0,1716,0,1715 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.1-w4b: (groupid=13, jobs=1): err= 0: pid=1229819: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block writes"]
write: IOPS=30, BW=122KiB/s (125kB/s)(7308KiB/60009msec); 0 zone resets
slat (nsec): min=19600, max=88638, avg=38284.49, stdev=6851.61
clat (usec): min=7029, max=39035, avg=11747.44, stdev=3509.84
lat (usec): min=7061, max=39061, avg=11787.09, stdev=3510.16
clat percentiles (usec):
| 1.00th=[ 7242], 5.00th=[ 7635], 10.00th=[ 8029], 20.00th=[ 8848],
| 30.00th=[ 9765], 40.00th=[10683], 50.00th=[11600], 60.00th=[12387],
| 70.00th=[13173], 80.00th=[13960], 90.00th=[14877], 95.00th=[15270],
| 99.00th=[29230], 99.50th=[32113], 99.90th=[36963], 99.95th=[39060],
| 99.99th=[39060]
bw ( KiB/s): min= 72, max= 136, per=99.36%, avg=121.79, stdev=11.58, samples=119
iops : min= 18, max= 34, avg=30.45, stdev= 2.90, samples=119
lat (msec) : 10=33.22%, 20=64.70%, 50=2.08%
fsync/fdatasync/sync_file_range:
sync (nsec): min=301, max=3277, avg=586.68, stdev=170.63
sync percentiles (nsec):
| 1.00th=[ 310], 5.00th=[ 318], 10.00th=[ 378], 20.00th=[ 532],
| 30.00th=[ 532], 40.00th=[ 532], 50.00th=[ 548], 60.00th=[ 556],
| 70.00th=[ 612], 80.00th=[ 692], 90.00th=[ 820], 95.00th=[ 884],
| 99.00th=[ 1080], 99.50th=[ 1128], 99.90th=[ 1288], 99.95th=[ 3280],
| 99.99th=[ 3280]
cpu : usr=0.00%, sys=0.51%, ctx=3668, majf=0, minf=25
IO depths : 1=200.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 rwts: total=0,1827,0,1827 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.2-w4b: (groupid=14, jobs=1): err= 0: pid=1231280: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block writes"]
write: IOPS=29, BW=120KiB/s (123kB/s)(7196KiB/60009msec); 0 zone resets
slat (usec): min=18, max=207, avg=38.94, stdev=10.12
clat (msec): min=6, max=331, avg=12.14, stdev= 9.24
lat (msec): min=7, max=331, avg=12.18, stdev= 9.24
clat percentiles (msec):
| 1.00th=[ 8], 5.00th=[ 8], 10.00th=[ 9], 20.00th=[ 9],
| 30.00th=[ 10], 40.00th=[ 11], 50.00th=[ 12], 60.00th=[ 13],
| 70.00th=[ 14], 80.00th=[ 15], 90.00th=[ 16], 95.00th=[ 16],
| 99.00th=[ 34], 99.50th=[ 37], 99.90th=[ 163], 99.95th=[ 334],
| 99.99th=[ 334]
bw ( KiB/s): min= 48, max= 144, per=99.24%, avg=119.85, stdev=15.45, samples=120
iops : min= 12, max= 36, avg=29.96, stdev= 3.86, samples=120
lat (msec) : 10=32.07%, 20=65.65%, 50=2.17%, 250=0.06%, 500=0.06%
fsync/fdatasync/sync_file_range:
sync (nsec): min=300, max=5287, avg=595.02, stdev=216.23
sync percentiles (nsec):
| 1.00th=[ 310], 5.00th=[ 314], 10.00th=[ 370], 20.00th=[ 532],
| 30.00th=[ 532], 40.00th=[ 532], 50.00th=[ 548], 60.00th=[ 564],
| 70.00th=[ 620], 80.00th=[ 716], 90.00th=[ 820], 95.00th=[ 908],
| 99.00th=[ 1128], 99.50th=[ 1192], 99.90th=[ 3280], 99.95th=[ 5280],
| 99.99th=[ 5280]
cpu : usr=0.13%, sys=0.37%, ctx=3615, majf=0, minf=25
IO depths : 1=199.9%, 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 rwts: total=0,1799,0,1798 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
job0.3-w4b: (groupid=15, jobs=1): err= 0: pid=1232863: Sun Oct 17 11:18:32 2021
Description : ["Random 4K block writes"]
write: IOPS=30, BW=120KiB/s (123kB/s)(7220KiB/60011msec); 0 zone resets
slat (usec): min=21, max=145, avg=38.33, stdev= 8.14
clat (msec): min=7, max=242, avg=11.89, stdev= 6.85
lat (msec): min=7, max=242, avg=11.93, stdev= 6.85
clat percentiles (msec):
| 1.00th=[ 8], 5.00th=[ 8], 10.00th=[ 8], 20.00th=[ 9],
| 30.00th=[ 10], 40.00th=[ 11], 50.00th=[ 12], 60.00th=[ 13],
| 70.00th=[ 14], 80.00th=[ 14], 90.00th=[ 15], 95.00th=[ 16],
| 99.00th=[ 31], 99.50th=[ 35], 99.90th=[ 90], 99.95th=[ 243],
| 99.99th=[ 243]
bw ( KiB/s): min= 64, max= 136, per=99.74%, avg=120.33, stdev=13.38, samples=120
iops : min= 16, max= 34, avg=30.08, stdev= 3.34, samples=120
lat (msec) : 10=33.41%, 20=64.71%, 50=1.72%, 100=0.11%, 250=0.06%
fsync/fdatasync/sync_file_range:
sync (nsec): min=310, max=18168, avg=687.51, stdev=463.57
sync percentiles (nsec):
| 1.00th=[ 314], 5.00th=[ 378], 10.00th=[ 450], 20.00th=[ 524],
| 30.00th=[ 572], 40.00th=[ 612], 50.00th=[ 676], 60.00th=[ 732],
| 70.00th=[ 780], 80.00th=[ 828], 90.00th=[ 900], 95.00th=[ 964],
| 99.00th=[ 1112], 99.50th=[ 1128], 99.90th=[ 5728], 99.95th=[18048],
| 99.99th=[18048]
cpu : usr=0.08%, sys=0.39%, ctx=3619, majf=0, minf=24
IO depths : 1=200.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 rwts: total=0,1805,0,1805 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1
Run status group 0 (all jobs):
READ: bw=96.0MiB/s (101MB/s), 96.0MiB/s-96.0MiB/s (101MB/s-101MB/s), io=5792MiB (6073MB), run=60311-60311msec
Run status group 1 (all jobs):
READ: bw=95.4MiB/s (100.0MB/s), 95.4MiB/s-95.4MiB/s (100.0MB/s-100.0MB/s), io=5754MiB (6034MB), run=60338-60338msec
Run status group 2 (all jobs):
READ: bw=94.3MiB/s (98.9MB/s), 94.3MiB/s-94.3MiB/s (98.9MB/s-98.9MB/s), io=5688MiB (5964MB), run=60314-60314msec
Run status group 3 (all jobs):
READ: bw=93.8MiB/s (98.3MB/s), 93.8MiB/s-93.8MiB/s (98.3MB/s-98.3MB/s), io=5654MiB (5929MB), run=60307-60307msec
Run status group 4 (all jobs):
WRITE: bw=83.1MiB/s (87.1MB/s), 83.1MiB/s-83.1MiB/s (87.1MB/s-87.1MB/s), io=5014MiB (5258MB), run=60336-60336msec
Run status group 5 (all jobs):
WRITE: bw=85.2MiB/s (89.3MB/s), 85.2MiB/s-85.2MiB/s (89.3MB/s-89.3MB/s), io=5149MiB (5399MB), run=60443-60443msec
Run status group 6 (all jobs):
WRITE: bw=85.0MiB/s (89.1MB/s), 85.0MiB/s-85.0MiB/s (89.1MB/s-89.1MB/s), io=5119MiB (5368MB), run=60216-60216msec
Run status group 7 (all jobs):
WRITE: bw=84.7MiB/s (88.8MB/s), 84.7MiB/s-84.7MiB/s (88.8MB/s-88.8MB/s), io=5108MiB (5356MB), run=60330-60330msec
Run status group 8 (all jobs):
READ: bw=560KiB/s (573kB/s), 560KiB/s-560KiB/s (573kB/s-573kB/s), io=32.8MiB (34.4MB), run=60005-60005msec
Run status group 9 (all jobs):
READ: bw=580KiB/s (593kB/s), 580KiB/s-580KiB/s (593kB/s-593kB/s), io=34.0MiB (35.6MB), run=60001-60001msec
Run status group 10 (all jobs):
READ: bw=586KiB/s (600kB/s), 586KiB/s-586KiB/s (600kB/s-600kB/s), io=34.3MiB (36.0MB), run=60004-60004msec
Run status group 11 (all jobs):
READ: bw=594KiB/s (608kB/s), 594KiB/s-594KiB/s (608kB/s-608kB/s), io=34.8MiB (36.5MB), run=60003-60003msec
Run status group 12 (all jobs):
WRITE: bw=114KiB/s (117kB/s), 114KiB/s-114KiB/s (117kB/s-117kB/s), io=6864KiB (7029kB), run=60007-60007msec
Run status group 13 (all jobs):
WRITE: bw=122KiB/s (125kB/s), 122KiB/s-122KiB/s (125kB/s-125kB/s), io=7308KiB (7483kB), run=60009-60009msec
Run status group 14 (all jobs):
WRITE: bw=120KiB/s (123kB/s), 120KiB/s-120KiB/s (123kB/s-123kB/s), io=7196KiB (7369kB), run=60009-60009msec
Run status group 15 (all jobs):
WRITE: bw=120KiB/s (123kB/s), 120KiB/s-120KiB/s (123kB/s-123kB/s), io=7220KiB (7393kB), run=60011-60011msec
Disk stats (read/write):
dm-7: ios=57686/49205, merge=0/0, ticks=7894350/7818370, in_queue=15712720, util=99.50%, aggrios=57763/70192, aggrmerge=0/0, aggrticks=7939800/70474480, aggrin_queue=78414280, aggrutil=99.11%
dm-0: ios=57763/70192, merge=0/0, ticks=7939800/70474480, in_queue=78414280, util=99.11%, aggrios=59018/66562, aggrmerge=3/15234, aggrticks=8221168/13131242, aggrin_queue=21352410, aggrutil=98.26%
sdb: ios=59018/66562, merge=3/15234, ticks=8221168/13131242, in_queue=21352410, util=98.26%
real 16m8.922s
user 0m2.921s
sys 0m6.983s
$Duration was just about 16 minutes as expected.
Conclusion
Things still seem to work as I expect, and it is notw a bitt easier to test out different drives and devices with environt variables passed on the command line rather than editing the profiles each time.
Chrls is currently a technology transformation leader at one of the oldest American investment banking services holding companies, headquartered in New York City. Previous roles at current employer include project manager, front office support, retail and enterprise global Windows server support. Currently residing in Tennessee on the Cumberland Plateau and enjoying life, family and open source.
Mastodon Diaspora Funkwhale Pixelfed