* Severe performance degradation for dm-cache mq since c86c3070
@ 2015-09-10 14:39 Andrey Korolyov
2015-09-11 12:58 ` Joe Thornber
2015-09-11 20:32 ` Andrey Korolyov
0 siblings, 2 replies; 6+ messages in thread
From: Andrey Korolyov @ 2015-09-10 14:39 UTC (permalink / raw)
To: dm-devel; +Cc: heinzm, ejt, snitzer
[-- Attachment #1: Type: text/plain, Size: 801 bytes --]
Hello,
After changing the default policy behavior for a block replacement,
any long-running workload, especially with *SYNC flags, is tend to
perform worse that the code before mentioned commit, up to 50% down
for a bandwidth and more than 100% performance hit for a rotating
media business ratio.
Attached files:
- dm-constructor.txt shows a set of arguments for both cases
- fio.txt shows a fio test suite to run (it was processed on top of
ext4 with default settings)
- dm-fio-3.10.txt and dm-fio-4.2.txt are showing results for 3.10/mq
and 4.2/smq tests correspondingly, one can see a dramatic difference
for an excessive bandwidth drop. For a Ceph-based workload which
cannot be simulated very accurately with fio, the impact is
proportional to increased slow disk usage. e.g. more than twice.
[-- Attachment #2: dm-constructor.txt --]
[-- Type: text/plain, Size: 421 bytes --]
dmsetup create metadata-test --table '0 15350 linear /dev/sda1 0'
dmsetup create blocks-test --table '0 11717120 linear /dev/sda1 15350'
dmsetup create cachetest --table '0 124995584 cache /dev/mapper/metadata-test /dev/mapper/blocks-test /dev/sdc2 512 1 writeback default 0'
or smq:
dmsetup create cachetest --table '0 124995584 cache /dev/mapper/metadata-test /dev/mapper/blocks-test /dev/sdc2 512 1 writeback smq 0'
[-- Attachment #3: fio.txt --]
[-- Type: text/plain, Size: 219 bytes --]
[global]
randrepeat=0
ioengine=sync
iodepth=32
direct=1
size=12G
numjobs=1
verify_fatal=1
verify_dump=1
numjobs=4
directory=/mnt/test
[randrw]
#stonewall
blocksize=64k
rw=randrw
rwmixread=20
rwmixwrite=80
verify=meta
[-- Attachment #4: dm-fio-3.10.txt --]
[-- Type: text/plain, Size: 9237 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K/64K-64K, ioengine=sync, iodepth=32
...
fio-2.2.5
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: (groupid=0, jobs=1): err= 0: pid=5418: Thu Sep 10 16:46:06 2015
read : io=12288MB, bw=3239.5KB/s, iops=50, runt=3884757msec
clat (usec): min=189, max=650441, avg=14097.13, stdev=32861.97
lat (usec): min=213, max=624429K, avg=267920007.52, stdev=214081774.82
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 310], 10.00th=[ 334], 20.00th=[ 350],
| 30.00th=[ 370], 40.00th=[ 636], 50.00th=[ 1256], 60.00th=[ 5216],
| 70.00th=[ 8896], 80.00th=[17024], 90.00th=[38144], 95.00th=[71168],
| 99.00th=[162816], 99.50th=[207872], 99.90th=[337920], 99.95th=[378880],
| 99.99th=[464896]
bw (KB /s): min= 87, max= 2635, per=6.03%, avg=781.53, stdev=316.19
write: io=9840.5MB, bw=3090.7KB/s, iops=48, runt=3260329msec
clat (usec): min=211, max=496173, avg=7024.27, stdev=20591.71
lat (usec): min=213, max=496175, avg=7026.49, stdev=20591.72
clat percentiles (usec):
| 1.00th=[ 251], 5.00th=[ 266], 10.00th=[ 282], 20.00th=[ 482],
| 30.00th=[ 716], 40.00th=[ 2224], 50.00th=[ 3472], 60.00th=[ 5728],
| 70.00th=[ 7328], 80.00th=[10048], 90.00th=[14784], 95.00th=[20864],
| 99.00th=[34560], 99.50th=[48384], 99.90th=[354304], 99.95th=[387072],
| 99.99th=[428032]
bw (KB /s): min= 85, max=11861, per=25.50%, avg=3152.08, stdev=1544.40
lat (usec) : 250=0.46%, 500=28.74%, 750=9.61%, 1000=3.88%
lat (msec) : 2=3.90%, 4=8.66%, 10=20.55%, 20=13.11%, 50=6.58%
lat (msec) : 100=2.71%, 250=1.48%, 500=0.30%, 750=0.01%
cpu : usr=0.20%, sys=0.36%, ctx=354474, majf=0, minf=3739
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157447/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
randrw: (groupid=0, jobs=1): err= 0: pid=5419: Thu Sep 10 16:46:06 2015
read : io=12288MB, bw=3650.4KB/s, iops=57, runt=3447050msec
clat (usec): min=194, max=574022, avg=13071.01, stdev=29822.54
lat (usec): min=194, max=842299K, avg=336856655.06, stdev=293045388.15
clat percentiles (usec):
| 1.00th=[ 251], 5.00th=[ 274], 10.00th=[ 298], 20.00th=[ 362],
| 30.00th=[ 462], 40.00th=[ 756], 50.00th=[ 1224], 60.00th=[ 3120],
| 70.00th=[ 8640], 80.00th=[17280], 90.00th=[37632], 95.00th=[65280],
| 99.00th=[144384], 99.50th=[185344], 99.90th=[317440], 99.95th=[358400],
| 99.99th=[423936]
bw (KB /s): min= 120, max= 3449, per=7.58%, avg=982.47, stdev=368.72
write: io=9828.8MB, bw=3863.1KB/s, iops=60, runt=2604752msec
clat (usec): min=213, max=485145, avg=5527.24, stdev=18720.53
lat (usec): min=215, max=485146, avg=5529.28, stdev=18720.53
clat percentiles (usec):
| 1.00th=[ 258], 5.00th=[ 270], 10.00th=[ 294], 20.00th=[ 366],
| 30.00th=[ 620], 40.00th=[ 1048], 50.00th=[ 2704], 60.00th=[ 4016],
| 70.00th=[ 6432], 80.00th=[ 8160], 90.00th=[11328], 95.00th=[14784],
| 99.00th=[26496], 99.50th=[34048], 99.90th=[350208], 99.95th=[378880],
| 99.99th=[419840]
bw (KB /s): min= 94, max=12478, per=31.89%, avg=3940.91, stdev=1811.87
lat (usec) : 250=0.65%, 500=30.48%, 750=6.90%, 1000=5.21%
lat (msec) : 2=8.41%, 4=9.27%, 10=18.50%, 20=9.42%, 50=7.03%
lat (msec) : 100=2.70%, 250=1.18%, 500=0.24%, 750=0.01%
cpu : usr=0.25%, sys=0.39%, ctx=354623, majf=0, minf=3736
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157259/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
randrw: (groupid=0, jobs=1): err= 0: pid=5420: Thu Sep 10 16:46:06 2015
read : io=12288MB, bw=3974.9KB/s, iops=62, runt=3165683msec
clat (usec): min=200, max=591368, avg=12397.85, stdev=30351.28
lat (usec): min=207, max=929627K, avg=322931618.39, stdev=290970752.51
clat percentiles (usec):
| 1.00th=[ 247], 5.00th=[ 262], 10.00th=[ 274], 20.00th=[ 322],
| 30.00th=[ 366], 40.00th=[ 438], 50.00th=[ 932], 60.00th=[ 1528],
| 70.00th=[ 5408], 80.00th=[16192], 90.00th=[37120], 95.00th=[65280],
| 99.00th=[144384], 99.50th=[185344], 99.90th=[325632], 99.95th=[366592],
| 99.99th=[428032]
bw (KB /s): min= 89, max= 3428, per=8.74%, avg=1131.78, stdev=434.53
write: io=9857.4MB, bw=4513.1KB/s, iops=70, runt=2236145msec
clat (usec): min=210, max=480975, avg=4566.59, stdev=17045.97
lat (usec): min=212, max=480977, avg=4568.78, stdev=17045.98
clat percentiles (usec):
| 1.00th=[ 255], 5.00th=[ 270], 10.00th=[ 290], 20.00th=[ 354],
| 30.00th=[ 378], 40.00th=[ 636], 50.00th=[ 1512], 60.00th=[ 3056],
| 70.00th=[ 5216], 80.00th=[ 7200], 90.00th=[10304], 95.00th=[12864],
| 99.00th=[21376], 99.50th=[27008], 99.90th=[342016], 99.95th=[374784],
| 99.99th=[415744]
bw (KB /s): min= 111, max=15492, per=37.23%, avg=4601.55, stdev=2159.42
lat (usec) : 250=1.12%, 500=37.89%, 750=5.81%, 1000=4.85%
lat (msec) : 2=9.35%, 4=8.31%, 10=14.83%, 20=7.66%, 50=6.12%
lat (msec) : 100=2.64%, 250=1.19%, 500=0.23%, 750=0.01%
cpu : usr=0.27%, sys=0.43%, ctx=354826, majf=0, minf=5519
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157717/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
randrw: (groupid=0, jobs=1): err= 0: pid=5421: Thu Sep 10 16:46:06 2015
read : io=12288MB, bw=3243.8KB/s, iops=50, runt=3879937msec
clat (usec): min=190, max=725443, avg=14038.62, stdev=31822.04
lat (usec): min=236, max=658362K, avg=266546225.24, stdev=214192617.25
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 318], 10.00th=[ 346], 20.00th=[ 354],
| 30.00th=[ 466], 40.00th=[ 692], 50.00th=[ 1848], 60.00th=[ 5856],
| 70.00th=[ 9024], 80.00th=[17024], 90.00th=[37120], 95.00th=[70144],
| 99.00th=[156672], 99.50th=[199680], 99.90th=[325632], 99.95th=[366592],
| 99.99th=[456704]
bw (KB /s): min= 78, max= 2788, per=6.15%, avg=796.32, stdev=312.59
write: io=9823.9MB, bw=3122.6KB/s, iops=48, runt=3221596msec
clat (usec): min=223, max=475319, avg=7073.60, stdev=20703.59
lat (usec): min=225, max=475321, avg=7075.67, stdev=20703.61
clat percentiles (usec):
| 1.00th=[ 255], 5.00th=[ 270], 10.00th=[ 290], 20.00th=[ 540],
| 30.00th=[ 772], 40.00th=[ 2320], 50.00th=[ 3504], 60.00th=[ 5728],
| 70.00th=[ 7328], 80.00th=[10048], 90.00th=[14784], 95.00th=[20864],
| 99.00th=[34560], 99.50th=[49408], 99.90th=[358400], 99.95th=[378880],
| 99.99th=[423936]
bw (KB /s): min= 93, max=10870, per=25.78%, avg=3186.68, stdev=1500.03
lat (usec) : 250=0.28%, 500=26.90%, 750=9.69%, 1000=4.25%
lat (msec) : 2=4.24%, 4=8.78%, 10=21.25%, 20=13.41%, 50=6.81%
lat (msec) : 100=2.70%, 250=1.42%, 500=0.28%, 750=0.01%
cpu : usr=0.22%, sys=0.36%, ctx=354535, majf=0, minf=3732
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157182/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=49152MB, aggrb=12956KB/s, minb=3239KB/s, maxb=3974KB/s, mint=3165683msec, maxt=3884757msec
WRITE: io=39350MB, aggrb=12359KB/s, minb=3090KB/s, maxb=4513KB/s, mint=2236145msec, maxt=3260329msec
Disk stats (read/write):
dm-2: ios=786279/633545, merge=0/0, ticks=10507120/4149532, in_queue=14656740, util=100.00%, aggrios=262147/211622, aggrmerge=1/1, aggrticks=3501357/1384065, aggrin_queue=4885236, aggrutil=100.00%
dm-0: ios=5/14, merge=0/0, ticks=4/36, in_queue=40, util=0.00%, aggrios=89265/73489, aggrmerge=3/682, aggrticks=30420/62668, aggrin_queue=92996, aggrutil=2.33%
sda: ios=89265/73489, merge=3/682, ticks=30420/62668, in_queue=92996, util=2.33%
dm-1: ios=89263/74157, merge=0/0, ticks=30300/68708, in_queue=99016, util=2.32%
sdc: ios=697174/560697, merge=3/3, ticks=10473768/4083452, in_queue=14556652, util=100.00%
[-- Attachment #5: dm-fio-4.2.txt --]
[-- Type: text/plain, Size: 9296 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K/64K-64K, ioengine=sync, iodepth=32
...
fio-2.2.5
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: (groupid=0, jobs=1): err= 0: pid=9310: Thu Sep 10 15:09:38 2015
read : io=12288MB, bw=4672.5KB/s, iops=73, runt=2692984msec
clat (usec): min=174, max=737535, avg=10702.07, stdev=32177.56
lat (usec): min=208, max=764070K, avg=178266090.02, stdev=239542626.31
clat percentiles (usec):
| 1.00th=[ 211], 5.00th=[ 235], 10.00th=[ 247], 20.00th=[ 266],
| 30.00th=[ 298], 40.00th=[ 342], 50.00th=[ 374], 60.00th=[ 620],
| 70.00th=[ 1448], 80.00th=[ 8640], 90.00th=[29056], 95.00th=[66048],
| 99.00th=[158720], 99.50th=[214016], 99.90th=[329728], 99.95th=[370688],
| 99.99th=[477184]
bw (KB /s): min= 106, max= 3824, per=9.86%, avg=1323.36, stdev=570.29
write: io=9834.8MB, bw=5220.1KB/s, iops=81, runt=1928915msec
clat (usec): min=203, max=472474, avg=3698.68, stdev=15578.20
lat (usec): min=205, max=472478, avg=3702.56, stdev=15578.23
clat percentiles (usec):
| 1.00th=[ 258], 5.00th=[ 270], 10.00th=[ 286], 20.00th=[ 354],
| 30.00th=[ 366], 40.00th=[ 378], 50.00th=[ 524], 60.00th=[ 964],
| 70.00th=[ 1848], 80.00th=[ 3792], 90.00th=[ 8256], 95.00th=[12480],
| 99.00th=[42240], 99.50th=[74240], 99.90th=[292864], 99.95th=[333824],
| 99.99th=[395264]
bw (KB /s): min= 85, max=19888, per=43.13%, avg=5320.37, stdev=2683.26
lat (usec) : 250=6.48%, 500=47.58%, 750=5.33%, 1000=4.05%
lat (msec) : 2=9.36%, 4=5.89%, 10=8.60%, 20=4.63%, 50=4.05%
lat (msec) : 100=2.42%, 250=1.36%, 500=0.25%, 750=0.01%
cpu : usr=0.29%, sys=0.39%, ctx=354131, majf=0, minf=105602
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157355/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
randrw: (groupid=0, jobs=1): err= 0: pid=9311: Thu Sep 10 15:09:38 2015
read : io=12288MB, bw=3361.4KB/s, iops=52, runt=3743447msec
clat (usec): min=188, max=572307, avg=13717.76, stdev=31277.49
lat (usec): min=200, max=620947K, avg=268533380.07, stdev=207605321.64
clat percentiles (usec):
| 1.00th=[ 274], 5.00th=[ 322], 10.00th=[ 342], 20.00th=[ 378],
| 30.00th=[ 402], 40.00th=[ 498], 50.00th=[ 636], 60.00th=[ 1512],
| 70.00th=[ 8160], 80.00th=[19328], 90.00th=[41728], 95.00th=[71168],
| 99.00th=[152576], 99.50th=[191488], 99.90th=[296960], 99.95th=[346112],
| 99.99th=[440320]
bw (KB /s): min= 97, max= 2599, per=6.11%, avg=820.51, stdev=313.73
write: io=9818.2MB, bw=3219.8KB/s, iops=50, runt=3122501msec
clat (usec): min=234, max=472798, avg=6609.93, stdev=19565.20
lat (usec): min=236, max=472807, avg=6614.64, stdev=19565.24
clat percentiles (usec):
| 1.00th=[ 258], 5.00th=[ 270], 10.00th=[ 278], 20.00th=[ 402],
| 30.00th=[ 636], 40.00th=[ 908], 50.00th=[ 2544], 60.00th=[ 3696],
| 70.00th=[ 6048], 80.00th=[ 8384], 90.00th=[13504], 95.00th=[21376],
| 99.00th=[67072], 99.50th=[110080], 99.90th=[317440], 99.95th=[350208],
| 99.99th=[411648]
bw (KB /s): min= 89, max=11442, per=26.48%, avg=3267.45, stdev=1530.20
lat (usec) : 250=0.44%, 500=34.40%, 750=11.45%, 1000=4.59%
lat (msec) : 2=4.49%, 4=8.70%, 10=13.81%, 20=8.65%, 50=8.33%
lat (msec) : 100=3.36%, 250=1.57%, 500=0.21%, 750=0.01%
cpu : usr=0.24%, sys=0.29%, ctx=354177, majf=0, minf=152719
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157090/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
randrw: (groupid=0, jobs=1): err= 0: pid=9312: Thu Sep 10 15:09:38 2015
read : io=12288MB, bw=3432.2KB/s, iops=53, runt=3665295msec
clat (usec): min=175, max=500374, avg=13295.18, stdev=30689.51
lat (usec): min=187, max=568651K, avg=248005140.06, stdev=187043844.65
clat percentiles (usec):
| 1.00th=[ 278], 5.00th=[ 326], 10.00th=[ 342], 20.00th=[ 386],
| 30.00th=[ 402], 40.00th=[ 498], 50.00th=[ 652], 60.00th=[ 1320],
| 70.00th=[ 8032], 80.00th=[18560], 90.00th=[39680], 95.00th=[69120],
| 99.00th=[150528], 99.50th=[187392], 99.90th=[301056], 99.95th=[346112],
| 99.99th=[423936]
bw (KB /s): min= 92, max= 2406, per=6.15%, avg=825.74, stdev=326.05
write: io=9824.1MB, bw=3248.1KB/s, iops=50, runt=3096645msec
clat (usec): min=236, max=480708, avg=6636.40, stdev=19768.22
lat (usec): min=239, max=480712, avg=6640.85, stdev=19768.27
clat percentiles (usec):
| 1.00th=[ 258], 5.00th=[ 270], 10.00th=[ 278], 20.00th=[ 402],
| 30.00th=[ 636], 40.00th=[ 916], 50.00th=[ 2576], 60.00th=[ 3696],
| 70.00th=[ 6112], 80.00th=[ 8384], 90.00th=[13632], 95.00th=[21376],
| 99.00th=[66048], 99.50th=[112128], 99.90th=[317440], 99.95th=[354304],
| 99.99th=[395264]
bw (KB /s): min= 85, max=11136, per=26.74%, avg=3299.01, stdev=1559.59
lat (usec) : 250=0.37%, 500=33.72%, 750=11.87%, 1000=4.95%
lat (msec) : 2=4.88%, 4=8.67%, 10=13.69%, 20=8.66%, 50=8.27%
lat (msec) : 100=3.22%, 250=1.49%, 500=0.21%, 750=0.01%
cpu : usr=0.24%, sys=0.30%, ctx=354848, majf=0, minf=152352
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157199/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
randrw: (groupid=0, jobs=1): err= 0: pid=9313: Thu Sep 10 15:09:38 2015
read : io=12288MB, bw=3354.7KB/s, iops=52, runt=3750927msec
clat (usec): min=175, max=939174, avg=13713.44, stdev=34224.48
lat (usec): min=225, max=487803K, avg=215721759.34, stdev=173004769.73
clat percentiles (usec):
| 1.00th=[ 282], 5.00th=[ 310], 10.00th=[ 330], 20.00th=[ 358],
| 30.00th=[ 394], 40.00th=[ 434], 50.00th=[ 588], 60.00th=[ 796],
| 70.00th=[ 5216], 80.00th=[17280], 90.00th=[40704], 95.00th=[73216],
| 99.00th=[171008], 99.50th=[216064], 99.90th=[329728], 99.95th=[382976],
| 99.99th=[514048]
bw (KB /s): min= 67, max= 3200, per=5.82%, avg=780.47, stdev=338.62
write: io=9838.6MB, bw=3087.5KB/s, iops=48, runt=3263125msec
clat (usec): min=236, max=468589, avg=6649.80, stdev=19860.28
lat (usec): min=239, max=468595, avg=6654.01, stdev=19860.32
clat percentiles (usec):
| 1.00th=[ 255], 5.00th=[ 266], 10.00th=[ 274], 20.00th=[ 374],
| 30.00th=[ 620], 40.00th=[ 852], 50.00th=[ 2256], 60.00th=[ 3568],
| 70.00th=[ 5920], 80.00th=[ 8384], 90.00th=[14016], 95.00th=[22144],
| 99.00th=[68096], 99.50th=[119296], 99.90th=[313344], 99.95th=[354304],
| 99.99th=[399360]
bw (KB /s): min= 93, max=12288, per=25.53%, avg=3149.76, stdev=1627.64
lat (usec) : 250=0.26%, 500=37.17%, 750=11.83%, 1000=4.34%
lat (msec) : 2=4.34%, 4=8.17%, 10=12.66%, 20=8.45%, 50=7.69%
lat (msec) : 100=3.10%, 250=1.71%, 500=0.27%, 750=0.01%, 1000=0.01%
cpu : usr=0.23%, sys=0.28%, ctx=354578, majf=0, minf=114364
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157417/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=49152MB, aggrb=13418KB/s, minb=3354KB/s, maxb=4672KB/s, mint=2692984msec, maxt=3750927msec
WRITE: io=39316MB, aggrb=12337KB/s, minb=3087KB/s, maxb=5220KB/s, mint=1928915msec, maxt=3263125msec
Disk stats (read/write):
dm-2: ios=786432/635099, merge=0/0, ticks=10062236/4157648, in_queue=14220268, util=100.00%, aggrios=302573/222505, aggrmerge=105/30296, aggrticks=3491692/1704593, aggrin_queue=5195789, aggrutil=99.90%
dm-0: ios=0/1470, merge=0/0, ticks=0/7712, in_queue=7712, util=0.12%, aggrios=118553/74553, aggrmerge=91918/1443, aggrticks=135940/88752, aggrin_queue=224420, aggrutil=4.19%
sda: ios=118553/74553, merge=91918/1443, ticks=135940/88752, in_queue=224420, util=4.19%
dm-1: ios=210514/74526, merge=0/0, ticks=456092/110120, in_queue=566272, util=4.08%
sdc: ios=697207/591520, merge=315/90888, ticks=10018984/4995948, in_queue=15013384, util=99.90%
[-- Attachment #6: Type: text/plain, Size: 0 bytes --]
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Severe performance degradation for dm-cache mq since c86c3070
2015-09-10 14:39 Severe performance degradation for dm-cache mq since c86c3070 Andrey Korolyov
@ 2015-09-11 12:58 ` Joe Thornber
2015-09-11 20:32 ` Andrey Korolyov
1 sibling, 0 replies; 6+ messages in thread
From: Joe Thornber @ 2015-09-11 12:58 UTC (permalink / raw)
To: device-mapper development; +Cc: heinzm, ejt, snitzer
On Thu, Sep 10, 2015 at 05:39:20PM +0300, Andrey Korolyov wrote:
> - dm-fio-3.10.txt and dm-fio-4.2.txt are showing results for 3.10/mq
> and 4.2/smq tests correspondingly, one can see a dramatic difference
> for an excessive bandwidth drop.
I've been trying your fio workload this morning on my system. I do
see a regression in performance for the mq policy, but smq is faster
for me:
- old version of mq - 636 seconds
- current version of mq - 820 seconds
- current version of smq - 585 seconds
This was running a smaller test than you with only 2G per thread.
Have you tried playing with the migration_threshold tunable? With
random IO such as this we really want the cache to initially populate
the cache but then do no churning. Could you give me the status line
for the caches once you've run the tests please? This would tell me
how many blocks are being demoted.
- Joe
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Severe performance degradation for dm-cache mq since c86c3070
2015-09-10 14:39 Severe performance degradation for dm-cache mq since c86c3070 Andrey Korolyov
2015-09-11 12:58 ` Joe Thornber
@ 2015-09-11 20:32 ` Andrey Korolyov
2015-09-12 22:15 ` Andrey Korolyov
2015-09-18 15:30 ` Joe Thornber
1 sibling, 2 replies; 6+ messages in thread
From: Andrey Korolyov @ 2015-09-11 20:32 UTC (permalink / raw)
To: thornber; +Cc: heinzm, ejt, dm-devel, snitzer
[-- Attachment #1: Type: text/plain, Size: 1271 bytes --]
> This was running a smaller test than you with only 2G per thread.
> Have you tried playing with the migration_threshold tunable? With
> random IO such as this we really want the cache to initially populate
> the cache but then do no churning. Could you give me the status line
> for the caches once you've run the tests please? This would tell me
> how many blocks are being demoted.
Please CC me always, as I am not subscribed to dm-devel.
Short-runs are tend to show better results on smq, but real-world
applications have at most long-running workloads with sustained cache
usage pattern where old algorithm shows a best result. I`ll give a try
for tunables and post results separately. Please take a look on an
attached results - at a given cache size smq outperforms all other
algorithms but both new mq and smq performs poorly when cache fills up
and issuing demotions. Status outputs are given right after test
completion. Hardware platform was changed for test, so absolute values
can differ from ones in original message.
The r/w ratio, block size and random pattern are selected to represent
a typical SDS workload on top of the cache, but, as I pointed earlier,
it is a quite inaccurate simulation - the hit curve is impossible to
reproduce with fio.
[-- Attachment #2: mq-2G.txt --]
[-- Type: text/plain, Size: 8786 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: (groupid=0, jobs=1): err= 0: pid=3809
read : io=2048.0MB, bw=4081.5KB/s, iops=63 , runt=513826msec
clat (usec): min=309 , max=480445 , avg=9780.86, stdev=25628.17
lat (usec): min=364 , max=105935K, avg=47447189.67, stdev=41544954.28
clat percentiles (usec):
| 1.00th=[ 346], 5.00th=[ 398], 10.00th=[ 422], 20.00th=[ 446],
| 30.00th=[ 466], 40.00th=[ 490], 50.00th=[ 564], 60.00th=[ 916],
| 70.00th=[ 2288], 80.00th=[ 9024], 90.00th=[29824], 95.00th=[54528],
| 99.00th=[121344], 99.50th=[162816], 99.90th=[264192], 99.95th=[296960],
| 99.99th=[399360]
bw (KB/s) : min= 122, max= 2447, per=6.54%, avg=1034.98, stdev=396.23
write: io=1638.7MB, bw=4113.8KB/s, iops=64 , runt=407894msec
clat (usec): min=316 , max=383703 , avg=7304.02, stdev=19091.19
lat (usec): min=316 , max=383704 , avg=7304.37, stdev=19091.19
clat percentiles (usec):
| 1.00th=[ 326], 5.00th=[ 330], 10.00th=[ 334], 20.00th=[ 342],
| 30.00th=[ 358], 40.00th=[ 426], 50.00th=[ 700], 60.00th=[ 1304],
| 70.00th=[ 3056], 80.00th=[ 7264], 90.00th=[20864], 95.00th=[40704],
| 99.00th=[82432], 99.50th=[108032], 99.90th=[230400], 99.95th=[248832],
| 99.99th=[337920]
bw (KB/s) : min= 588, max=11601, per=31.76%, avg=4145.12, stdev=1705.90
lat (usec) : 500=43.23%, 750=10.97%, 1000=5.10%
lat (msec) : 2=7.72%, 4=6.85%, 10=8.01%, 20=5.96%, 50=7.45%
lat (msec) : 100=3.54%, 250=1.09%, 500=0.09%
cpu : usr=0.37%, sys=0.37%, ctx=59246, majf=0, minf=11225
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26218/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3810
read : io=2048.0MB, bw=4918.5KB/s, iops=76 , runt=426420msec
clat (usec): min=318 , max=314785 , avg=8535.93, stdev=21345.05
lat (usec): min=402 , max=118706K, avg=55808063.48, stdev=47987188.82
clat percentiles (usec):
| 1.00th=[ 338], 5.00th=[ 358], 10.00th=[ 422], 20.00th=[ 446],
| 30.00th=[ 462], 40.00th=[ 482], 50.00th=[ 524], 60.00th=[ 828],
| 70.00th=[ 2096], 80.00th=[ 8640], 90.00th=[26496], 95.00th=[49920],
| 99.00th=[102912], 99.50th=[129536], 99.90th=[214016], 99.95th=[250880],
| 99.99th=[301056]
bw (KB/s) : min= 239, max= 3218, per=8.45%, avg=1336.86, stdev=483.39
write: io=1647.4MB, bw=5482.8KB/s, iops=85 , runt=307714msec
clat (usec): min=312 , max=381235 , avg=5496.90, stdev=16325.00
lat (usec): min=312 , max=381235 , avg=5497.26, stdev=16325.00
clat percentiles (usec):
| 1.00th=[ 322], 5.00th=[ 326], 10.00th=[ 330], 20.00th=[ 334],
| 30.00th=[ 342], 40.00th=[ 386], 50.00th=[ 498], 60.00th=[ 836],
| 70.00th=[ 2024], 80.00th=[ 4384], 90.00th=[12992], 95.00th=[29568],
| 99.00th=[73216], 99.50th=[91648], 99.90th=[211968], 99.95th=[240640],
| 99.99th=[342016]
bw (KB/s) : min= 1111, max=14065, per=42.15%, avg=5500.97, stdev=2159.83
lat (usec) : 500=48.50%, 750=9.83%, 1000=4.37%
lat (msec) : 2=7.10%, 4=6.33%, 10=9.21%, 20=4.71%, 50=6.05%
lat (msec) : 100=3.10%, 250=0.74%, 500=0.05%
cpu : usr=0.44%, sys=0.45%, ctx=59212, majf=0, minf=4524
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26358/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3811
read : io=2048.0MB, bw=4045.3KB/s, iops=63 , runt=518427msec
clat (usec): min=294 , max=377118 , avg=9564.41, stdev=22314.71
lat (usec): min=351 , max=106256K, avg=44671610.54, stdev=38402348.37
clat percentiles (usec):
| 1.00th=[ 342], 5.00th=[ 398], 10.00th=[ 426], 20.00th=[ 454],
| 30.00th=[ 478], 40.00th=[ 516], 50.00th=[ 716], 60.00th=[ 1288],
| 70.00th=[ 3888], 80.00th=[11968], 90.00th=[29312], 95.00th=[50432],
| 99.00th=[105984], 99.50th=[132096], 99.90th=[216064], 99.95th=[259072],
| 99.99th=[350208]
bw (KB/s) : min= 111, max= 2869, per=6.45%, avg=1020.78, stdev=373.00
write: io=1638.9MB, bw=4071.5KB/s, iops=63 , runt=412171msec
clat (usec): min=318 , max=381875 , avg=7749.48, stdev=19003.91
lat (usec): min=319 , max=381875 , avg=7749.83, stdev=19003.92
clat percentiles (usec):
| 1.00th=[ 326], 5.00th=[ 330], 10.00th=[ 338], 20.00th=[ 354],
| 30.00th=[ 410], 40.00th=[ 612], 50.00th=[ 940], 60.00th=[ 1912],
| 70.00th=[ 3696], 80.00th=[ 8512], 90.00th=[21888], 95.00th=[41728],
| 99.00th=[84480], 99.50th=[103936], 99.90th=[230400], 99.95th=[250880],
| 99.99th=[337920]
bw (KB/s) : min= 764, max=11532, per=31.41%, avg=4098.38, stdev=1648.44
lat (usec) : 500=35.80%, 750=12.30%, 1000=6.04%
lat (msec) : 2=8.97%, 4=7.51%, 10=9.49%, 20=7.05%, 50=8.40%
lat (msec) : 100=3.49%, 250=0.89%, 500=0.06%
cpu : usr=0.36%, sys=0.36%, ctx=59132, majf=0, minf=12137
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26221/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3812
read : io=2048.0MB, bw=3955.4KB/s, iops=61 , runt=530209msec
clat (usec): min=290 , max=417591 , avg=8605.52, stdev=24033.69
lat (usec): min=367 , max=15350K, avg=7120235.14, stdev=4908645.90
clat percentiles (usec):
| 1.00th=[ 294], 5.00th=[ 318], 10.00th=[ 326], 20.00th=[ 330],
| 30.00th=[ 334], 40.00th=[ 342], 50.00th=[ 346], 60.00th=[ 482],
| 70.00th=[ 660], 80.00th=[ 5024], 90.00th=[28800], 95.00th=[51968],
| 99.00th=[115200], 99.50th=[146432], 99.90th=[250880], 99.95th=[296960],
| 99.99th=[387072]
bw (KB/s) : min= 112, max= 3920, per=5.20%, avg=822.72, stdev=381.18
write: io=1637.4MB, bw=3256.4KB/s, iops=50 , runt=514892msec
clat (usec): min=327 , max=383583 , avg=9406.56, stdev=20679.37
lat (usec): min=327 , max=383584 , avg=9406.92, stdev=20679.38
clat percentiles (usec):
| 1.00th=[ 370], 5.00th=[ 386], 10.00th=[ 398], 20.00th=[ 506],
| 30.00th=[ 660], 40.00th=[ 932], 50.00th=[ 1608], 60.00th=[ 3184],
| 70.00th=[ 6432], 80.00th=[13120], 90.00th=[25728], 95.00th=[44288],
| 99.00th=[89600], 99.50th=[116224], 99.90th=[244736], 99.95th=[268288],
| 99.99th=[350208]
bw (KB/s) : min= 381, max=11125, per=25.21%, avg=3290.53, stdev=1507.63
lat (usec) : 500=42.45%, 750=12.63%, 1000=4.54%
lat (msec) : 2=6.88%, 4=6.07%, 10=6.95%, 20=7.18%, 50=8.55%
lat (msec) : 100=3.65%, 250=1.00%, 500=0.09%
cpu : usr=0.35%, sys=0.35%, ctx=59066, majf=0, minf=4624
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26198/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=8192.0MB, aggrb=15821KB/s, minb=3955KB/s, maxb=4918KB/s, mint=426420msec, maxt=530209msec
WRITE: io=6562.2MB, aggrb=13050KB/s, minb=3256KB/s, maxb=5482KB/s, mint=307714msec, maxt=514892msec
Disk stats (read/write):
dm-2: ios=130710/108295, merge=0/0, ticks=1192312/993432, in_queue=2185792, util=99.99%, aggrios=67733/43706, aggrmerge=0/18034, aggrticks=452722/465613, aggrin_queue=918240, aggrutil=99.96%
dm-0: ios=0/4587, merge=0/0, ticks=0/10912, in_queue=10912, util=0.62%, aggrios=51333/33234, aggrmerge=54912/1733, aggrticks=58204/28260, aggrin_queue=86376, aggrutil=9.13%
sdc: ios=51333/33234, merge=54912/1733, ticks=58204/28260, in_queue=86376, util=9.13%
dm-1: ios=106244/30380, merge=0/0, ticks=185344/23868, in_queue=209224, util=9.12%
sdd: ios=96956/96152, merge=0/54103, ticks=1172824/1362060, in_queue=2534584, util=99.96%
[-- Attachment #3: mq-12G.txt --]
[-- Type: text/plain, Size: 8924 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: (groupid=0, jobs=1): err= 0: pid=3869
read : io=12288MB, bw=2947.8KB/s, iops=46 , runt=4268634msec
clat (usec): min=287 , max=769122 , avg=14981.72, stdev=38642.32
lat (usec): min=357 , max=610718K, avg=363841220.94, stdev=243902010.18
clat percentiles (usec):
| 1.00th=[ 314], 5.00th=[ 318], 10.00th=[ 326], 20.00th=[ 334],
| 30.00th=[ 394], 40.00th=[ 502], 50.00th=[ 572], 60.00th=[ 876],
| 70.00th=[ 5216], 80.00th=[16512], 90.00th=[46336], 95.00th=[86528],
| 99.00th=[191488], 99.50th=[242688], 99.90th=[370688], 99.95th=[419840],
| 99.99th=[552960]
bw (KB/s) : min= 77, max= 2970, per=5.84%, avg=689.03, stdev=295.83
write: io=9863.0MB, bw=2761.6KB/s, iops=43 , runt=3657917msec
clat (usec): min=324 , max=447068 , avg=8311.03, stdev=22022.36
lat (usec): min=325 , max=447069 , avg=8311.39, stdev=22022.36
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 390], 10.00th=[ 402], 20.00th=[ 588],
| 30.00th=[ 764], 40.00th=[ 1128], 50.00th=[ 2224], 60.00th=[ 3696],
| 70.00th=[ 6432], 80.00th=[10944], 90.00th=[20352], 95.00th=[30080],
| 99.00th=[76288], 99.50th=[117248], 99.90th=[321536], 99.95th=[350208],
| 99.99th=[391168]
bw (KB/s) : min= 98, max=11509, per=25.50%, avg=2809.31, stdev=1432.66
lat (usec) : 500=28.47%, 750=15.42%, 1000=6.87%
lat (msec) : 2=7.20%, 4=7.26%, 10=11.84%, 20=9.19%, 50=7.49%
lat (msec) : 100=3.80%, 250=2.07%, 500=0.37%, 750=0.01%, 1000=0.01%
cpu : usr=0.29%, sys=0.26%, ctx=355781, majf=0, minf=180200
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157808/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3870
read : io=12288MB, bw=3703.9KB/s, iops=57 , runt=3397297msec
clat (usec): min=275 , max=583552 , avg=12963.72, stdev=32672.31
lat (usec): min=402 , max=918166K, avg=341151993.78, stdev=280770251.41
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 378], 10.00th=[ 418], 20.00th=[ 446],
| 30.00th=[ 466], 40.00th=[ 502], 50.00th=[ 756], 60.00th=[ 1336],
| 70.00th=[ 3792], 80.00th=[13632], 90.00th=[40704], 95.00th=[74240],
| 99.00th=[156672], 99.50th=[203776], 99.90th=[329728], 99.95th=[362496],
| 99.99th=[428032]
bw (KB/s) : min= 82, max= 4163, per=8.69%, avg=1024.92, stdev=411.14
write: io=9834.2MB, bw=4061.1KB/s, iops=63 , runt=2479132msec
clat (usec): min=315 , max=418492 , avg=5319.12, stdev=17987.58
lat (usec): min=315 , max=418493 , avg=5319.46, stdev=17987.59
clat percentiles (usec):
| 1.00th=[ 322], 5.00th=[ 326], 10.00th=[ 330], 20.00th=[ 342],
| 30.00th=[ 374], 40.00th=[ 414], 50.00th=[ 636], 60.00th=[ 1032],
| 70.00th=[ 2352], 80.00th=[ 4640], 90.00th=[11968], 95.00th=[24192],
| 99.00th=[67072], 99.50th=[91648], 99.90th=[288768], 99.95th=[321536],
| 99.99th=[366592]
bw (KB/s) : min= 113, max=16128, per=37.36%, avg=4115.82, stdev=1983.16
lat (usec) : 500=41.51%, 750=9.92%, 1000=5.13%
lat (msec) : 2=10.02%, 4=6.99%, 10=8.99%, 20=5.54%, 50=6.47%
lat (msec) : 100=3.65%, 250=1.52%, 500=0.24%, 750=0.01%
cpu : usr=0.37%, sys=0.32%, ctx=355632, majf=0, minf=190101
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157346/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3871
read : io=12288MB, bw=3101.1KB/s, iops=48 , runt=4056446msec
clat (usec): min=278 , max=624375 , avg=14519.49, stdev=31494.33
lat (usec): min=382 , max=766493K, avg=311483731.58, stdev=252701852.14
clat percentiles (usec):
| 1.00th=[ 294], 5.00th=[ 374], 10.00th=[ 398], 20.00th=[ 466],
| 30.00th=[ 764], 40.00th=[ 924], 50.00th=[ 1848], 60.00th=[ 7904],
| 70.00th=[ 8640], 80.00th=[17024], 90.00th=[41216], 95.00th=[74240],
| 99.00th=[154624], 99.50th=[191488], 99.90th=[305152], 99.95th=[346112],
| 99.99th=[407552]
bw (KB/s) : min= 88, max= 2640, per=6.54%, avg=770.55, stdev=296.53
write: io=9840.3MB, bw=3062.9KB/s, iops=47 , runt=3289954msec
clat (usec): min=320 , max=453186 , avg=7559.82, stdev=20755.11
lat (usec): min=320 , max=453186 , avg=7560.17, stdev=20755.11
clat percentiles (usec):
| 1.00th=[ 338], 5.00th=[ 374], 10.00th=[ 390], 20.00th=[ 516],
| 30.00th=[ 660], 40.00th=[ 964], 50.00th=[ 1656], 60.00th=[ 3216],
| 70.00th=[ 5344], 80.00th=[ 9408], 90.00th=[18304], 95.00th=[29312],
| 99.00th=[74240], 99.50th=[108032], 99.90th=[313344], 99.95th=[342016],
| 99.99th=[387072]
bw (KB/s) : min= 125, max=11729, per=28.18%, avg=3104.61, stdev=1468.83
lat (usec) : 500=21.19%, 750=9.07%, 1000=11.35%
lat (msec) : 2=9.82%, 4=8.06%, 10=17.72%, 20=8.87%, 50=8.30%
lat (msec) : 100=3.74%, 250=1.63%, 500=0.23%, 750=0.01%
cpu : usr=0.31%, sys=0.27%, ctx=355712, majf=0, minf=198408
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157444/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3872
read : io=12288MB, bw=2971.2KB/s, iops=46 , runt=4235030msec
clat (usec): min=279 , max=804296 , avg=15017.66, stdev=34430.56
lat (usec): min=368 , max=677268K, avg=278204382.21, stdev=223262722.28
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 390], 10.00th=[ 402], 20.00th=[ 502],
| 30.00th=[ 604], 40.00th=[ 876], 50.00th=[ 1608], 60.00th=[ 7648],
| 70.00th=[ 8640], 80.00th=[16768], 90.00th=[41728], 95.00th=[78336],
| 99.00th=[171008], 99.50th=[218112], 99.90th=[329728], 99.95th=[366592],
| 99.99th=[493568]
bw (KB/s) : min= 85, max= 2422, per=6.11%, avg=719.92, stdev=299.47
write: io=9824.5MB, bw=2827.7KB/s, iops=44 , runt=3557773msec
clat (usec): min=319 , max=462498 , avg=8085.06, stdev=21709.34
lat (usec): min=320 , max=462498 , avg=8085.42, stdev=21709.34
clat percentiles (usec):
| 1.00th=[ 342], 5.00th=[ 378], 10.00th=[ 390], 20.00th=[ 548],
| 30.00th=[ 716], 40.00th=[ 1064], 50.00th=[ 1992], 60.00th=[ 3504],
| 70.00th=[ 6048], 80.00th=[10304], 90.00th=[19840], 95.00th=[30336],
| 99.00th=[77312], 99.50th=[115200], 99.90th=[321536], 99.95th=[346112],
| 99.99th=[403456]
bw (KB/s) : min= 112, max=10496, per=26.12%, avg=2878.16, stdev=1449.07
lat (usec) : 500=18.35%, 750=13.30%, 1000=10.93%
lat (msec) : 2=8.12%, 4=7.50%, 10=18.41%, 20=9.79%, 50=7.81%
lat (msec) : 100=3.67%, 250=1.81%, 500=0.30%, 750=0.01%, 1000=0.01%
cpu : usr=0.28%, sys=0.27%, ctx=355723, majf=0, minf=188896
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157191/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=49152MB, aggrb=11791KB/s, minb=2947KB/s, maxb=3703KB/s, mint=3397297msec, maxt=4268634msec
WRITE: io=39362MB, aggrb=11018KB/s, minb=2761KB/s, maxb=4061KB/s, mint=2479132msec, maxt=3657917msec
Disk stats (read/write):
dm-2: ios=786428/635787, merge=0/0, ticks=11276976/5208140, in_queue=16485400, util=100.00%, aggrios=356501/238294, aggrmerge=0/71431, aggrticks=3958825/2348300, aggrin_queue=6306597, aggrutil=100.00%
dm-0: ios=8/8860, merge=0/0, ticks=0/11612, in_queue=11616, util=0.08%, aggrios=148230/74349, aggrmerge=213543/1571, aggrticks=183484/43260, aggrin_queue=226468, aggrutil=3.17%
sdc: ios=148230/74349, merge=213543/1571, ticks=183484/43260, in_queue=226468, util=3.17%
dm-1: ios=361765/67060, merge=0/0, ticks=638232/37020, in_queue=675324, util=3.18%
sdd: ios=707731/638963, merge=0/214295, ticks=11238244/6996268, in_queue=18232852, util=100.00%
[-- Attachment #4: mq-old-2G.txt --]
[-- Type: text/plain, Size: 8993 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: (groupid=0, jobs=1): err= 0: pid=3604
read : io=2048.0MB, bw=3948.4KB/s, iops=61 , runt=531147msec
clat (usec): min=280 , max=9799.6K, avg=10907.06, stdev=68654.54
lat (usec): min=409 , max=32140K, avg=18682452.93, stdev=12272762.15
clat percentiles (usec):
| 1.00th=[ 286], 5.00th=[ 302], 10.00th=[ 314], 20.00th=[ 330],
| 30.00th=[ 346], 40.00th=[ 354], 50.00th=[ 358], 60.00th=[ 366],
| 70.00th=[ 556], 80.00th=[ 1816], 90.00th=[33024], 95.00th=[65280],
| 99.00th=[160768], 99.50th=[207872], 99.90th=[337920], 99.95th=[411648],
| 99.99th=[929792]
bw (KB/s) : min= 32, max= 2176, per=5.60%, avg=885.14, stdev=352.38
write: io=1638.4MB, bw=3362.7KB/s, iops=52 , runt=499007msec
clat (usec): min=310 , max=9480.7K, avg=6570.06, stdev=71920.57
lat (usec): min=310 , max=9480.7K, avg=6570.30, stdev=71920.58
clat percentiles (usec):
| 1.00th=[ 322], 5.00th=[ 338], 10.00th=[ 350], 20.00th=[ 430],
| 30.00th=[ 668], 40.00th=[ 1576], 50.00th=[ 3120], 60.00th=[ 5536],
| 70.00th=[ 6816], 80.00th=[ 9152], 90.00th=[11968], 95.00th=[14400],
| 99.00th=[22912], 99.50th=[71168], 99.90th=[224256], 99.95th=[264192],
| 99.99th=[2703360]
bw (KB/s) : min= 64, max=12317, per=26.37%, avg=3533.50, stdev=1692.15
lat (usec) : 500=47.80%, 750=8.88%, 1000=2.77%
lat (msec) : 2=4.15%, 4=6.21%, 10=14.35%, 20=7.73%, 50=4.01%
lat (msec) : 100=2.41%, 250=1.49%, 500=0.16%, 750=0.01%, 1000=0.02%
lat (msec) : 2000=0.01%, >=2000=0.01%
cpu : usr=0.33%, sys=0.37%, ctx=59113, majf=0, minf=651
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26214/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3605
read : io=2048.0MB, bw=4034.1KB/s, iops=63 , runt=519747msec
clat (usec): min=287 , max=13041K, avg=10775.49, stdev=99304.45
lat (usec): min=380 , max=68287K, avg=39035964.11, stdev=24465820.05
clat percentiles (usec):
| 1.00th=[ 302], 5.00th=[ 318], 10.00th=[ 322], 20.00th=[ 346],
| 30.00th=[ 354], 40.00th=[ 362], 50.00th=[ 370], 60.00th=[ 394],
| 70.00th=[ 660], 80.00th=[ 8160], 90.00th=[32384], 95.00th=[56576],
| 99.00th=[124416], 99.50th=[160768], 99.90th=[301056], 99.95th=[913408],
| 99.99th=[2834432]
bw (KB/s) : min= 54, max= 2080, per=5.95%, avg=940.41, stdev=299.03
write: io=1636.7MB, bw=3712.2KB/s, iops=58 , runt=451467msec
clat (usec): min=321 , max=907699 , avg=6306.25, stdev=13927.31
lat (usec): min=321 , max=907700 , avg=6306.49, stdev=13927.31
clat percentiles (usec):
| 1.00th=[ 370], 5.00th=[ 398], 10.00th=[ 446], 20.00th=[ 668],
| 30.00th=[ 1592], 40.00th=[ 2992], 50.00th=[ 5024], 60.00th=[ 6176],
| 70.00th=[ 7648], 80.00th=[ 9408], 90.00th=[12224], 95.00th=[14528],
| 99.00th=[22400], 99.50th=[30336], 99.90th=[205824], 99.95th=[236544],
| 99.99th=[264192]
bw (KB/s) : min= 256, max= 8945, per=27.95%, avg=3745.99, stdev=1455.29
lat (usec) : 500=40.53%, 750=8.91%, 1000=2.83%
lat (msec) : 2=4.47%, 4=7.38%, 10=18.07%, 20=9.07%, 50=5.25%
lat (msec) : 100=2.38%, 250=1.02%, 500=0.05%, 750=0.01%, 1000=0.02%
lat (msec) : 2000=0.01%, >=2000=0.01%
cpu : usr=0.34%, sys=0.38%, ctx=59072, majf=0, minf=827
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26186/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3606
read : io=2048.0MB, bw=4383.4KB/s, iops=68 , runt=478437msec
clat (usec): min=298 , max=1114.8K, avg=9523.49, stdev=31997.57
lat (usec): min=402 , max=32311K, avg=15312590.83, stdev=9883328.15
clat percentiles (usec):
| 1.00th=[ 318], 5.00th=[ 318], 10.00th=[ 322], 20.00th=[ 342],
| 30.00th=[ 346], 40.00th=[ 354], 50.00th=[ 358], 60.00th=[ 386],
| 70.00th=[ 660], 80.00th=[ 8384], 90.00th=[31360], 95.00th=[54528],
| 99.00th=[117248], 99.50th=[148480], 99.90th=[252928], 99.95th=[536576],
| 99.99th=[1089536]
bw (KB/s) : min= 62, max= 2519, per=6.00%, avg=947.36, stdev=296.22
write: io=1639.5MB, bw=3763.1KB/s, iops=58 , runt=446129msec
clat (usec): min=348 , max=282169 , avg=6285.01, stdev=12730.52
lat (usec): min=348 , max=282170 , avg=6285.25, stdev=12730.52
clat percentiles (usec):
| 1.00th=[ 382], 5.00th=[ 402], 10.00th=[ 462], 20.00th=[ 700],
| 30.00th=[ 1832], 40.00th=[ 3024], 50.00th=[ 5024], 60.00th=[ 6176],
| 70.00th=[ 7648], 80.00th=[ 9408], 90.00th=[12096], 95.00th=[14528],
| 99.00th=[21632], 99.50th=[30080], 99.90th=[205824], 99.95th=[228352],
| 99.99th=[272384]
bw (KB/s) : min= 125, max= 8576, per=28.37%, avg=3801.75, stdev=1382.74
lat (usec) : 500=39.72%, 750=9.05%, 1000=2.88%
lat (msec) : 2=4.47%, 4=7.82%, 10=18.33%, 20=9.20%, 50=5.20%
lat (msec) : 100=2.29%, 250=0.97%, 500=0.04%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.37%, sys=0.41%, ctx=59120, majf=0, minf=652
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26231/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3607
read : io=2048.0MB, bw=4082.6KB/s, iops=63 , runt=513683msec
clat (usec): min=297 , max=9516.5K, avg=10370.37, stdev=63661.86
lat (usec): min=453 , max=13012K, avg=5322112.07, stdev=4199536.63
clat percentiles (usec):
| 1.00th=[ 318], 5.00th=[ 318], 10.00th=[ 322], 20.00th=[ 346],
| 30.00th=[ 354], 40.00th=[ 354], 50.00th=[ 362], 60.00th=[ 370],
| 70.00th=[ 628], 80.00th=[ 3184], 90.00th=[33024], 95.00th=[60672],
| 99.00th=[140288], 99.50th=[181248], 99.90th=[268288], 99.95th=[325632],
| 99.99th=[700416]
bw (KB/s) : min= 55, max= 3555, per=5.58%, avg=880.50, stdev=354.66
write: io=1638.2MB, bw=3350.6KB/s, iops=52 , runt=500672msec
clat (usec): min=313 , max=2696.2K, avg=6576.57, stdev=27827.49
lat (usec): min=314 , max=2696.3K, avg=6576.80, stdev=27827.49
clat percentiles (usec):
| 1.00th=[ 358], 5.00th=[ 390], 10.00th=[ 418], 20.00th=[ 628],
| 30.00th=[ 1064], 40.00th=[ 2736], 50.00th=[ 4080], 60.00th=[ 5984],
| 70.00th=[ 7328], 80.00th=[ 9280], 90.00th=[12224], 95.00th=[14656],
| 99.00th=[23424], 99.50th=[89600], 99.90th=[228352], 99.95th=[272384],
| 99.99th=[1011712]
bw (KB/s) : min= 44, max=14632, per=26.23%, avg=3515.16, stdev=1613.71
lat (usec) : 500=42.28%, 750=9.49%, 1000=2.99%
lat (msec) : 2=4.42%, 4=7.39%, 10=16.10%, 20=8.69%, 50=4.81%
lat (msec) : 100=2.47%, 250=1.25%, 500=0.09%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%, >=2000=0.01%
cpu : usr=0.34%, sys=0.38%, ctx=59101, majf=0, minf=651
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26211/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=8192.0MB, aggrb=15793KB/s, minb=3948KB/s, maxb=4383KB/s, mint=478437msec, maxt=531147msec
WRITE: io=6552.7MB, aggrb=13401KB/s, minb=3350KB/s, maxb=3763KB/s, mint=446129msec, maxt=500672msec
Disk stats (read/write):
dm-2: ios=130764/106405, merge=0/0, ticks=1318168/4867904, in_queue=6186396, util=100.00%, aggrios=43704/35515, aggrmerge=1/170, aggrticks=439133/881230, aggrin_queue=1320297, aggrutil=100.00%
dm-0: ios=40/455, merge=0/0, ticks=12/52, in_queue=64, util=0.01%, aggrios=4131/4170, aggrmerge=0/178, aggrticks=1408/1144, aggrin_queue=2548, aggrutil=0.47%
sdc: ios=4131/4170, merge=0/178, ticks=1408/1144, in_queue=2548, util=0.47%
dm-1: ios=4091/3893, merge=0/0, ticks=1392/1096, in_queue=2488, util=0.46%
sdd: ios=126982/102198, merge=3/512, ticks=1315996/2642544, in_queue=3958340, util=100.00%
[-- Attachment #5: mq-old-12G.txt --]
[-- Type: text/plain, Size: 8986 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: (groupid=0, jobs=1): err= 0: pid=4599
read : io=12288MB, bw=3843.5KB/s, iops=60 , runt=3273888msec
clat (usec): min=281 , max=972349 , avg=11584.85, stdev=34844.24
lat (usec): min=318 , max=247506K, avg=120099137.88, stdev=90705677.60
clat percentiles (usec):
| 1.00th=[ 302], 5.00th=[ 314], 10.00th=[ 322], 20.00th=[ 338],
| 30.00th=[ 338], 40.00th=[ 346], 50.00th=[ 350], 60.00th=[ 366],
| 70.00th=[ 628], 80.00th=[ 5984], 90.00th=[34560], 95.00th=[71168],
| 99.00th=[179200], 99.50th=[224256], 99.90th=[342016], 99.95th=[391168],
| 99.99th=[518144]
bw (KB/s) : min= 102, max= 3047, per=5.52%, avg=848.53, stdev=375.93
write: io=9826.9MB, bw=3324.2KB/s, iops=51 , runt=3026383msec
clat (usec): min=313 , max=631276 , avg=6275.83, stdev=22326.99
lat (usec): min=313 , max=631276 , avg=6276.06, stdev=22326.99
clat percentiles (usec):
| 1.00th=[ 346], 5.00th=[ 382], 10.00th=[ 398], 20.00th=[ 596],
| 30.00th=[ 732], 40.00th=[ 1528], 50.00th=[ 3120], 60.00th=[ 4448],
| 70.00th=[ 6560], 80.00th=[ 8256], 90.00th=[11072], 95.00th=[13760],
| 99.00th=[26240], 99.50th=[156672], 99.90th=[362496], 99.95th=[403456],
| 99.99th=[518144]
bw (KB/s) : min= 101, max=12621, per=25.55%, avg=3399.78, stdev=1749.48
lat (usec) : 500=43.46%, 750=10.72%, 1000=2.95%
lat (msec) : 2=4.63%, 4=7.98%, 10=13.90%, 20=7.63%, 50=4.36%
lat (msec) : 100=2.37%, 250=1.68%, 500=0.30%, 750=0.01%, 1000=0.01%
cpu : usr=0.34%, sys=0.40%, ctx=354161, majf=0, minf=5528
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157229/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=4600
read : io=12288MB, bw=3916.8KB/s, iops=61 , runt=3212586msec
clat (usec): min=277 , max=1492.4K, avg=12085.38, stdev=51093.65
lat (usec): min=374 , max=704904K, avg=367291688.03, stdev=260083263.18
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 302], 10.00th=[ 306], 20.00th=[ 318],
| 30.00th=[ 338], 40.00th=[ 346], 50.00th=[ 354], 60.00th=[ 374],
| 70.00th=[ 588], 80.00th=[ 2768], 90.00th=[30848], 95.00th=[64768],
| 99.00th=[189440], 99.50th=[257024], 99.90th=[839680], 99.95th=[1073152],
| 99.99th=[1204224]
bw (KB/s) : min= 88, max= 3031, per=6.64%, avg=1020.21, stdev=379.64
write: io=9832.9MB, bw=4015.2KB/s, iops=62 , runt=2507683msec
clat (usec): min=310 , max=1158.7K, avg=5256.09, stdev=18701.23
lat (usec): min=310 , max=1158.7K, avg=5256.33, stdev=18701.23
clat percentiles (usec):
| 1.00th=[ 322], 5.00th=[ 334], 10.00th=[ 338], 20.00th=[ 390],
| 30.00th=[ 588], 40.00th=[ 908], 50.00th=[ 2608], 60.00th=[ 3952],
| 70.00th=[ 6368], 80.00th=[ 8032], 90.00th=[10816], 95.00th=[13504],
| 99.00th=[21888], 99.50th=[29312], 99.90th=[350208], 99.95th=[382976],
| 99.99th=[428032]
bw (KB/s) : min= 84, max=13029, per=30.82%, avg=4099.73, stdev=1870.33
lat (usec) : 500=49.44%, 750=8.86%, 1000=2.31%
lat (msec) : 2=4.15%, 4=6.65%, 10=13.64%, 20=7.12%, 50=3.96%
lat (msec) : 100=2.18%, 250=1.29%, 500=0.28%, 750=0.04%, 1000=0.02%
lat (msec) : 2000=0.04%
cpu : usr=0.35%, sys=0.40%, ctx=354208, majf=0, minf=7411
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157325/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=4601
read : io=12288MB, bw=3948.7KB/s, iops=61 , runt=3186636msec
clat (usec): min=279 , max=1591.2K, avg=12379.47, stdev=58861.06
lat (usec): min=413 , max=886691K, avg=449620848.40, stdev=334167859.74
clat percentiles (usec):
| 1.00th=[ 290], 5.00th=[ 302], 10.00th=[ 306], 20.00th=[ 314],
| 30.00th=[ 334], 40.00th=[ 346], 50.00th=[ 354], 60.00th=[ 374],
| 70.00th=[ 556], 80.00th=[ 2064], 90.00th=[27776], 95.00th=[62208],
| 99.00th=[203776], 99.50th=[292864], 99.90th=[1044480], 99.95th=[1105920],
| 99.99th=[1236992]
bw (KB/s) : min= 96, max= 3321, per=7.24%, avg=1113.63, stdev=409.97
write: io=9827.4MB, bw=4375.5KB/s, iops=68 , runt=2299946msec
clat (usec): min=310 , max=1032.4K, avg=4723.78, stdev=16847.92
lat (usec): min=311 , max=1032.4K, avg=4724.03, stdev=16847.92
clat percentiles (usec):
| 1.00th=[ 326], 5.00th=[ 330], 10.00th=[ 338], 20.00th=[ 346],
| 30.00th=[ 406], 40.00th=[ 636], 50.00th=[ 1336], 60.00th=[ 3344],
| 70.00th=[ 5920], 80.00th=[ 7584], 90.00th=[10560], 95.00th=[13120],
| 99.00th=[21120], 99.50th=[25472], 99.90th=[337920], 99.95th=[366592],
| 99.99th=[423936]
bw (KB/s) : min= 169, max=13460, per=33.51%, avg=4458.03, stdev=2039.25
lat (usec) : 500=52.79%, 750=8.56%, 1000=2.19%
lat (msec) : 2=4.02%, 4=5.96%, 10=12.74%, 20=6.49%, 50=3.64%
lat (msec) : 100=1.99%, 250=1.19%, 500=0.28%, 750=0.05%, 1000=0.04%
lat (msec) : 2000=0.07%
cpu : usr=0.35%, sys=0.42%, ctx=354586, majf=0, minf=4992
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157238/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=4602
read : io=12288MB, bw=3854.6KB/s, iops=60 , runt=3264430msec
clat (usec): min=290 , max=1079.9K, avg=11607.28, stdev=34089.51
lat (usec): min=368 , max=290032K, avg=141951293.18, stdev=99049941.32
clat percentiles (usec):
| 1.00th=[ 302], 5.00th=[ 314], 10.00th=[ 322], 20.00th=[ 338],
| 30.00th=[ 346], 40.00th=[ 350], 50.00th=[ 358], 60.00th=[ 370],
| 70.00th=[ 644], 80.00th=[ 7520], 90.00th=[35072], 95.00th=[70144],
| 99.00th=[181248], 99.50th=[222208], 99.90th=[313344], 99.95th=[370688],
| 99.99th=[485376]
bw (KB/s) : min= 66, max= 2959, per=5.60%, avg=860.86, stdev=370.12
write: io=9833.7MB, bw=3385.5KB/s, iops=52 , runt=2974408msec
clat (usec): min=337 , max=1036.9K, avg=6183.67, stdev=21372.93
lat (usec): min=337 , max=1036.9K, avg=6183.91, stdev=21372.93
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 390], 10.00th=[ 406], 20.00th=[ 620],
| 30.00th=[ 828], 40.00th=[ 2096], 50.00th=[ 3248], 60.00th=[ 4640],
| 70.00th=[ 6624], 80.00th=[ 8256], 90.00th=[11072], 95.00th=[13760],
| 99.00th=[24448], 99.50th=[148480], 99.90th=[358400], 99.95th=[399360],
| 99.99th=[514048]
bw (KB/s) : min= 104, max=12876, per=26.02%, avg=3461.92, stdev=1741.81
lat (usec) : 500=42.47%, 750=10.57%, 1000=2.85%
lat (msec) : 2=4.74%, 4=8.34%, 10=14.48%, 20=7.74%, 50=4.45%
lat (msec) : 100=2.46%, 250=1.63%, 500=0.26%, 750=0.01%, 1000=0.01%
lat (msec) : 2000=0.01%
cpu : usr=0.34%, sys=0.40%, ctx=354217, majf=0, minf=5630
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157338/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=49152MB, aggrb=15373KB/s, minb=3843KB/s, maxb=3948KB/s, mint=3186636msec, maxt=3273888msec
WRITE: io=39321MB, aggrb=13304KB/s, minb=3324KB/s, maxb=4375KB/s, mint=2299946msec, maxt=3026383msec
Disk stats (read/write):
dm-2: ios=786230/631907, merge=0/0, ticks=9305368/7871784, in_queue=17177236, util=100.00%, aggrios=262144/210908, aggrmerge=0/128, aggrticks=3100856/1998866, aggrin_queue=5099316, aggrutil=100.00%
dm-0: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00%, aggrios=89116/73249, aggrmerge=0/658, aggrticks=31544/21592, aggrin_queue=53032, aggrutil=1.61%
sdc: ios=89116/73249, merge=0/658, ticks=31544/21592, in_queue=53032, util=1.61%
dm-1: ios=89116/73907, merge=0/0, ticks=31480/21576, in_queue=53056, util=1.61%
sdd: ios=697316/558818, merge=0/384, ticks=9271088/5975024, in_queue=15244892, util=100.00%
[-- Attachment #6: mq-old-status-2G.txt --]
[-- Type: text/plain, Size: 217 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 51/1918 4148 127149 38030 136621 0 1686 1686 1685 0 2 migration_threshold 2048 4 random_threshold 4 sequential_threshold 512
blocks-test: 0 11717120 linear
[-- Attachment #7: mq-old-status-12G.txt --]
[-- Type: text/plain, Size: 222 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 51/1918 89198 697484 129732 737278 0 22885 22885 22885 0 2 migration_threshold 2048 4 random_threshold 4 sequential_threshold 512
blocks-test: 0 11717120 linear
[-- Attachment #8: mq-status-2G.txt --]
[-- Type: text/plain, Size: 330 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 8 51/1918 512 12589/22885 34206 97088 37192 103226 0 12589 0 1 writeback 2 migration_threshold 2048 mq 10 random_threshold 4 sequential_threshold 512 discard_promote_adjustment 1 read_promote_adjustment 4 write_promote_adjustment 8 rw -
blocks-test: 0 11717120 linear
[-- Attachment #9: mq-status-12G.txt --]
[-- Type: text/plain, Size: 334 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 8 51/1918 512 22885/22885 78800 707879 92403 739669 8958 31843 0 1 writeback 2 migration_threshold 2048 mq 10 random_threshold 4 sequential_threshold 512 discard_promote_adjustment 1 read_promote_adjustment 4 write_promote_adjustment 8 rw -
blocks-test: 0 11717120 linear
[-- Attachment #10: smq-2G.txt --]
[-- Type: text/plain, Size: 8641 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: Laying out IO file(s) (1 file(s) / 2048MB)
randrw: (groupid=0, jobs=1): err= 0: pid=3710
read : io=2048.0MB, bw=45705KB/s, iops=714 , runt= 45885msec
clat (usec): min=400 , max=66749 , avg=982.63, stdev=859.75
lat (usec): min=406 , max=18775K, avg=7591279.47, stdev=6115340.60
clat percentiles (usec):
| 1.00th=[ 516], 5.00th=[ 596], 10.00th=[ 604], 20.00th=[ 620],
| 30.00th=[ 636], 40.00th=[ 644], 50.00th=[ 660], 60.00th=[ 676],
| 70.00th=[ 716], 80.00th=[ 924], 90.00th=[ 2448], 95.00th=[ 3152],
| 99.00th=[ 3536], 99.50th=[ 3664], 99.90th=[ 4832], 99.95th=[ 5664],
| 99.99th=[ 6752]
bw (KB/s) : min=13003, max=17408, per=43.65%, avg=15413.61, stdev=905.49
write: io=1640.2MB, bw=61949KB/s, iops=967 , runt= 27111msec
clat (usec): min=311 , max=19534 , avg=447.84, stdev=289.19
lat (usec): min=311 , max=19534 , avg=448.16, stdev=289.19
clat percentiles (usec):
| 1.00th=[ 318], 5.00th=[ 322], 10.00th=[ 326], 20.00th=[ 330],
| 30.00th=[ 338], 40.00th=[ 430], 50.00th=[ 450], 60.00th=[ 454],
| 70.00th=[ 462], 80.00th=[ 478], 90.00th=[ 498], 95.00th=[ 676],
| 99.00th=[ 812], 99.50th=[ 2040], 99.90th=[ 4832], 99.95th=[ 5664],
| 99.99th=[ 6688]
bw (KB/s) : min=55424, max=67832, per=100.00%, avg=61997.63, stdev=2994.70
lat (usec) : 500=40.94%, 750=44.26%, 1000=3.97%
lat (msec) : 2=4.39%, 4=6.26%, 10=0.18%, 20=0.01%, 100=0.01%
cpu : usr=4.31%, sys=4.07%, ctx=59133, majf=0, minf=7264
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26242/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3711
read : io=2048.0MB, bw=45745KB/s, iops=714 , runt= 45844msec
clat (usec): min=416 , max=58092 , avg=985.58, stdev=875.66
lat (usec): min=416 , max=18558K, avg=7402410.91, stdev=6056189.25
clat percentiles (usec):
| 1.00th=[ 516], 5.00th=[ 596], 10.00th=[ 604], 20.00th=[ 620],
| 30.00th=[ 636], 40.00th=[ 644], 50.00th=[ 660], 60.00th=[ 676],
| 70.00th=[ 708], 80.00th=[ 924], 90.00th=[ 2480], 95.00th=[ 3152],
| 99.00th=[ 3536], 99.50th=[ 3664], 99.90th=[ 4832], 99.95th=[ 6112],
| 99.99th=[22144]
bw (KB/s) : min=12800, max=17466, per=44.08%, avg=15565.59, stdev=983.05
write: io=1633.6MB, bw=61291KB/s, iops=957 , runt= 27291msec
clat (usec): min=312 , max=9205 , avg=444.99, stdev=256.66
lat (usec): min=312 , max=9206 , avg=445.32, stdev=256.66
clat percentiles (usec):
| 1.00th=[ 318], 5.00th=[ 322], 10.00th=[ 326], 20.00th=[ 330],
| 30.00th=[ 338], 40.00th=[ 430], 50.00th=[ 450], 60.00th=[ 458],
| 70.00th=[ 462], 80.00th=[ 478], 90.00th=[ 494], 95.00th=[ 668],
| 99.00th=[ 756], 99.50th=[ 1720], 99.90th=[ 4704], 99.95th=[ 5344],
| 99.99th=[ 6112]
bw (KB/s) : min=52480, max=69632, per=100.00%, avg=61312.72, stdev=3462.32
lat (usec) : 500=40.93%, 750=44.31%, 1000=4.03%
lat (msec) : 2=4.25%, 4=6.30%, 10=0.17%, 50=0.01%, 100=0.01%
cpu : usr=4.41%, sys=4.00%, ctx=58965, majf=0, minf=3378
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26136/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3712
read : io=2048.0MB, bw=10147KB/s, iops=158 , runt=206683msec
clat (usec): min=299 , max=345627 , avg=4751.36, stdev=12680.94
lat (usec): min=347 , max=61563K, avg=14950365.88, stdev=18983034.76
clat percentiles (usec):
| 1.00th=[ 326], 5.00th=[ 398], 10.00th=[ 414], 20.00th=[ 434],
| 30.00th=[ 446], 40.00th=[ 462], 50.00th=[ 482], 60.00th=[ 612],
| 70.00th=[ 1336], 80.00th=[ 4896], 90.00th=[13632], 95.00th=[24192],
| 99.00th=[58624], 99.50th=[79360], 99.90th=[128512], 99.95th=[173056],
| 99.99th=[272384]
bw (KB/s) : min= 883, max= 5165, per=8.33%, avg=2939.96, stdev=754.22
write: io=1633.3MB, bw=11525KB/s, iops=180 , runt=145121msec
clat (usec): min=311 , max=300928 , avg=1881.31, stdev=10199.41
lat (usec): min=312 , max=300929 , avg=1881.66, stdev=10199.41
clat percentiles (usec):
| 1.00th=[ 318], 5.00th=[ 322], 10.00th=[ 322], 20.00th=[ 326],
| 30.00th=[ 334], 40.00th=[ 362], 50.00th=[ 386], 60.00th=[ 458],
| 70.00th=[ 588], 80.00th=[ 756], 90.00th=[ 2800], 95.00th=[ 5600],
| 99.00th=[24448], 99.50th=[63744], 99.90th=[150528], 99.95th=[222208],
| 99.99th=[288768]
bw (KB/s) : min= 4355, max=21461, per=38.54%, avg=11569.80, stdev=3282.78
lat (usec) : 500=58.15%, 750=11.93%, 1000=4.07%
lat (msec) : 2=5.86%, 4=5.37%, 10=6.68%, 20=3.93%, 50=2.98%
lat (msec) : 100=0.78%, 250=0.23%, 500=0.03%
cpu : usr=0.92%, sys=0.86%, ctx=59041, majf=0, minf=12936
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26132/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3713
read : io=2048.0MB, bw=8828.6KB/s, iops=137 , runt=237542msec
clat (usec): min=284 , max=342968 , avg=4883.48, stdev=12599.33
lat (usec): min=290 , max=14376K, avg=6076996.16, stdev=4724141.50
clat percentiles (usec):
| 1.00th=[ 286], 5.00th=[ 290], 10.00th=[ 294], 20.00th=[ 314],
| 30.00th=[ 326], 40.00th=[ 330], 50.00th=[ 334], 60.00th=[ 346],
| 70.00th=[ 652], 80.00th=[ 5216], 90.00th=[16512], 95.00th=[27520],
| 99.00th=[56064], 99.50th=[71168], 99.90th=[124416], 99.95th=[154624],
| 99.99th=[261120]
bw (KB/s) : min= 664, max= 4707, per=5.39%, avg=1902.12, stdev=644.92
write: io=1635.9MB, bw=7506.3KB/s, iops=117 , runt=223166msec
clat (usec): min=317 , max=309529 , avg=2891.79, stdev=11293.61
lat (usec): min=318 , max=309530 , avg=2892.14, stdev=11293.61
clat percentiles (usec):
| 1.00th=[ 330], 5.00th=[ 334], 10.00th=[ 342], 20.00th=[ 378],
| 30.00th=[ 398], 40.00th=[ 482], 50.00th=[ 580], 60.00th=[ 700],
| 70.00th=[ 972], 80.00th=[ 2768], 90.00th=[ 6688], 95.00th=[10560],
| 99.00th=[31360], 99.50th=[68096], 99.90th=[175104], 99.95th=[244736],
| 99.99th=[288768]
bw (KB/s) : min= 2304, max=17833, per=25.15%, avg=7549.48, stdev=2514.55
lat (usec) : 500=54.78%, 750=13.66%, 1000=4.35%
lat (msec) : 2=4.06%, 4=5.16%, 10=6.93%, 20=5.98%, 50=3.98%
lat (msec) : 100=0.85%, 250=0.22%, 500=0.03%
cpu : usr=0.83%, sys=0.73%, ctx=59014, majf=0, minf=4694
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=32768/w=26174/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=8192.0MB, aggrb=35314KB/s, minb=8828KB/s, maxb=45745KB/s, mint=45844msec, maxt=237542msec
WRITE: io=6542.8MB, aggrb=30021KB/s, minb=7506KB/s, maxb=61948KB/s, mint=27111msec, maxt=223166msec
Disk stats (read/write):
dm-2: ios=130776/107092, merge=0/0, ticks=376672/275036, in_queue=651776, util=99.57%, aggrios=47566/39189, aggrmerge=476/3112, aggrticks=132813/91696, aggrin_queue=224485, aggrutil=98.42%
dm-0: ios=0/6664, merge=0/0, ticks=0/532, in_queue=532, util=0.14%, aggrios=86767/72023, aggrmerge=8480/2907, aggrticks=81588/27856, aggrin_queue=109232, aggrutil=26.31%
sdc: ios=86767/72023, merge=8480/2907, ticks=81588/27856, in_queue=109232, util=26.31%
dm-1: ios=95247/68266, merge=0/0, ticks=101044/28692, in_queue=129776, util=26.24%
sdd: ios=47453/42638, merge=1428/9337, ticks=297396/245864, in_queue=543148, util=98.42%
[-- Attachment #11: smq-12G.txt --]
[-- Type: text/plain, Size: 8892 bytes --]
Multiple writers may overwrite blocks that belong to other jobs. This can cause verification failures.
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
...
randrw: (g=0): rw=randrw, bs=64K-64K/64K-64K, ioengine=sync, iodepth=32
2.0.8
Starting 4 processes
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: Laying out IO file(s) (1 file(s) / 12288MB)
randrw: (groupid=0, jobs=1): err= 0: pid=3677
read : io=12288MB, bw=4445.3KB/s, iops=69 , runt=2830671msec
clat (usec): min=309 , max=581291 , avg=11413.71, stdev=32711.11
lat (usec): min=395 , max=858374K, avg=208791790.47, stdev=270940253.17
clat percentiles (usec):
| 1.00th=[ 334], 5.00th=[ 394], 10.00th=[ 422], 20.00th=[ 442],
| 30.00th=[ 454], 40.00th=[ 470], 50.00th=[ 494], 60.00th=[ 820],
| 70.00th=[ 1720], 80.00th=[ 8640], 90.00th=[32640], 95.00th=[68096],
| 99.00th=[162816], 99.50th=[211968], 99.90th=[342016], 99.95th=[370688],
| 99.99th=[448512]
bw (KB/s) : min= 99, max= 3541, per=9.70%, avg=1300.84, stdev=543.86
write: io=9820.8MB, bw=5098.9KB/s, iops=79 , runt=1972297msec
clat (usec): min=312 , max=474356 , avg=3661.34, stdev=15931.38
lat (usec): min=313 , max=474356 , avg=3661.68, stdev=15931.39
clat percentiles (usec):
| 1.00th=[ 322], 5.00th=[ 322], 10.00th=[ 326], 20.00th=[ 330],
| 30.00th=[ 338], 40.00th=[ 346], 50.00th=[ 410], 60.00th=[ 708],
| 70.00th=[ 1768], 80.00th=[ 4384], 90.00th=[ 8640], 95.00th=[12352],
| 99.00th=[34048], 99.50th=[64768], 99.90th=[313344], 99.95th=[346112],
| 99.99th=[395264]
bw (KB/s) : min= 256, max=16569, per=42.59%, avg=5192.04, stdev=2526.73
lat (usec) : 500=51.94%, 750=7.89%, 1000=3.81%
lat (msec) : 2=7.43%, 4=6.26%, 10=9.24%, 20=4.93%, 50=4.28%
lat (msec) : 100=2.56%, 250=1.41%, 500=0.25%, 750=0.01%
cpu : usr=0.41%, sys=0.39%, ctx=355074, majf=0, minf=135474
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157132/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3678
read : io=12288MB, bw=3362.2KB/s, iops=52 , runt=3741587msec
clat (usec): min=296 , max=592456 , avg=13550.20, stdev=31121.55
lat (usec): min=389 , max=612510K, avg=275986429.89, stdev=207090845.57
clat percentiles (usec):
| 1.00th=[ 366], 5.00th=[ 390], 10.00th=[ 398], 20.00th=[ 402],
| 30.00th=[ 434], 40.00th=[ 486], 50.00th=[ 604], 60.00th=[ 1128],
| 70.00th=[ 6048], 80.00th=[19584], 90.00th=[41216], 95.00th=[70144],
| 99.00th=[150528], 99.50th=[191488], 99.90th=[305152], 99.95th=[337920],
| 99.99th=[423936]
bw (KB/s) : min= 96, max= 2417, per=6.04%, avg=809.57, stdev=305.13
write: io=9847.6MB, bw=3222.7KB/s, iops=50 , runt=3129077msec
clat (usec): min=349 , max=504223 , avg=6764.99, stdev=20015.25
lat (usec): min=349 , max=504223 , avg=6765.33, stdev=20015.25
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 390], 10.00th=[ 402], 20.00th=[ 596],
| 30.00th=[ 780], 40.00th=[ 1272], 50.00th=[ 2832], 60.00th=[ 4048],
| 70.00th=[ 6432], 80.00th=[ 8896], 90.00th=[13760], 95.00th=[21120],
| 99.00th=[55552], 99.50th=[93696], 99.90th=[337920], 99.95th=[362496],
| 99.99th=[411648]
bw (KB/s) : min= 95, max=10750, per=26.85%, avg=3273.59, stdev=1514.03
lat (usec) : 500=30.93%, 750=12.91%, 1000=4.78%
lat (msec) : 2=6.62%, 4=8.72%, 10=13.60%, 20=8.93%, 50=8.57%
lat (msec) : 100=3.25%, 250=1.45%, 500=0.23%, 750=0.01%
cpu : usr=0.33%, sys=0.28%, ctx=356081, majf=0, minf=207366
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157560/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3679
read : io=12288MB, bw=3389.2KB/s, iops=52 , runt=3712660msec
clat (usec): min=300 , max=708556 , avg=13399.77, stdev=30618.15
lat (usec): min=389 , max=564342K, avg=242373040.50, stdev=183403325.58
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 394], 10.00th=[ 398], 20.00th=[ 406],
| 30.00th=[ 442], 40.00th=[ 494], 50.00th=[ 676], 60.00th=[ 1400],
| 70.00th=[ 7904], 80.00th=[18816], 90.00th=[40704], 95.00th=[69120],
| 99.00th=[146432], 99.50th=[187392], 99.90th=[292864], 99.95th=[333824],
| 99.99th=[423936]
bw (KB/s) : min= 95, max= 2276, per=6.11%, avg=819.40, stdev=309.73
write: io=9802.0MB, bw=3188.2KB/s, iops=49 , runt=3148319msec
clat (usec): min=355 , max=454833 , avg=6802.80, stdev=20124.38
lat (usec): min=355 , max=454834 , avg=6803.15, stdev=20124.38
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 386], 10.00th=[ 402], 20.00th=[ 596],
| 30.00th=[ 772], 40.00th=[ 1288], 50.00th=[ 2864], 60.00th=[ 4080],
| 70.00th=[ 6496], 80.00th=[ 9024], 90.00th=[13760], 95.00th=[21376],
| 99.00th=[55552], 99.50th=[93696], 99.90th=[337920], 99.95th=[358400],
| 99.99th=[403456]
bw (KB/s) : min= 100, max=10752, per=26.59%, avg=3241.68, stdev=1512.52
lat (usec) : 500=29.88%, 750=12.90%, 1000=5.02%
lat (msec) : 2=6.84%, 4=8.76%, 10=14.13%, 20=9.10%, 50=8.52%
lat (msec) : 100=3.18%, 250=1.43%, 500=0.23%, 750=0.01%
cpu : usr=0.34%, sys=0.27%, ctx=354078, majf=0, minf=114764
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=156832/d=0, short=r=0/w=0/d=0
randrw: (groupid=0, jobs=1): err= 0: pid=3680
read : io=12288MB, bw=3352.5KB/s, iops=52 , runt=3753341msec
clat (usec): min=285 , max=601743 , avg=13527.31, stdev=33657.57
lat (usec): min=374 , max=451537K, avg=205726082.43, stdev=164134260.89
clat percentiles (usec):
| 1.00th=[ 326], 5.00th=[ 338], 10.00th=[ 374], 20.00th=[ 398],
| 30.00th=[ 406], 40.00th=[ 446], 50.00th=[ 502], 60.00th=[ 700],
| 70.00th=[ 3408], 80.00th=[17280], 90.00th=[41216], 95.00th=[74240],
| 99.00th=[166912], 99.50th=[214016], 99.90th=[325632], 99.95th=[366592],
| 99.99th=[436224]
bw (KB/s) : min= 83, max= 2688, per=5.75%, avg=770.52, stdev=313.85
write: io=9840.6MB, bw=3051.9KB/s, iops=47 , runt=3301805msec
clat (usec): min=353 , max=463390 , avg=6876.75, stdev=20247.19
lat (usec): min=353 , max=463390 , avg=6877.09, stdev=20247.20
clat percentiles (usec):
| 1.00th=[ 374], 5.00th=[ 386], 10.00th=[ 398], 20.00th=[ 596],
| 30.00th=[ 764], 40.00th=[ 1224], 50.00th=[ 2736], 60.00th=[ 3952],
| 70.00th=[ 6432], 80.00th=[ 9152], 90.00th=[14272], 95.00th=[21888],
| 99.00th=[57088], 99.50th=[96768], 99.90th=[333824], 99.95th=[358400],
| 99.99th=[411648]
bw (KB/s) : min= 90, max=11960, per=25.52%, avg=3111.70, stdev=1542.89
lat (usec) : 500=34.25%, 750=13.06%, 1000=4.50%
lat (msec) : 2=6.03%, 4=8.23%, 10=12.44%, 20=8.54%, 50=7.89%
lat (msec) : 100=3.14%, 250=1.63%, 500=0.29%, 750=0.01%
cpu : usr=0.32%, sys=0.27%, ctx=354184, majf=0, minf=11501
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=196608/w=157448/d=0, short=r=0/w=0/d=0
Run status group 0 (all jobs):
READ: io=49152MB, aggrb=13409KB/s, minb=3352KB/s, maxb=4445KB/s, mint=2830671msec, maxt=3753341msec
WRITE: io=39311MB, aggrb=12191KB/s, minb=3051KB/s, maxb=5098KB/s, mint=1972297msec, maxt=3301805msec
Disk stats (read/write):
dm-2: ios=786064/633479, merge=0/0, ticks=10182024/4176864, in_queue=14359152, util=100.00%, aggrios=298177/221751, aggrmerge=256/27328, aggrticks=3467992/1637008, aggrin_queue=5104489, aggrutil=100.00%
dm-0: ios=12/3584, merge=0/0, ticks=0/248, in_queue=248, util=0.00%, aggrios=113193/73812, aggrmerge=81830/2440, aggrticks=101916/22808, aggrin_queue=124452, aggrutil=2.57%
sdc: ios=113193/73812, merge=81830/2440, ticks=101916/22808, in_queue=124452, util=2.57%
dm-1: ios=195011/72668, merge=0/0, ticks=277792/23688, in_queue=301504, util=2.58%
sdd: ios=699509/589001, merge=768/81986, ticks=10126184/4887088, in_queue=15011716, util=100.00%
[-- Attachment #12: smq-status-2G.txt --]
[-- Type: text/plain, Size: 209 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 8 51/1918 512 22885/22885 84305 47082 87850 53520 476 23361 19216 1 writeback 2 migration_threshold 2048 smq 0 rw -
blocks-test: 0 11717120 linear
[-- Attachment #13: smq-status-12G.txt --]
[-- Type: text/plain, Size: 210 bytes --]
metadata-test: 0 15350 linear
cachetest: 0 124995584 cache 8 51/1918 512 22885/22885 87321 699358 94266 738860 270 23155 7276 1 writeback 2 migration_threshold 2048 smq 0 rw -
blocks-test: 0 11717120 linear
[-- Attachment #14: Type: text/plain, Size: 0 bytes --]
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Severe performance degradation for dm-cache mq since c86c3070
2015-09-11 20:32 ` Andrey Korolyov
@ 2015-09-12 22:15 ` Andrey Korolyov
2015-09-18 15:30 ` Joe Thornber
1 sibling, 0 replies; 6+ messages in thread
From: Andrey Korolyov @ 2015-09-12 22:15 UTC (permalink / raw)
To: thornber; +Cc: heinzm, ejt, dm-devel, snitzer
On Fri, Sep 11, 2015 at 11:32 PM, Andrey Korolyov <andrey@xdel.ru> wrote:
>> This was running a smaller test than you with only 2G per thread.
>
>> Have you tried playing with the migration_threshold tunable? With
>> random IO such as this we really want the cache to initially populate
>> the cache but then do no churning. Could you give me the status line
>> for the caches once you've run the tests please? This would tell me
>> how many blocks are being demoted.
>
> Please CC me always, as I am not subscribed to dm-devel.
>
> Short-runs are tend to show better results on smq, but real-world
> applications have at most long-running workloads with sustained cache
> usage pattern where old algorithm shows a best result. I`ll give a try
> for tunables and post results separately. Please take a look on an
> attached results - at a given cache size smq outperforms all other
> algorithms but both new mq and smq performs poorly when cache fills up
> and issuing demotions. Status outputs are given right after test
> completion. Hardware platform was changed for test, so absolute values
> can differ from ones in original message.
>
> The r/w ratio, block size and random pattern are selected to represent
> a typical SDS workload on top of the cache, but, as I pointed earlier,
> it is a quite inaccurate simulation - the hit curve is impossible to
> reproduce with fio.
Replying to myself back - migration_threshold increase does not make
situation better, when reduction results in a worse situation than
with default value. As far as I can see 'new' mq suffers from the
immediate processing of the promoted blocks on update when 'old' one
delays their processing (not in a very good manner, though, because a
large plateau of the blocks which has every right to be demoted
remains in this case in front cache).
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Severe performance degradation for dm-cache mq since c86c3070
2015-09-11 20:32 ` Andrey Korolyov
2015-09-12 22:15 ` Andrey Korolyov
@ 2015-09-18 15:30 ` Joe Thornber
2015-09-22 11:24 ` Andrey Korolyov
1 sibling, 1 reply; 6+ messages in thread
From: Joe Thornber @ 2015-09-18 15:30 UTC (permalink / raw)
To: Andrey Korolyov; +Cc: heinzm, ejt, dm-devel, snitzer
On Fri, Sep 11, 2015 at 11:32:38PM +0300, Andrey Korolyov wrote:
> Please take a look on an
> attached results - at a given cache size smq outperforms all other
> algorithms but both new mq and smq performs poorly when cache fills up
> and issuing demotions.
Having looked at your results again I think there are two issues here:
i) You're expecting dm-cache to be a writeback cache that streams
_all_ writes to the SSD, and then updates the spindle in the
background. It's not, it's a slow moving cache that promotes specific
regions of the spindle to the SSD.
ii) You're doing random, small, sync IO. Which evenly hits all areas.
In this case the cache has a really hard time improving over the
performance of the spindle. In your tests I think you have around 6G
of SSD and 48G of active data. So only 1 in 8 IOs are going to hit the
SSD; any benefits will be marginal. You use the same SSD size when
running with an 8G work load, so nearly every IO hits the SSD. Hence
better performance.
Does this benchmark really reflect your use case?
- Joe
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Severe performance degradation for dm-cache mq since c86c3070
2015-09-18 15:30 ` Joe Thornber
@ 2015-09-22 11:24 ` Andrey Korolyov
0 siblings, 0 replies; 6+ messages in thread
From: Andrey Korolyov @ 2015-09-22 11:24 UTC (permalink / raw)
To: Andrey Korolyov, snitzer, ejt, heinzm, dm-devel
On Fri, Sep 18, 2015 at 6:30 PM, Joe Thornber <thornber@redhat.com> wrote:
> On Fri, Sep 11, 2015 at 11:32:38PM +0300, Andrey Korolyov wrote:
>> Please take a look on an
>> attached results - at a given cache size smq outperforms all other
>> algorithms but both new mq and smq performs poorly when cache fills up
>> and issuing demotions.
>
> Having looked at your results again I think there are two issues here:
>
> i) You're expecting dm-cache to be a writeback cache that streams
> _all_ writes to the SSD, and then updates the spindle in the
> background. It's not, it's a slow moving cache that promotes specific
> regions of the spindle to the SSD.
>
> ii) You're doing random, small, sync IO. Which evenly hits all areas.
> In this case the cache has a really hard time improving over the
> performance of the spindle. In your tests I think you have around 6G
> of SSD and 48G of active data. So only 1 in 8 IOs are going to hit the
> SSD; any benefits will be marginal. You use the same SSD size when
> running with an 8G work load, so nearly every IO hits the SSD. Hence
> better performance.
>
> Does this benchmark really reflect your use case?
Not really, I tried to reproduce worst possible case for writeback
cache. The main problem for fine representation of the production SDS
workload is a lack of hot read/write spots and apparent lack in
pattern differences - writes tends to be sequential and group over
several spots at most and reads are mostly scattered. Despite
relatively small difference b/w 3.10 and 3.18 policy in fio test above
the real-world workload with described r/w patterns differs more
heavily, but I`m afraid that nobody from the list would want to set up
a Ceph/Gluster cluster to put a couple of VMs on to to reproduce that.
For a random worst-case randrw I assume that the current SMQ *could*
be outperformed by modified version which delays block eviction in a
same manner as it was in 3.10. If I miss a case where delayed eviction
would perform worse, please point me at those.
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2015-09-22 11:24 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-09-10 14:39 Severe performance degradation for dm-cache mq since c86c3070 Andrey Korolyov
2015-09-11 12:58 ` Joe Thornber
2015-09-11 20:32 ` Andrey Korolyov
2015-09-12 22:15 ` Andrey Korolyov
2015-09-18 15:30 ` Joe Thornber
2015-09-22 11:24 ` Andrey Korolyov
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.