Re: [RFC][PATCH] Make io_submit non-blocking

[Ankit Jain]

On 07/25/2012 04:20 AM, Christoph Hellwig wrote:
> On Wed, Jul 25, 2012 at 08:31:10AM +1000, Dave Chinner wrote:
>> FWIW, if you are going to change generic code, you need to present
>> results for other filesystems as well (xfs, btrfs are typical), as
>> they may not have the same problems as ext4 or react the same way to
>> your change. The result might simply be "it is 20% slower"....
> 
> And most importantly block devices, as they are one of the biggest
> use cases of AIO.  With an almost no-op get_blocks callback I can't
> see how this change would provide any gain there.

I tried running fio against a block device, disk partition and a
ramdisk. I ran this with a single job though. For disks, bandwidth
seems to stay nearly the same with submit latencies getting better.
And for ramdisk, bandwidth also sees improvement. I should probably
be doing better tests, any suggestions on what or how I can test?
For block devices, if the patch doesn't make it worse, at least, then
that should be good enough?

------ disk -------
                                      submit latencies(usec)
       	B/w       iops   runtime     min  max   avg  std dev
Read :
Old:  417335 B/s  101   252668msec     4  231  40.03  21.66
New:  419099 B/s  102   251282msec     0  169   8.20   6.95

Write:
Old:  412667 B/s  100   252668msec     3  272  47.65  24.58
New:  415481 B/s  101   251282msec     0  134   7.95   7.11

------ ramdisk -------
                                      submit latencies(usec)
       	B/w       iops      runtime   min  max   avg  std dev
Read:
Old:  708235KB/s  177058   1227msec     1   51   1.61  0.72
New:  822157KB/s  205539   1059msec     0   14   0.38  0.52

Write:
Old:  710510KB/s  177627   1227msec     2   46   2.33  0.81
New:  821658KB/s  205414   1059msec     0   24   0.40  0.53

Full fio results are attached, and I dropped cache before running
the tests.

-- 
Ankit Jain
SUSE Labs
random_rw: (g=0): rw=randrw, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
fio-2.0.8-9-gfb9f0
Starting 1 process

random_rw: (groupid=0, jobs=1): err= 0: pid=2109: Thu Jul 26 17:14:55 2012
  read : io=102844KB, bw=419099 B/s, iops=102 , runt=251282msec
    slat (usec): min=0 , max=169 , avg= 8.20, stdev= 6.95
    clat (usec): min=335 , max=3356.7K, avg=255054.47, stdev=158234.29
     lat (usec): min=342 , max=3356.7K, avg=255063.32, stdev=158234.33
    clat percentiles (msec):
     |  1.00th=[    8],  5.00th=[   50], 10.00th=[   84], 20.00th=[  130],
     | 30.00th=[  169], 40.00th=[  204], 50.00th=[  237], 60.00th=[  269],
     | 70.00th=[  306], 80.00th=[  351], 90.00th=[  437], 95.00th=[  529],
     | 99.00th=[  791], 99.50th=[  914], 99.90th=[ 1237], 99.95th=[ 1483],
     | 99.99th=[ 2073]
    bw (KB/s)  : min=  111, max=  646, per=100.00%, avg=410.90, stdev=84.69
  write: io=101956KB, bw=415481 B/s, iops=101 , runt=251282msec
    slat (usec): min=0 , max=134 , avg= 7.95, stdev= 7.11
    clat (usec): min=189 , max=928209 , avg=58138.79, stdev=76776.72
     lat (usec): min=194 , max=928221 , avg=58147.37, stdev=76776.86
    clat percentiles (usec):
     |  1.00th=[  498],  5.00th=[  828], 10.00th=[ 1624], 20.00th=[ 4960],
     | 30.00th=[12352], 40.00th=[22144], 50.00th=[33536], 60.00th=[46848],
     | 70.00th=[63232], 80.00th=[90624], 90.00th=[148480], 95.00th=[203776],
     | 99.00th=[370688], 99.50th=[460800], 99.90th=[643072], 99.95th=[716800],
     | 99.99th=[831488]
    bw (KB/s)  : min=   31, max=  864, per=100.00%, avg=408.11, stdev=111.34
    lat (usec) : 250=0.02%, 500=0.54%, 750=1.27%, 1000=1.51%
    lat (msec) : 2=2.39%, 4=3.60%, 10=4.63%, 20=5.96%, 50=13.51%
    lat (msec) : 100=14.18%, 250=27.95%, 500=21.04%, 750=2.78%, 1000=0.46%
    lat (msec) : 2000=0.15%, >=2000=0.01%
  cpu          : usr=0.51%, sys=1.52%, ctx=52135, majf=0, minf=23
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=99.9%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=25711/w=25489/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=102844KB, aggrb=409KB/s, minb=409KB/s, maxb=409KB/s, mint=251282msec, maxt=251282msec
  WRITE: io=101956KB, aggrb=405KB/s, minb=405KB/s, maxb=405KB/s, mint=251282msec, maxt=251282msec
fio rand-rw-disk-2-raw.fio --output=/home/radical/src/play/ios-test/logs-with-drop-cache/ad6d29a/raw-disk-2-raw-ad6d29a.log --max-jobs=2 --latency-log --bandwidth-log
ad6d29a sent upstream
random_rw: (g=0): rw=randrw, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
fio-2.0.8-9-gfb9f0
Starting 1 process

random_rw: (groupid=0, jobs=1): err= 0: pid=2117: Thu Jul 26 17:53:41 2012
  read : io=102976KB, bw=417335 B/s, iops=101 , runt=252668msec
    slat (usec): min=4 , max=231 , avg=40.03, stdev=21.66
    clat (usec): min=236 , max=4075.6K, avg=254175.39, stdev=158853.64
     lat (usec): min=339 , max=4075.7K, avg=254216.22, stdev=158853.33
    clat percentiles (msec):
     |  1.00th=[    7],  5.00th=[   51], 10.00th=[   85], 20.00th=[  131],
     | 30.00th=[  169], 40.00th=[  204], 50.00th=[  237], 60.00th=[  269],
     | 70.00th=[  306], 80.00th=[  351], 90.00th=[  433], 95.00th=[  529],
     | 99.00th=[  766], 99.50th=[  906], 99.90th=[ 1270], 99.95th=[ 1500],
     | 99.99th=[ 3261]
    bw (KB/s)  : min=   83, max=  624, per=100.00%, avg=409.49, stdev=91.68
  write: io=101824KB, bw=412667 B/s, iops=100 , runt=252668msec
    slat (usec): min=3 , max=272 , avg=47.65, stdev=24.58
    clat (usec): min=139 , max=1248.8K, avg=60442.70, stdev=82817.74
     lat (usec): min=198 , max=1248.9K, avg=60491.15, stdev=82817.11
    clat percentiles (usec):
     |  1.00th=[  438],  5.00th=[  812], 10.00th=[ 1704], 20.00th=[ 5280],
     | 30.00th=[13376], 40.00th=[23168], 50.00th=[34560], 60.00th=[47872],
     | 70.00th=[66048], 80.00th=[91648], 90.00th=[150528], 95.00th=[209920],
     | 99.00th=[403456], 99.50th=[505856], 99.90th=[798720], 99.95th=[897024],
     | 99.99th=[1073152]
    bw (KB/s)  : min=    7, max=  808, per=100.00%, avg=405.72, stdev=121.51
    lat (usec) : 250=0.03%, 500=0.79%, 750=1.35%, 1000=1.21%
    lat (msec) : 2=2.29%, 4=3.59%, 10=4.36%, 20=5.90%, 50=13.45%
    lat (msec) : 100=14.37%, 250=28.08%, 500=21.27%, 750=2.73%, 1000=0.42%
    lat (msec) : 2000=0.17%, >=2000=0.01%
  cpu          : usr=0.54%, sys=1.44%, ctx=52211, majf=0, minf=23
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=99.9%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=25744/w=25456/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=102976KB, aggrb=407KB/s, minb=407KB/s, maxb=407KB/s, mint=252668msec, maxt=252668msec
  WRITE: io=101824KB, aggrb=402KB/s, minb=402KB/s, maxb=402KB/s, mint=252668msec, maxt=252668msec
fio rand-rw-disk-2-raw.fio --output=/home/radical/src/play/ios-test/logs-with-drop-cache/918227b/raw-disk-2-raw-918227b.log --max-jobs=2 --latency-log --bandwidth-log
918227b Merge tag 'fbdev-fixes-for-3.5-2' of git://github.com/schandinat/linux-2.6
random_rw: (g=0): rw=randrw, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
fio-2.0.8-9-gfb9f0
Starting 1 process

