Log for bps=((10 * 1024 * 1024)). test: (g=0): rw=write, bs=512-512/512-512, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [100.0% done] [0K/58K /s] [0/114 iops] [eta 00m:00s] test: (groupid=0, jobs=1): err= 0: pid=2657 write: io=51,200KB, bw=58,527B/s, iops=114, runt=895793msec slat (usec): min=26, max=376K, avg=81.69, stdev=2104.09 clat (usec): min=859, max=757K, avg=8648.07, stdev=8278.64 lat (usec): min=921, max=1,133K, avg=8730.49, stdev=9239.57 bw (KB/s) : min= 0, max= 60, per=101.03%, avg=57.59, stdev= 7.41 cpu : usr=0.05%, sys=0.75%, ctx=102611, majf=0, minf=51 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 r/w: total=0/102400, short=0/0 lat (usec): 1000=0.01% lat (msec): 2=0.01%, 4=0.02%, 10=98.99%, 20=0.24%, 50=0.66% lat (msec): 100=0.03%, 250=0.01%, 500=0.05%, 1000=0.01%
Run status group 0 (all jobs): WRITE: io=51,200KB, aggrb=57KB/s, minb=58KB/s, maxb=58KB/s, mint=895793msec, maxt=895793msec Disk stats (read/write): dm-0: ios=28/103311, merge=0/0, ticks=1318/950537, in_queue=951852, util=99.63%, aggrios=28/102932, aggrmerge=0/379, aggrticks=1316/929743, aggrin_queue=930987, aggrutil=99.60% vda: ios=28/102932, merge=0/379, ticks=1316/929743, in_queue=930987, util=99.60% test: (g=0): rw=write, bs=8K-8K/8K-8K, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [100.0% done] [0K/892K /s] [0/108 iops] [eta 00m:00s] test: (groupid=0, jobs=1): err= 0: pid=2782 write: io=51,200KB, bw=926KB/s, iops=115, runt= 55269msec slat (usec): min=20, max=32,160, avg=66.43, stdev=935.62 clat (msec): min=1, max=157, avg= 8.53, stdev= 2.55 lat (msec): min=1, max=158, avg= 8.60, stdev= 2.93 bw (KB/s) : min= 539, max= 968, per=100.12%, avg=927.09, stdev=63.89 cpu : usr=0.10%, sys=0.47%, ctx=6415, majf=0, minf=26 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 r/w: total=0/6400, short=0/0 lat (msec): 2=0.06%, 4=0.05%, 10=99.19%, 20=0.06%, 50=0.62% lat (msec): 250=0.02% Run status group 0 (all jobs): WRITE: io=51,200KB, aggrb=926KB/s, minb=948KB/s, maxb=948KB/s, mint=55269msec, maxt=55269msec Disk stats (read/write): dm-0: ios=3/6546, merge=0/0, ticks=117/65262, in_queue=65387, util=99.58%, aggrios=3/6472, aggrmerge=0/79, aggrticks=117/62063, aggrin_queue=62178, aggrutil=99.54% vda: ios=3/6472, merge=0/79, ticks=117/62063, in_queue=62178, util=99.54% test: (g=0): rw=write, bs=64K-64K/64K-64K, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [100.0% done] [0K/7,332K /s] [0/111 iops] [eta 00m:00s] test: (g=0): rw=write, bs=64K-64K/64K-64K, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [100.0% done] [0K/7,332K /s] [0/111 iops] [eta 00m:00s] test: (groupid=0, jobs=1): err= 0: pid=2793 write: io=51,200KB, bw=7,074KB/s, iops=110, runt= 7238msec slat (usec): min=23, max=37,715, avg=82.08, stdev=1332.25 clat (msec): min=2, max=34, avg= 8.96, stdev= 1.54 lat (msec): min=2, max=58, avg= 9.04, stdev= 2.31 bw (KB/s) : min= 6361, max= 7281, per=100.13%, avg=7082.07, stdev=274.31 cpu : usr=0.08%, sys=0.53%, ctx=801, majf=0, minf=23 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 r/w: total=0/800, short=0/0 lat (msec): 4=0.25%, 10=92.12%, 20=7.25%, 50=0.38% Run status group 0 (all jobs): WRITE: io=51,200KB, aggrb=7,073KB/s, minb=7,243KB/s, maxb=7,243KB/s, mint=7238msec, maxt=7238msec Disk stats (read/write): dm-0: ios=0/811, merge=0/0, ticks=0/8003, in_queue=8003, util=98.35%, aggrios=0/804, aggrmerge=0/17, aggrticks=0/7319, aggrin_queue=7319, aggrutil=98.19% vda: ios=0/804, merge=0/17, ticks=0/7319, in_queue=7319, util=98.19% test: (g=0): rw=write, bs=128K-128K/128K-128K, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [83.3% done] [0K/10M /s] [0/81 iops] [eta 00m:01s] test: (groupid=0, jobs=1): err= 0: pid=2800 write: io=51,200KB, bw=10,113KB/s, iops=79, runt= 5063msec slat (usec): min=36, max=35,279, avg=130.55, stdev=1761.93 clat (msec): min=3, max=134, avg=12.52, stdev=16.93 lat (msec): min=3, max=134, avg=12.65, stdev=17.14 bw (KB/s) : min= 7888, max=13128, per=100.41%, avg=10153.00, stdev=1607.48 cpu : usr=0.00%, sys=0.51%, ctx=401, majf=0, minf=23 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 r/w: total=0/400, short=0/0 lat (msec): 4=0.50%, 10=81.25%, 20=14.75%, 50=0.75%, 250=2.75% Run status group 0 (all jobs): WRITE: io=51,200KB, aggrb=10,112KB/s, minb=10,355KB/s, maxb=10,355KB/s, mint=5063msec, maxt=5063msec Disk stats (read/write): dm-0: ios=0/403, merge=0/0, ticks=0/6216, in_queue=6225, util=97.83%, aggrios=0/404, aggrmerge=0/17, aggrticks=0/5228, aggrin_queue=5228, aggrutil=97.62% vda: ios=0/404, merge=0/17, ticks=0/5228, in_queue=5228, util=97.62% test: (g=0): rw=write, bs=256K-256K/256K-256K, ioengine=libaio, iodepth=1 Starting 1 process Jobs: 1 (f=1): [W] [100.0% done] [0K/9,165K /s] [0/34 iops] [eta 00m:00s] test: (groupid=0, jobs=1): err= 0: pid=2807 write: io=51,200KB, bw=8,883KB/s, iops=34, runt= 5764msec slat (usec): min=37, max=36,481, avg=240.22, stdev=2575.78 clat (msec): min=4, max=164, avg=28.57, stdev=39.97 lat (msec): min=4, max=164, avg=28.81, stdev=40.03 bw (KB/s) : min= 7613, max= 9678, per=98.98%, avg=8791.27, stdev=569.82 cpu : usr=0.10%, sys=0.17%, ctx=201, majf=0, minf=23 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 r/w: total=0/200, short=0/0 lat (msec): 10=14.50%, 20=68.00%, 50=1.00%, 250=16.50% Run status group 0 (all jobs): WRITE: io=51,200KB, aggrb=8,882KB/s, minb=9,095KB/s, maxb=9,095KB/s, mint=5764msec, maxt=5764msec Disk stats (read/write): dm-0: ios=0/216, merge=0/0, ticks=0/6446, in_queue=6484, util=98.10%, aggrios=0/204, aggrmerge=0/16, aggrticks=0/5861, aggrin_queue=5861, aggrutil=97.92% vda: ios=0/204, merge=0/16, ticks=0/5861, in_queue=5861, util=97.92% On Tue, Sep 13, 2011 at 6:14 PM, Stefan Hajnoczi <stefa...@gmail.com> wrote: > On Tue, Sep 13, 2011 at 10:25 AM, Zhi Yong Wu <zwu.ker...@gmail.com> wrote: >> On Tue, Sep 13, 2011 at 3:14 PM, Stefan Hajnoczi >> <stefa...@linux.vnet.ibm.com> wrote: >>> On Tue, Sep 13, 2011 at 10:52:44AM +0800, Zhi Yong Wu wrote: >>>> This is real log when fio issued with bs=128K and bps=1000000(block >>>> I/O throttling): >>> >>> I would use 1024 * 1024 instead of 1000000 as the throughput limit. >>> 10^5 is not a multiple of 512 bytes and is not a nice value in KB/s >>> (976.5625). >> OK. next time, i will adopt this. >>> >>>> >>>> 8,2 0 1 0.000000000 24332 A WS 79958528 + 256 <- >>>> (253,2) 71830016 >>> >>> 256 blocks = 256 * 512 bytes = 128 KB per request. We know the maximum >>> request size from Linux is 128 KB so this makes sense. >>> >>>> Throughput (R/W): 0KiB/s / 482KiB/s >>> >>> What throughput do you get without I/O throttling? Either I/O >>> throttling is limiting too aggressively here or the physical disk is the >>> bottleneck (I double that since the write throughput value is very low). >>> We need to compare against the throughput when throttling is not >>> enabled. >> Without block I/O throttling. > [...] >> test: (g=0): rw=write, bs=128K-128K/128K-128K, ioengine=libaio, iodepth=1 >> Starting 1 process >> Jobs: 1 (f=1): [W] [100.0% done] [0K/13M /s] [0/103 iops] [eta 00m:00s] >> test: (groupid=0, jobs=1): err= 0: pid=2734 >> write: io=51,200KB, bw=12,933KB/s, iops=101, runt= 3959msec > > This shows that the physical disk is capable of far exceeding 1 MB/s > when I/O is not limited. So the earlier result where the guest only > gets 482 KiB/s under 1000000 bps limit shows that I/O limits are being > too aggressive. For some reason the algorithm is causing the guest to > get lower throughput than expected. > > It would be interesting to try with bps=$((10 * 1024 * 1024)). I > wonder if the algorithm has a constant overhead of a couple hundred > KB/s or if it changes with the much larger bps value. > > Stefan > -- Regards, Zhi Yong Wu