fio mmap writes much slower than default writes

DISCUSSION Richard Kennedy 2 participants 6 messages Jul 16, 2009 – Jul 18, 2009

Share & tools

Richard Kennedy

author

2009-07-16 13:40 UTC #0 lore raw

Running tests of fio write with sizes that are less than the write cache size I'm seeing a big slow down when using mmap. I'm running the tests on linux 2.6.31-rc* x86_64.

Typical results with default writes :-

fio size=300m rw=write
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec

with mmap :-

fio size=300m rw=write ioengine=mmap
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec

Is this expected or is it indicative of a problem somewhere?

regards
Richard

Jens Axboe

2009-07-18 06:18 UTC #1 lore raw

Quoted 9 lines · Richard Kennedy

Running tests of fio write with sizes that are less than the write cache size I'm seeing a big slow down when using mmap. I'm running the tests on linux 2.6.31-rc* x86_64.
Typical results with default writes :-
fio size=300m rw=write
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec

Quoted 7 lines

with mmap :-
fio size=300m rw=write ioengine=mmap
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec
Is this expected or is it indicative of a problem somewhere?

What does the full job file look like? Is the file cached, or are the faults reading in data?

Signature · 1 line

Jens Axboe

Richard Kennedy

author

2009-07-18 13:58 UTC #2 lore raw

Quoted 12 lines · Jens Axboe

Quoted 11 lines · Richard Kennedy
Running tests of fio write with sizes that are less than the write cache size I'm seeing a big slow down when using mmap. I'm running the tests on linux 2.6.31-rc* x86_64.
Typical results with default writes :-
fio size=300m rw=write
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec
with mmap :-

Quoted 9 lines

Quoted 5 lines
fio size=300m rw=write ioengine=mmap
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec
Is this expected or is it indicative of a problem somewhere?
What does the full job file look like? Is the file cached, or are the faults reading in data?

Hi Jens,
My machine has 3g of memory so it should all fit into cache. here is the full output from the tests.

I get the same sort of results from 200m,300m,400m. I run each test 5 times and get average speeds of approx 300m on default writes & only 60m on mmap. I use the same test harness for each test so they should be comparable, but I'll re-check them to make sure.

Would oprofile tell us anything interesting?

Is there anything else you'd like to know?

regards
Richard

mmap
----------
f1: (g=0): rw=write, bs=4K-4K/4K-4K, ioengine=mmap, iodepth=1
f1: (groupid=0, jobs=1): err= 0: pid=3404
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec

    clat (usec): min=0, max=0, avg= 0.00, stdev= 0.00
    bw (KiB/s) : min=    0, max=62200, per=95.02%, avg=52957.91, stdev=18235.16
  cpu          : usr=8.86%, sys=17.64%, ctx=1540, majf=1, minf=76828
  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/76800, short=0/0
     lat (usec): 10=67.71%, 20=29.46%, 50=1.01%, 100=0.02%, 250=0.04%
     lat (usec): 500=0.02%, 750=0.05%, 1000=0.06%
     lat (msec): 2=0.22%, 4=1.07%, 10=0.32%, 20=0.02%, 50=0.01%
     lat (msec): 100=0.01%

Run status group 0 (all jobs):
WRITE: io=300MiB, aggrb=55,735KiB/s, minb=55,735KiB/s, maxb=55,735KiB/s, mint=5512msec, maxt=5512msec

Disk stats (read/write):
dm-0: ios=3571/9894, merge=0/0, ticks=25884/31650, in_queue=511733, util=96.46%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%

    sda: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=nan%

----------
default writes
f1: (g=0): rw=write, bs=4K-4K/4K-4K, ioengine=sync, iodepth=1
f1: (groupid=0, jobs=1): err= 0: pid=5097
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec

    clat (usec): min=0, max=0, avg= 0.00, stdev= 0.00
    bw (KiB/s) : min=    0, max=359672, per=55.85%, avg=179836.00, stdev=254326.51
  cpu          : usr=9.54%, sys=88.89%, ctx=85, majf=0, minf=30
  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/76800, short=0/0
     lat (usec): 10=93.05%, 20=6.76%, 50=0.15%, 100=0.02%, 250=0.02%
     lat (usec): 500=0.01%, 750=0.01%
     lat (msec): 4=0.01%

Run status group 0 (all jobs):
WRITE: io=300MiB, aggrb=314MiB/s, minb=314MiB/s, maxb=314MiB/s, mint=955msec, maxt=955msec

Disk stats (read/write):
dm-0: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%

    sda: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=nan%

Jens Axboe

2009-07-18 14:20 UTC #3 lore raw

Quoted 17 lines · Richard Kennedy

Quoted 16 lines · Jens Axboe
Quoted 15 lines · Richard Kennedy
Running tests of fio write with sizes that are less than the write cache size I'm seeing a big slow down when using mmap. I'm running the tests on linux 2.6.31-rc* x86_64.
Typical results with default writes :-
fio size=300m rw=write
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec
with mmap :-
fio size=300m rw=write ioengine=mmap
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec

Quoted 8 lines

Quoted 5 lines
Quoted 1 line
Is this expected or is it indicative of a problem somewhere?
What does the full job file look like? Is the file cached, or are the faults reading in data?
Hi Jens,
My machine has 3g of memory so it should all fit into cache. here is the full output from the tests.

Fio will invalidate the file cache by default, so you probably want to use invalidate=0 or pre_read=1 to make sure the file(s) is/are cached. Does that change the picture?

Quoted 67 lines

I get the same sort of results from 200m,300m,400m. I run each test 5 times and get average speeds of approx 300m on default writes & only 60m on mmap. I use the same test harness for each test so they should be comparable, but I'll re-check them to make sure.
Would oprofile tell us anything interesting?
Is there anything else you'd like to know?
regards
Richard
mmap
----------
f1: (g=0): rw=write, bs=4K-4K/4K-4K, ioengine=mmap, iodepth=1
f1: (groupid=0, jobs=1): err= 0: pid=3404
write: io=300MiB, bw=55,732KiB/s, iops=13,933, runt= 5512msec
    clat (usec): min=0, max=0, avg= 0.00, stdev= 0.00
    bw (KiB/s) : min=    0, max=62200, per=95.02%, avg=52957.91, stdev=18235.16
  cpu          : usr=8.86%, sys=17.64%, ctx=1540, majf=1, minf=76828
  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/76800, short=0/0
     lat (usec): 10=67.71%, 20=29.46%, 50=1.01%, 100=0.02%, 250=0.04%
     lat (usec): 500=0.02%, 750=0.05%, 1000=0.06%
     lat (msec): 2=0.22%, 4=1.07%, 10=0.32%, 20=0.02%, 50=0.01%
     lat (msec): 100=0.01%
Run status group 0 (all jobs):
WRITE: io=300MiB, aggrb=55,735KiB/s, minb=55,735KiB/s, maxb=55,735KiB/s, mint=5512msec, maxt=5512msec
Disk stats (read/write):
dm-0: ios=3571/9894, merge=0/0, ticks=25884/31650, in_queue=511733, util=96.46%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%
    sda: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=nan%
----------
default writes
f1: (g=0): rw=write, bs=4K-4K/4K-4K, ioengine=sync, iodepth=1
f1: (groupid=0, jobs=1): err= 0: pid=5097
write: io=300MiB, bw=314MiB/s, iops=80,418, runt= 955msec
    clat (usec): min=0, max=0, avg= 0.00, stdev= 0.00
    bw (KiB/s) : min=    0, max=359672, per=55.85%, avg=179836.00, stdev=254326.51
  cpu          : usr=9.54%, sys=88.89%, ctx=85, majf=0, minf=30
  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/76800, short=0/0
     lat (usec): 10=93.05%, 20=6.76%, 50=0.15%, 100=0.02%, 250=0.02%
     lat (usec): 500=0.01%, 750=0.01%
     lat (msec): 4=0.01%
Run status group 0 (all jobs):
WRITE: io=300MiB, aggrb=314MiB/s, minb=314MiB/s, maxb=314MiB/s, mint=955msec, maxt=955msec
Disk stats (read/write):
dm-0: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%
    sda: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=nan%
--
To unsubscribe from this list: send the line "unsubscribe fio" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Signature · 1 line

Jens Axboe

Jens Axboe

2009-07-18 14:39 UTC #4 lore raw

In reply to Richard Kennedy

Quoted 2 lines · Richard Kennedy

Disk stats (read/write):
dm-0: ios=3571/9894, merge=0/0, ticks=25884/31650, in_queue=511733, util=96.46%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%

If you look at the disk stats, it also shows a considerable amount of reads. So I'm guessing that you need pre_read=1 to get the same sort of results.

Signature · 1 line

Jens Axboe

Richard Kennedy

author

2009-07-18 14:50 UTC #5 lore raw

Quoted 8 lines · Jens Axboe

Quoted 2 lines · Richard Kennedy
Disk stats (read/write):
dm-0: ios=3571/9894, merge=0/0, ticks=25884/31650, in_queue=511733, util=96.46%, aggrios=0/0, aggrmerge=0/0, aggrticks=0/0, aggrin_queue=0, aggrutil=0.00%
If you look at the disk stats, it also shows a considerable amount of reads. So I'm guessing that you need pre_read=1 to get the same sort of results.

thanks for that. Yes, pre_read is much better.

fio --name=f1 --rw=write --size=300m --pre_read=1
write: io=300MiB, bw=274MiB/s, iops=70,265, runt= 1093msec

fio --name=f1 --rw=write --size=300m --pre_read=1 --ioengine=mmap
write: io=300MiB, bw=391MiB/s, iops=100K, runt= 767msec

fio --name=f1 --rw=write --size=300m --ioengine=mmap
write: io=300MiB, bw=30,837KiB/s, iops=7,709, runt= 9962msec

regards
Richard