random_rw: (groupid=0, jobs=1): err= 0: pid=2179: Thu Jul 26 17:14:57 2012
  read : io=870664KB, bw=822157KB/s, iops=205539 , runt=  1059msec
    slat (usec): min=0 , max=14 , avg= 0.38, stdev= 0.52
    clat (usec): min=44 , max=294 , avg=76.67, stdev=12.77
     lat (usec): min=45 , max=296 , avg=77.10, stdev=12.84
    clat percentiles (usec):
     |  1.00th=[   70],  5.00th=[   71], 10.00th=[   72], 20.00th=[   73],
     | 30.00th=[   74], 40.00th=[   74], 50.00th=[   75], 60.00th=[   76],
     | 70.00th=[   76], 80.00th=[   77], 90.00th=[   79], 95.00th=[   86],
     | 99.00th=[   97], 99.50th=[  107], 99.90th=[  255], 99.95th=[  266],
     | 99.99th=[  286]
    bw (KB/s)  : min=819368, max=826656, per=100.00%, avg=823012.00, stdev=5153.39
  write: io=870136KB, bw=821658KB/s, iops=205414 , runt=  1059msec
    slat (usec): min=0 , max=24 , avg= 0.40, stdev= 0.53
    clat (usec): min=42 , max=292 , avg=77.34, stdev=12.81
     lat (usec): min=43 , max=293 , avg=77.79, stdev=12.89
    clat percentiles (usec):
     |  1.00th=[   70],  5.00th=[   72], 10.00th=[   73], 20.00th=[   74],
     | 30.00th=[   74], 40.00th=[   75], 50.00th=[   76], 60.00th=[   76],
     | 70.00th=[   77], 80.00th=[   78], 90.00th=[   80], 95.00th=[   87],
     | 99.00th=[   98], 99.50th=[  107], 99.90th=[  262], 99.95th=[  270],
     | 99.99th=[  286]
    bw (KB/s)  : min=819368, max=825328, per=100.00%, avg=822348.00, stdev=4214.36
    lat (usec) : 50=0.01%, 100=99.35%, 250=0.41%, 500=0.24%
  cpu          : usr=24.76%, sys=74.76%, ctx=114, majf=0, minf=24
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=217666/w=217534/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=870664KB, aggrb=822156KB/s, minb=822156KB/s, maxb=822156KB/s, mint=1059msec, maxt=1059msec
  WRITE: io=870136KB, aggrb=821658KB/s, minb=821658KB/s, maxb=821658KB/s, mint=1059msec, maxt=1059msec

Disk stats (read/write):
  ram0: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00%
fio rand-rw-rd-raw.fio --output=/home/radical/src/play/ios-test/logs-with-drop-cache/ad6d29a/raw-rd-raw-ad6d29a.log --max-jobs=2 --latency-log --bandwidth-log
ad6d29a sent upstream
random_rw: (g=0): rw=randrw, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
fio-2.0.8-9-gfb9f0
Starting 1 process

random_rw: (groupid=0, jobs=1): err= 0: pid=2192: Thu Jul 26 17:53:52 2012
  read : io=869004KB, bw=708235KB/s, iops=177058 , runt=  1227msec
    slat (usec): min=1 , max=51 , avg= 1.61, stdev= 0.72
    clat (usec): min=17 , max=425 , avg=87.51, stdev=17.51
     lat (usec): min=19 , max=432 , avg=89.20, stdev=17.83
    clat percentiles (usec):
     |  1.00th=[   79],  5.00th=[   81], 10.00th=[   82], 20.00th=[   83],
     | 30.00th=[   84], 40.00th=[   85], 50.00th=[   86], 60.00th=[   86],
     | 70.00th=[   87], 80.00th=[   89], 90.00th=[   91], 95.00th=[   98],
     | 99.00th=[  111], 99.50th=[  118], 99.90th=[  374], 99.95th=[  390],
     | 99.99th=[  406]
    bw (KB/s)  : min=707912, max=711328, per=100.00%, avg=709620.00, stdev=2415.48
  write: io=871796KB, bw=710510KB/s, iops=177627 , runt=  1227msec
    slat (usec): min=2 , max=46 , avg= 2.33, stdev= 0.81
    clat (usec): min=14 , max=425 , avg=87.62, stdev=17.61
     lat (usec): min=16 , max=435 , avg=90.05, stdev=18.07
    clat percentiles (usec):
     |  1.00th=[   79],  5.00th=[   81], 10.00th=[   82], 20.00th=[   83],
     | 30.00th=[   84], 40.00th=[   85], 50.00th=[   86], 60.00th=[   87],
     | 70.00th=[   87], 80.00th=[   89], 90.00th=[   91], 95.00th=[   98],
     | 99.00th=[  111], 99.50th=[  118], 99.90th=[  378], 99.95th=[  390],
     | 99.99th=[  406]
    bw (KB/s)  : min=709360, max=717872, per=100.00%, avg=713616.00, stdev=6018.89
    lat (usec) : 20=0.01%, 50=0.01%, 100=95.59%, 250=4.04%, 500=0.36%
  cpu          : usr=31.57%, sys=67.94%, ctx=125, majf=0, minf=24
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=217251/w=217949/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=869004KB, aggrb=708234KB/s, minb=708234KB/s, maxb=708234KB/s, mint=1227msec, maxt=1227msec
  WRITE: io=871796KB, aggrb=710510KB/s, minb=710510KB/s, maxb=710510KB/s, mint=1227msec, maxt=1227msec

Disk stats (read/write):
  ram0: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00%
fio rand-rw-rd-raw.fio --output=/home/radical/src/play/ios-test/logs-with-drop-cache/918227b/raw-rd-raw-918227b.log --max-jobs=2 --latency-log --bandwidth-log
918227b Merge tag 'fbdev-fixes-for-3.5-2' of git://github.com/schandinat/linux-2.6