Skip to content

Instantly share code, notes, and snippets.

@mattmacy
Last active February 26, 2018 08:31
Show Gist options
  • Star 1 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save mattmacy/5b209a27b7891b3acb3b23f96031bbd9 to your computer and use it in GitHub Desktop.
Save mattmacy/5b209a27b7891b3acb3b23f96031bbd9 to your computer and use it in GitHub Desktop.
sdb-sde are 64G zvols on a striped zpool of 8 mirrors
fio was created by:
lvcreate -L 240G -i4 -I64 -n fio TestVolGroup
guest command:
doas cpuset -c -l 16-31 -n ft:1 -- grub-bhyve -S -m /chyves/storage/guests/ubi0/device.map -r hd0,msdos1 -c /dev/nmdm52A -M 32G chy-ubi0; doas cpuset -c -l 16-31 -n ft:1 -- bhyve -A -H -P -S -c 16 -U ec30b988-f5aa-11e7-a76c-ac1f6b0a8cd2 -m 32G -s 0,hostbridge -s
4,ahci-hd,/dev/zvol/storage/chyves/guests/ubi0/disk0 -s 5,virtio-net,tap52 -s 6,kvirtio-net,mtu=1500,queues=4,intf=cc0,mac=00:07:43:3d:92:d1 -s 7,ahci-hd,/dev/zvol/storage/chyves/guests/ubi0/disk1 -s 8,ahci-hd,/dev/zvol/storage/chyves/guests/ubi0/disk2 -s 9,ahci-hd,/dev/zvol/storage/chyves/guests/ubi0/disk3 -s 10,ahci-hd,/dev/zvol/storage/chyves/guests/ubi0/disk4 -l com1,/dev/nmdm52A -s 31,lpc chy-ubi0
ARC MAX 8G (in use 8G)
mmacy@ubi0:/fio$ fio --direct=1 --rw=randrw --refill_buffers --norandommap --randrepeat=0 --ioengine=libaio --bs=4k --rwmixread=80 --iodepth=32 --numjobs=12 --runtime=240 --group_reporting --name=randwrite
randwrite: (g=0): rw=randrw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32
...
fio-2.2.10
Starting 12 processes
Jobs: 1 (f=0): [_(11),m(1)] [23.0% done] [120.2MB/31193KB/0KB /s] [30.8K/7798/0 iops] [eta 13m:28s]
randwrite: (groupid=0, jobs=12): err= 0: pid=7524: Sun Feb 25 21:54:49 2018
read : io=35479MB, bw=151371KB/s, iops=37842, runt=240010msec
slat (usec): min=0, max=283605, avg=173.00, stdev=2443.61
clat (usec): min=0, max=359621, avg=6389.00, stdev=16356.63
lat (usec): min=1, max=359627, avg=6562.22, stdev=16661.39
clat percentiles (usec):
| 1.00th=[ 0], 5.00th=[ 1], 10.00th=[ 22], 20.00th=[ 151],
| 30.00th=[ 374], 40.00th=[ 724], 50.00th=[ 1512], 60.00th=[ 3728],
| 70.00th=[ 6752], 80.00th=[10176], 90.00th=[15808], 95.00th=[22144],
| 99.00th=[44800], 99.50th=[60160], 99.90th=[257024], 99.95th=[268288],
| 99.99th=[284672]
bw (KB /s): min= 3880, max=18110, per=8.42%, avg=12749.97, stdev=2810.34
write: io=8876.2MB, bw=37870KB/s, iops=9467, runt=240010msec
slat (usec): min=2, max=280995, avg=384.68, stdev=4616.02
clat (usec): min=0, max=363578, avg=13935.91, stdev=24838.33
lat (usec): min=77, max=363592, avg=14320.91, stdev=25413.84
clat percentiles (usec):
| 1.00th=[ 398], 5.00th=[ 740], 10.00th=[ 1128], 20.00th=[ 2160],
| 30.00th=[ 4192], 40.00th=[ 6304], 50.00th=[ 8256], 60.00th=[10560],
| 70.00th=[13504], 80.00th=[17792], 90.00th=[28800], 95.00th=[44288],
| 99.00th=[90624], 99.50th=[242688], 99.90th=[276480], 99.95th=[284672],
| 99.99th=[309248]
bw (KB /s): min= 1056, max= 4744, per=8.42%, avg=3189.29, stdev=702.76
lat (usec) : 2=4.63%, 4=0.38%, 10=1.53%, 20=1.23%, 50=2.58%
lat (usec) : 100=3.15%, 250=6.48%, 500=7.86%, 750=5.58%, 1000=3.92%
lat (msec) : 2=9.14%, 4=8.00%, 10=20.62%, 20=16.60%, 50=6.92%
lat (msec) : 100=0.92%, 250=0.26%, 500=0.20%
cpu : usr=0.66%, sys=13.02%, ctx=1241509, majf=0, minf=150
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.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.1%, 64=0.0%, >=64=0.0%
issued : total=r=9082651/w=2272287/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=32
Run status group 0 (all jobs):
READ: io=35479MB, aggrb=151371KB/s, minb=151371KB/s, maxb=151371KB/s, mint=240010msec, maxt=240010msec
WRITE: io=8876.2MB, aggrb=37869KB/s, minb=37869KB/s, maxb=37869KB/s, mint=240010msec, maxt=240010msec
Disk stats (read/write):
dm-0: ios=4490445/4328800, merge=0/0, ticks=28141972/39192764, in_queue=67501792, util=99.84%, aggrios=1123630/802876, aggrmerge=4/280082, aggrticks=6771536/5122267, aggrin_queue=11890084, aggrutil=96.59%
sdb: ios=1157489/801419, merge=14/280107, ticks=18247640/14554684, in_queue=32804024, util=96.59%
sdc: ios=1112065/798417, merge=3/280111, ticks=3915056/2561660, in_queue=6471652, util=95.19%
sdd: ios=1109851/807468, merge=0/280039, ticks=2564268/1672036, in_queue=4230008, util=90.04%
sde: ios=1115116/804203, merge=1/280073, ticks=2359180/1700688, in_queue=4054652, util=91.98%
fio --direct=1 --rw=randrw --refill_buffers --norandommap --randrepeat=0 --ioengine=libaio --bs=4k --rwmixread=80 --iodepth=256 --numjobs=12 --runtime=960 --group_reporting --name=randwrite
randwrite: (g=0): rw=randrw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=256
...
fio-2.2.10
Starting 12 processes
Jobs: 3 (f=3): [m(2),_(1),m(1),_(8)] [99.8% done] [169.2MB/43147KB/0KB /s] [43.6K/10.8K/0 iops] [eta 00m:02s]
randwrite: (groupid=0, jobs=12): err= 0: pid=7203: Sun Feb 25 21:36:15 2018
read : io=157282MB, bw=172858KB/s, iops=43214, runt=931731msec
slat (usec): min=1, max=379075, avg=154.73, stdev=2806.82
clat (usec): min=0, max=631668, avg=54044.76, stdev=51997.19
lat (usec): min=2, max=641900, avg=54199.71, stdev=52093.02
clat percentiles (msec):
| 1.00th=[ 16], 5.00th=[ 23], 10.00th=[ 26], 20.00th=[ 30],
| 30.00th=[ 34], 40.00th=[ 38], 50.00th=[ 42], 60.00th=[ 46],
| 70.00th=[ 52], 80.00th=[ 60], 90.00th=[ 74], 95.00th=[ 101],
| 99.00th=[ 302], 99.50th=[ 314], 99.90th=[ 343], 99.95th=[ 359],
| 99.99th=[ 420]
bw (KB /s): min= 667, max=79376, per=8.50%, avg=14694.56, stdev=4305.17
write: io=39326MB, bw=43220KB/s, iops=10805, runt=931731msec
slat (usec): min=2, max=368745, avg=475.12, stdev=5621.93
clat (usec): min=794, max=677917, avg=66156.39, stdev=59813.11
lat (usec): min=834, max=686472, avg=66631.90, stdev=60157.90
clat percentiles (msec):
| 1.00th=[ 20], 5.00th=[ 26], 10.00th=[ 29], 20.00th=[ 35],
| 30.00th=[ 39], 40.00th=[ 44], 50.00th=[ 50], 60.00th=[ 56],
| 70.00th=[ 64], 80.00th=[ 76], 90.00th=[ 102], 95.00th=[ 249],
| 99.00th=[ 322], 99.50th=[ 338], 99.90th=[ 375], 99.95th=[ 392],
| 99.99th=[ 445]
bw (KB /s): min= 125, max=19536, per=8.50%, avg=3674.05, stdev=1081.80
lat (usec) : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01%
lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
lat (msec) : 2=0.02%, 4=0.07%, 10=0.44%, 20=1.63%, 50=62.00%
lat (msec) : 100=29.72%, 250=2.04%, 500=4.08%, 750=0.01%
cpu : usr=0.78%, sys=14.38%, ctx=2747930, majf=0, minf=151
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%
issued : total=r=40264243/w=10067405/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=256
Run status group 0 (all jobs):
READ: io=157282MB, aggrb=172857KB/s, minb=172857KB/s, maxb=172857KB/s, mint=931731msec, maxt=931731msec
WRITE: io=39326MB, aggrb=43220KB/s, minb=43220KB/s, maxb=43220KB/s, mint=931731msec, maxt=931731msec
Disk stats (read/write):
dm-0: ios=13732420/21931674, merge=0/0, ticks=68548908/219739420, in_queue=288918632, util=99.66%, aggrios=3434240/3856344, aggrmerge=8/1628685, aggrticks=16146121/27550702, aggrin_queue=43673925, aggrutil=92.89%
sdb: ios=3634421/3860037, merge=27/1628729, ticks=36304908/80945732, in_queue=117256772, util=90.73%
sdc: ios=3361812/3831760, merge=6/1628590, ticks=12981684/12961424, in_queue=25914060, util=92.89%
sdd: ios=3359985/3876112, merge=1/1628672, ticks=8089248/8087912, in_queue=16141344, util=82.83%
sde: ios=3380745/3857468, merge=1/1628752, ticks=7208644/8207740, in_queue=15383524, util=87.56%
sample gstat during run:
dT: 1.002s w: 1.000s
L(q) ops/s r/s kBps ms/r w/s kBps ms/w %busy Name
0 0 0 0 0.0 0 0 0.0 0.0| ada0
0 0 0 0 0.0 0 0 0.0 0.0| ada1
0 0 0 0 0.0 0 0 0.0 0.0| ada0p1
0 0 0 0 0.0 0 0 0.0 0.0| ada0p2
0 0 0 0 0.0 0 0 0.0 0.0| ada0p3
0 8187 3254 13017 0.5 4930 27303 0.3 55.9| zvol/storage/chyves/guests/ubi0/disk1
1 5124 1272 13276 0.4 1892 164060 0.2 64.6| da0
2 5098 1243 12546 0.4 1895 164351 0.2 64.2| da1
1 5160 1311 13795 0.4 1796 164435 0.2 65.9| da2
2 5135 1285 13460 0.4 1797 164838 0.2 65.8| da3
2 5159 1276 12793 0.4 1846 165979 0.2 65.3| da4
1 5146 1252 13208 0.4 1857 165401 0.2 65.9| da5
2 5345 1264 12797 0.4 2023 157839 0.2 64.1| da6
1 5363 1301 12949 0.4 2004 157180 0.2 64.0| da7
1 5238 1288 13224 0.4 1912 156574 0.2 64.8| da8
1 5203 1260 12809 0.4 1904 156155 0.2 63.8| da9
1 5151 1313 13875 0.4 1899 161889 0.2 64.7| da10
1 5121 1275 13484 0.4 1907 162404 0.2 64.5| da11
2 5306 1309 12742 0.4 1901 159602 0.2 65.4| da12
1 5343 1356 14162 0.4 1891 159407 0.2 64.8| da13
1 5085 1301 13085 0.4 1767 163206 0.3 64.8| da14
1 5051 1250 12714 0.4 1784 164040 0.3 64.4| da15
8 7731 2768 11074 0.5 4960 27426 0.3 60.9| zvol/storage/chyves/guests/ubi0/disk2
0 7861 2799 11197 0.5 5060 27825 0.3 62.5| zvol/storage/chyves/guests/ubi0/disk3
0 7673 2757 11030 0.5 4912 27207 0.3 62.1| zvol/storage/chyves/guests/ubi0/disk4
12 users Load 20.16 21.05 18.96 Feb 25 21:36
Mem usage: 75%Phy 62%Kmem
Mem: KB REAL VIRTUAL VN PAGER SWAP PAGER
Tot Share Tot Share Free in out in out
Act 32922K 8340 70661636 9784 64347K count
All 32928K 14648 70740480 88332 pages
Proc: Interrupts
r p d s w Csw Trp Sys Int Sof Flt ioflt 80003 total
3 123 0.9 0.4 0.6 44k 274 19k 3544 cow uart1 3
12818 zfod acpi0 9
58.8%Sys 0.9%Intr 1.9%User 0.0%Nice 38.4%Idle ozfod 1451 cpu0:timer
| | | | | | | | | | %ozfod 1125 cpu1:timer
=============================+> daefr 1129 cpu25:time
dtbuf 15363 prcfr 1129 cpu6:timer
Namei Name-cache Dir-cache 4241123 desvn 19850 totfr 1129 cpu14:time
Calls hits % hits % 1062 numvn react 1129 cpu30:time
1634 1634 100 507 frevn pdwak 1128 cpu2:timer
23 pdpgs 1129 cpu7:timer
Disks ada0 ada1 da0 da1 da2 da3 da4 intrn 1128 cpu26:time
KB/t 4.00 0.00 48.30 48.64 47.20 47.22 38.85 189743K wire 1127 cpu31:time
tps 5 0 4866 4829 4794 4792 5382 58204 act 1129 cpu24:time
MB/s 0.02 0.00 230 229 221 221 204 67284 inact 1125 cpu19:time
%busy 0 0 70 71 70 70 67 laund 1129 cpu12:time
65891616 free 1126 cpu23:time
buf 1128 cpu16:time
1126 cpu22:time
1126 cpu20:time
1129 cpu13:time
1128 cpu18:time
1129 cpu21:time
1128 cpu27:time
1129 cpu15:time
1129 cpu4:timer
1128 cpu28:time
1129 cpu8:timer
1129 cpu29:time
1129 cpu5:timer
1129 cpu10:time
1129 cpu11:time
1129 cpu3:timer
1129 cpu17:time
1128 cpu9:timer
5 ahci0 264
mmacy@ubi0:/fio$ fio --name=randwrite --ioengine=libaio --iodepth=64 --rw=randread --bs=4k --size=16G --numjobs=12 --runtime=240 --group_reporting --direct=1
randwrite: (g=0): rw=randread, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=64
...
fio-2.2.10
Starting 12 processes
Jobs: 3 (f=3): [r(2),_(1),r(1),_(8)] [94.2% done] [3620MB/0KB/0KB /s] [927K/0/0 iops] [eta 00m:10s]
randwrite: (groupid=0, jobs=12): err= 0: pid=5314: Sun Feb 25 20:46:33 2018
read : io=196608MB, bw=1211.8MB/s, iops=310034, runt=162342msec
slat (usec): min=0, max=123587, avg=33.60, stdev=385.60
clat (usec): min=0, max=525535, avg=2189.56, stdev=5856.49
lat (usec): min=1, max=525547, avg=2223.27, stdev=5965.15
clat percentiles (usec):
| 1.00th=[ 46], 5.00th=[ 97], 10.00th=[ 124], 20.00th=[ 153],
| 30.00th=[ 175], 40.00th=[ 199], 50.00th=[ 227], 60.00th=[ 266],
| 70.00th=[ 334], 80.00th=[ 532], 90.00th=[ 7648], 95.00th=[15168],
| 99.00th=[28544], 99.50th=[33024], 99.90th=[44288], 99.95th=[50432],
| 99.99th=[77312]
bw (KB /s): min= 3307, max=1282336, per=9.20%, avg=114098.42, stdev=229038.51
lat (usec) : 2=0.05%, 4=0.03%, 10=0.08%, 20=0.14%, 50=0.83%
lat (usec) : 100=4.18%, 250=50.79%, 500=23.09%, 750=3.69%, 1000=1.11%
lat (msec) : 2=1.24%, 4=1.60%, 10=4.98%, 20=5.26%, 50=2.88%
lat (msec) : 100=0.05%, 250=0.01%, 500=0.01%, 750=0.01%
cpu : usr=2.79%, sys=31.85%, ctx=249156, majf=0, minf=890
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%, >=64=0.0%
issued : total=r=50331648/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=64
Run status group 0 (all jobs):
READ: io=196608MB, aggrb=1211.8MB/s, minb=1211.8MB/s, maxb=1211.8MB/s, mint=162342msec, maxt=162342msec
Disk stats (read/write):
dm-0: ios=7001172/6, merge=0/0, ticks=30637908/24, in_queue=30775976, util=100.00%, aggrios=1750555/1, aggrmerge=244/0, aggrticks=7370948/3, aggrin_queue=7373608, aggrutil=97.87%
sdb: ios=1983764/1, merge=825/0, ticks=23235072/4, in_queue=23246084, util=97.87%
sdc: ios=1663389/1, merge=79/0, ticks=3862464/0, in_queue=3862100, util=89.74%
sdd: ios=1661084/4, merge=14/3, ticks=1342100/8, in_queue=1342108, util=77.20%
sde: ios=1693984/1, merge=59/0, ticks=1044156/0, in_queue=1044140, util=75.96%
mmacy@ubi0:/fio$ fio --name=randread --ioengine=libaio --iodepth=64 --rw=randread --bs=4k --direct=0 --size=16G --numjobs=12 --runtime=240 --group_reporting
randread: (g=0): rw=randread, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=64
...
fio-2.2.10
Starting 12 processes
Jobs: 12 (f=12): [r(12)] [100.0% done] [1005MB/0KB/0KB /s] [257K/0/0 iops] [eta 00m:00s]
randread: (groupid=0, jobs=12): err= 0: pid=3951: Sun Feb 25 20:25:11 2018
read : io=111160MB, bw=474280KB/s, iops=118569, runt=240001msec
slat (usec): min=2, max=28101, avg=99.29, stdev=182.49
clat (usec): min=1, max=68197, avg=6337.98, stdev=8444.42
lat (usec): min=7, max=68588, avg=6437.42, stdev=8576.91
clat percentiles (usec):
| 1.00th=[ 908], 5.00th=[ 1304], 10.00th=[ 1560], 20.00th=[ 1912],
| 30.00th=[ 2192], 40.00th=[ 2480], 50.00th=[ 2768], 60.00th=[ 3088],
| 70.00th=[ 3536], 80.00th=[ 4512], 90.00th=[24704], 95.00th=[25984],
| 99.00th=[27520], 99.50th=[28288], 99.90th=[31616], 99.95th=[34560],
| 99.99th=[48896]
bw (KB /s): min= 2, max=136208, per=8.36%, avg=39644.27, stdev=41749.92
lat (usec) : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01%
lat (usec) : 100=0.01%, 250=0.01%, 500=0.07%, 750=0.34%, 1000=1.14%
lat (msec) : 2=21.49%, 4=53.13%, 10=7.41%, 20=0.01%, 50=16.39%
lat (msec) : 100=0.01%
cpu : usr=1.58%, sys=11.66%, ctx=7273339, majf=0, minf=868
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%, >=64=0.0%
issued : total=r=28456894/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=64
Run status group 0 (all jobs):
READ: io=111160MB, aggrb=474279KB/s, minb=474279KB/s, maxb=474279KB/s, mint=240001msec, maxt=240001msec
Disk stats (read/write):
dm-0: ios=7264419/0, merge=0/0, ticks=2550996/0, in_queue=2557116, util=100.00%, aggrios=1817853/0, aggrmerge=0/0, aggrticks=639018/0, aggrin_queue=638779, aggrutil=98.24%
sdb: ios=2324546/0, merge=0/0, ticks=1000192/0, in_queue=999936, util=98.24%
sdc: ios=1757241/0, merge=0/0, ticks=589552/0, in_queue=589300, util=91.53%
sdd: ios=1603276/0, merge=0/0, ticks=495524/0, in_queue=495256, util=87.44%
sde: ios=1586352/0, merge=0/0, ticks=470804/0, in_queue=470624, util=86.21%
mmacy@ubi0:/fio$ fio --name=randwrite --ioengine=libaio --iodepth=64 --rw=randwrite --bs=4k --size=16G --numjobs=12 --runtime=240 --group_reporting --direct=1
randwrite: (g=0): rw=randwrite, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=64
...
fio-2.2.10
Starting 12 processes
Jobs: 12 (f=12): [w(12)] [100.0% done] [0KB/73051KB/0KB /s] [0/18.3K/0 iops] [eta 00m:00s]
randwrite: (groupid=0, jobs=12): err= 0: pid=4057: Sun Feb 25 20:43:02 2018
write: io=20784MB, bw=88623KB/s, iops=22155, runt=240145msec
slat (usec): min=2, max=344513, avg=380.79, stdev=3947.33
clat (usec): min=0, max=443841, avg=24358.45, stdev=32957.84
lat (usec): min=71, max=443858, avg=24739.60, stdev=33331.47
clat percentiles (usec):
| 1.00th=[ 788], 5.00th=[ 2608], 10.00th=[ 4960], 20.00th=[ 7776],
| 30.00th=[10432], 40.00th=[13120], 50.00th=[16064], 60.00th=[19840],
| 70.00th=[24192], 80.00th=[30336], 90.00th=[43264], 95.00th=[64768],
| 99.00th=[195584], 99.50th=[228352], 99.90th=[305152], 99.95th=[329728],
| 99.99th=[358400]
bw (KB /s): min= 0, max=47176, per=11.82%, avg=10478.67, stdev=5713.74
lat (usec) : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01%
lat (usec) : 100=0.02%, 250=0.12%, 500=0.37%, 750=0.43%, 1000=0.48%
lat (msec) : 2=2.22%, 4=4.21%, 10=20.61%, 20=32.24%, 50=31.70%
lat (msec) : 100=4.44%, 250=2.82%, 500=0.34%
cpu : usr=0.46%, sys=21.03%, ctx=1234892, majf=0, minf=137
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%, >=64=0.0%
issued : total=r=0/w=5320597/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=64
Run status group 0 (all jobs):
WRITE: io=20784MB, aggrb=88623KB/s, minb=88623KB/s, maxb=88623KB/s, mint=240145msec, maxt=240145msec
Disk stats (read/write):
dm-0: ios=0/9689760, merge=0/0, ticks=0/73560604, in_queue=73647536, util=99.55%, aggrios=0/1836336, aggrmerge=0/598629, aggrticks=0/9187431, aggrin_queue=9184782, aggrutil=93.90%
sdb: ios=0/2081763, merge=0/602237, ticks=0/27068380, in_queue=27074356, util=93.90%
sdc: ios=0/1743777, merge=0/595917, ticks=0/4488304, in_queue=4484184, util=92.28%
sdd: ios=0/1761398, merge=0/596407, ticks=0/2760464, in_queue=2753448, util=85.55%
sde: ios=0/1758407, merge=0/599957, ticks=0/2432576, in_queue=2427140, util=87.72%
ARC max: 250G (in use 33G)
mmacy@ubi0:/fio$ fio --name=randread --ioengine=libaio --iodepth=64 --rw=randread --bs=4k --direct=0 --size=16G --numjobs=12 --runtime=240 --group_reporting
randread: (g=0): rw=randread, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=64
...
fio-2.2.10
Starting 12 processes
Jobs: 10 (f=10): [r(5),_(2),r(5)] [33.8% done] [963.4MB/0KB/0KB /s] [247K/0/0 iops] [eta 07m:50s]
randread: (groupid=0, jobs=12): err= 0: pid=3918: Sun Feb 25 20:09:25 2018
read : io=139560MB, bw=595452KB/s, iops=148862, runt=240001msec
slat (usec): min=1, max=406221, avg=78.84, stdev=191.24
clat (usec): min=1, max=451702, avg=5044.82, stdev=6552.82
lat (usec): min=4, max=454327, avg=5123.80, stdev=6653.86
clat percentiles (usec):
| 1.00th=[ 796], 5.00th=[ 1144], 10.00th=[ 1368], 20.00th=[ 1688],
| 30.00th=[ 1960], 40.00th=[ 2224], 50.00th=[ 2512], 60.00th=[ 2864],
| 70.00th=[ 3312], 80.00th=[ 4192], 90.00th=[19328], 95.00th=[21376],
| 99.00th=[23936], 99.50th=[25216], 99.90th=[33536], 99.95th=[37632],
| 99.99th=[45824]
bw (KB /s): min= 2, max=196520, per=8.36%, avg=49794.40, stdev=46437.40
lat (usec) : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01%
lat (usec) : 100=0.01%, 250=0.01%, 500=0.13%, 750=0.65%, 1000=2.05%
lat (msec) : 2=28.67%, 4=47.29%, 10=7.21%, 20=5.74%, 50=8.26%
lat (msec) : 100=0.01%, 250=0.01%, 500=0.01%
cpu : usr=1.62%, sys=12.94%, ctx=8272468, majf=0, minf=868
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%, >=64=0.0%
issued : total=r=35727243/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=64
Run status group 0 (all jobs):
READ: io=139560MB, aggrb=595451KB/s, minb=595451KB/s, maxb=595451KB/s, mint=240001msec, maxt=240001msec
Disk stats (read/write):
dm-0: ios=8255523/6, merge=0/0, ticks=2498536/8, in_queue=2505772, util=100.00%, aggrios=2065612/1, aggrmerge=0/0, aggrticks=626138/2, aggrin_queue=625951, aggrutil=98.03%
sdb: ios=2494009/1, merge=0/0, ticks=1138284/0, in_queue=1138316, util=98.03%
sdc: ios=1981472/3, merge=0/2, ticks=556860/8, in_queue=556636, util=87.98%
sdd: ios=1891991/2, merge=0/1, ticks=422196/0, in_queue=421896, util=81.52%
sde: ios=1894976/1, merge=0/0, ticks=387212/0, in_queue=386956, util=79.28%
mmacy@ubi0:/fio$ fio --name=randwrite --ioengine=libaio --iodepth=64 --rw=randwrite --bs=4k --direct=0 --size=16G --numjobs=12 --runtime=240 --group_reporting
randread: (g=0): rw=randwrite, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=64
...
fio-2.2.10
Starting 12 processes
Jobs: 12 (f=12): [w(12)] [100.0% done] [0KB/50801KB/0KB /s] [0/12.7K/0 iops] [eta 00m:00s]
randread: (groupid=0, jobs=12): err= 0: pid=3887: Sun Feb 25 19:59:54 2018
write: io=20697MB, bw=88295KB/s, iops=22073, runt=240035msec
slat (usec): min=1, max=452185, avg=462.34, stdev=4360.34
clat (usec): min=3, max=480414, avg=29181.50, stdev=25833.26
lat (usec): min=202, max=480419, avg=29643.90, stdev=25983.85
clat percentiles (usec):
| 1.00th=[ 229], 5.00th=[ 258], 10.00th=[ 282], 20.00th=[ 310],
| 30.00th=[ 354], 40.00th=[31872], 50.00th=[31872], 60.00th=[36096],
| 70.00th=[40192], 80.00th=[47360], 90.00th=[56064], 95.00th=[80384],
| 99.00th=[87552], 99.50th=[87552], 99.90th=[156672], 99.95th=[246784],
| 99.99th=[444416]
bw (KB /s): min= 0, max=884512, per=9.82%, avg=8671.18, stdev=35334.41
lat (usec) : 4=0.01%, 10=0.01%, 250=3.75%, 500=29.15%, 750=0.28%
lat (usec) : 1000=0.16%
lat (msec) : 2=0.16%, 4=0.03%, 10=0.01%, 20=1.73%, 50=48.91%
lat (msec) : 100=15.70%, 250=0.07%, 500=0.05%
cpu : usr=0.03%, sys=9.04%, ctx=411503, majf=0, minf=128
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=100.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.1%, >=64=0.0%
issued : total=r=0/w=5298458/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=64
Run status group 0 (all jobs):
WRITE: io=20697MB, aggrb=88294KB/s, minb=88294KB/s, maxb=88294KB/s, mint=240035msec, maxt=240035msec
Disk stats (read/write):
dm-0: ios=0/6132034, merge=0/0, ticks=0/4917188, in_queue=4942576, util=99.32%, aggrios=0/1445327, aggrmerge=0/141677, aggrticks=0/971629, aggrin_queue=960092, aggrutil=73.19%
sdb: ios=0/1574426, merge=0/153200, ticks=0/898424, in_queue=882852, util=57.56%
sdc: ios=0/1395989, merge=0/135157, ticks=0/1054196, in_queue=1043900, util=71.96%
sdd: ios=0/1397205, merge=0/135298, ticks=0/820208, in_queue=809912, util=61.72%
sde: ios=0/1413691, merge=0/143056, ticks=0/1113688, in_queue=1103704, util=73.19%
PGBENCH:
shared_buffers = 8192MB
synchronous_commit = off
postgres@ubi0:~$ pgbench -i -s 4096 example
postgres@ubi0:~$ pgbench -c 80 -j 16 -t 10000 -M prepared -r example
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 4096
query mode: prepared
number of clients: 80
number of threads: 16
number of transactions per client: 10000
number of transactions actually processed: 800000/800000
latency average: 9.216 ms
tps = 8680.781523 (including connections establishing)
tps = 8681.170452 (excluding connections establishing)
statement latencies in milliseconds:
0.001981 \set nbranches 1 * :scale
0.000735 \set ntellers 10 * :scale
0.000608 \set naccounts 100000 * :scale
0.000871 \setrandom aid 1 :naccounts
0.000736 \setrandom bid 1 :nbranches
0.000683 \setrandom tid 1 :ntellers
0.000711 \setrandom delta -5000 5000
0.301188 BEGIN;
4.315862 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
0.482193 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
1.112375 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
0.957378 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
0.690099 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
1.023741 END;
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment