[dm-devel] Severe performance degradation for dm-cache mq since c86c3070

[Andrey Korolyov]

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.
-------------- next part --------------
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'
-------------- next part --------------
[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
-------------- next part --------------
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%
-------------- next part --------------
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%