4k randreads over 1 GB RBD image - the cache hit scenario

wip-bs-async-delegation---rbd_randread_4kB_1G_bscache.txt

rbd_iodepth32: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=rbd, iodepth=32
fio-3.0-32-g83070-dirty
Starting 1 process

rbd_iodepth32: (groupid=0, jobs=1): err= 0: pid=32696: Tue Jan 16 13:25:51 2018
   read: IOPS=29.1k, BW=114MiB/s (119MB/s)(6814MiB/60001msec)
    slat (nsec): min=1004, max=872435, avg=7025.71, stdev=18582.37
    clat (usec): min=141, max=9765, avg=1092.74, stdev=350.96
     lat (usec): min=148, max=9790, avg=1099.76, stdev=349.95
    clat percentiles (usec):
     |  1.00th=[  408],  5.00th=[  586], 10.00th=[  701], 20.00th=[  832],
     | 30.00th=[  922], 40.00th=[ 1004], 50.00th=[ 1074], 60.00th=[ 1156],
     | 70.00th=[ 1221], 80.00th=[ 1319], 90.00th=[ 1483], 95.00th=[ 1631],
     | 99.00th=[ 1991], 99.50th=[ 2212], 99.90th=[ 4293], 99.95th=[ 4883],
     | 99.99th=[ 5800]
   bw (  KiB/s): min=112312, max=119072, per=100.00%, avg=116296.77, stdev=1346.09, samples=120
   iops        : min=28078, max=29768, avg=29074.23, stdev=336.52, samples=120
  lat (usec)   : 250=0.04%, 500=2.55%, 750=10.74%, 1000=26.25%
  lat (msec)   : 2=59.43%, 4=0.86%, 10=0.12%
  cpu          : usr=42.84%, sys=29.41%, ctx=2103493, majf=0, minf=7
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued rwt: total=1744427,0,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: bw=114MiB/s (119MB/s), 114MiB/s-114MiB/s (119MB/s-119MB/s), io=6814MiB (7145MB), run=60001-60001msec

Disk stats (read/write):
    dm-1: ios=0/928, merge=0/0, ticks=0/828, in_queue=828, util=1.17%, aggrios=0/1085, aggrmerge=0/0, aggrticks=0/856, aggrin_queue=856, aggrutil=1.19%
    dm-0: ios=0/1085, merge=0/0, ticks=0/856, in_queue=856, util=1.19%, aggrios=0/747, aggrmerge=0/338, aggrticks=0/740, aggrin_queue=740, aggrutil=1.14%
  nvme0n1: ios=0/747, merge=0/338, ticks=0/740, in_queue=740, util=1.14%

wip-bs-async-delegation_ref---rbd_randread_4kB_1G_bscache.txt

rbd_iodepth32: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=rbd, iodepth=32
fio-3.0-32-g83070-dirty
Starting 1 process

rbd_iodepth32: (groupid=0, jobs=1): err= 0: pid=17243: Tue Jan 16 14:15:04 2018
   read: IOPS=28.4k, BW=111MiB/s (116MB/s)(6653MiB/60001msec)
    slat (nsec): min=1004, max=1629.8k, avg=7284.77, stdev=19110.80
    clat (usec): min=159, max=9232, avg=1119.17, stdev=363.59
     lat (usec): min=167, max=9234, avg=1126.46, stdev=362.59
    clat percentiles (usec):
     |  1.00th=[  420],  5.00th=[  603], 10.00th=[  717], 20.00th=[  848],
     | 30.00th=[  947], 40.00th=[ 1029], 50.00th=[ 1090], 60.00th=[ 1172],
     | 70.00th=[ 1254], 80.00th=[ 1352], 90.00th=[ 1516], 95.00th=[ 1680],
     | 99.00th=[ 2089], 99.50th=[ 2409], 99.90th=[ 4293], 99.95th=[ 4948],
     | 99.99th=[ 5866]
   bw (  KiB/s): min=100408, max=117608, per=100.00%, avg=113539.24, stdev=2732.98, samples=120
   iops        : min=25102, max=29402, avg=28384.80, stdev=683.23, samples=120
  lat (usec)   : 250=0.03%, 500=2.22%, 750=9.79%, 1000=24.76%
  lat (msec)   : 2=61.86%, 4=1.21%, 10=0.13%
  cpu          : usr=42.95%, sys=29.08%, ctx=2174483, majf=0, minf=7
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued rwt: total=1703065,0,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: bw=111MiB/s (116MB/s), 111MiB/s-111MiB/s (116MB/s-116MB/s), io=6653MiB (6976MB), run=60001-60001msec

Disk stats (read/write):
    dm-1: ios=2/925, merge=0/0, ticks=16/832, in_queue=848, util=1.20%, aggrios=2/1083, aggrmerge=0/0, aggrticks=16/848, aggrin_queue=864, aggrutil=1.21%
    dm-0: ios=2/1083, merge=0/0, ticks=16/848, in_queue=864, util=1.21%, aggrios=2/751, aggrmerge=0/332, aggrticks=12/776, aggrin_queue=788, aggrutil=1.18%
  nvme0n1: ios=2/751, merge=0/332, ticks=12/776, in_queue=788, util=1.18%