Read efficiency?

N

Notmy Realname

I'm wondering if anyone knows much about Ruby's efficiency with IO#read.
Specifically, I'm wondering about libraries I might use to speed up disk
reads.

To see what I mean, here's some test code that iterates over an
11-megabyte file. All it does is call IO#read on a number of bytes (set
on the command-line) over the entire file, and times it.

#!/usr/bin/env ruby
# readspeed.rb

buf_size = ARGV[0].to_i
fd = File.open("some.txt")

start = Time.now
while (fd.read(buf_size))
end
stop = Time.now

puts (stop - start).to_s + " seconds"

#--- EOF

Running this on my system yields:

$ ruby readspeed.rb 4096
0.014 seconds

$ ruby readspeed.rb 1
7.547 seconds


Obviously a big difference! This is a simplified version of the test I
was actually running, which tried to account for the increased amount of
overhead when calling with 1 byte at a time. There's still an
order-of-magnitude difference between the two...reading one byte at a
time is *slow*, slow enough to bog down an entire program.

I know this is supposed to be the case with unbuffered input, such as
the C standard library "read", but isn't IO#read supposed to be
buffered? What's causing this slowdown? I'm writing a class that will
hopefully speed up smaller reads from binary files by explicitly caching
data in memory, but I'm wondering if there are any pre-built (i.e.,
tested) solutions that Ruby programmers might be using.
 
N

Notmy Realname

I hate it when I put my foot in my mouth. After further testing, I'm
almost entirely sure this is just due to overhead, not a problem with
disk access.

Who would have thought looping 11*2**20 times would incur a performance
hit?
 
R

Robert Klemme

I hate it when I put my foot in my mouth. After further testing, I'm
almost entirely sure this is just due to overhead, not a problem with
disk access.

Good that you did not use your real name. ;-)
Who would have thought looping 11*2**20 times would incur a performance
hit?

The overhead of a simple method call is significant already:

robert@fussel:~$ ruby19 -r benchmark <<XXX
def f;end # function without effect
R1=11*1024*1024
R2=R1/4096
Benchmark.bmbm 20 do |r|
r.report("rare") { R2.times { f } }
r.report("often") { R1.times { f } }
end
XXX

Rehearsal -------------------------------------------------------
rare 0.000000 0.000000 0.000000 ( 0.000643)
often 2.620000 0.000000 2.620000 ( 2.663366)
---------------------------------------------- total: 2.620000sec

user system total real
rare 0.000000 0.000000 0.000000 ( 0.000643)
often 2.620000 0.000000 2.620000 ( 2.665057)
robert@fussel:~$

Kind regards

robert
 
N

Notmy Realname

Robert said:
Good that you did not use your real name. ;-)


The overhead of a simple method call is significant already:

robert@fussel:~$ ruby19 -r benchmark <<XXX
def f;end # function without effect
R1=11*1024*1024
R2=R1/4096
Benchmark.bmbm 20 do |r|
r.report("rare") { R2.times { f } }
r.report("often") { R1.times { f } }
end
XXX

Rehearsal -------------------------------------------------------
rare 0.000000 0.000000 0.000000 ( 0.000643)
often 2.620000 0.000000 2.620000 ( 2.663366)
---------------------------------------------- total: 2.620000sec

user system total real
rare 0.000000 0.000000 0.000000 ( 0.000643)
often 2.620000 0.000000 2.620000 ( 2.665057)
robert@fussel:~$

Kind regards

robert

I know, right? I'm embarrassed I use this username elsewhere. And I
spent like an hour trying to figure this out.

In my defense, I did do more or less exactly what you did and found the
function call overhead to be significant, but not enough to account for
the difference. Then I remembered that Ruby isn't just doing a disk
read---it's also doing stuff like packaging the bytes it reads into a
string. Once I accounted for *that*, the difference magically
disappeared. Note to self: Ruby is not C.
 
R

Robert Klemme

I know, right? I'm embarrassed I use this username elsewhere. And I
spent like an hour trying to figure this out.

In my defense, I did do more or less exactly what you did and found the
function call overhead to be significant, but not enough to account for
the difference. Then I remembered that Ruby isn't just doing a disk
read---it's also doing stuff like packaging the bytes it reads into a
string. Once I accounted for *that*, the difference magically
disappeared. Note to self: Ruby is not C.

Just an additional hint: you can dramatically reduce the String creation
overhead by using the second argument to IO#write:

robert@fussel:~$ dd bs=1024 count=10240 if=/dev/zero of=x
10240+0 records in
10240+0 records out
10485760 bytes (10 MB) copied, 0.135645 s, 77.3 MB/s
robert@fussel:~$ ruby19 bm
Rehearsal -------------------------------------------------------
simple 0.210000 0.240000 0.450000 ( 0.450689)
smart 0.100000 0.160000 0.260000 ( 0.262826)
---------------------------------------------- total: 0.710000sec

user system total real
simple 0.210000 0.240000 0.450000 ( 0.463716)
smart 0.130000 0.130000 0.260000 ( 0.260381)
robert@fussel:~$ cat bm
require 'benchmark'
REP = 10
BS = 1024
Benchmark.bmbm 20 do |r|
r.report 'simple' do
REP.times do
File.open "x", "rb" do |io|
while b = io.read(BS)
end
end
end
end
r.report 'smart' do
REP.times do
File.open "x", "rb" do |io|
b = ""
while io.read(BS, b)
end
end
end
end
end
robert@fussel:~$

Note: Ruby is not C but sometimes there is room for improvement. :)

Kind regards

robert
 
R

Robert Klemme

2010/2/21 Robert Klemme said:
Note: Ruby is not C but sometimes there is room for improvement. :)

09:40:20 Temp$ ./bmx.rb
Rehearsal -----------------------------------------------------------------
f-100.bin simple 0.000000 0.000000 0.000000 ( 0.004000)
f-100.bin smart 0.016000 0.000000 0.016000 ( 0.005000)
f-100.bin complete 0.000000 0.000000 0.000000 ( 0.008000)
f-1048576.bin simple 0.094000 0.046000 0.140000 ( 0.133000)
f-1048576.bin smart 0.078000 0.016000 0.094000 ( 0.100000)
f-1048576.bin complete 0.015000 0.031000 0.046000 ( 0.054000)
f-104857600.bin simple 9.031000 3.875000 12.906000 ( 12.913000)
f-104857600.bin smart 5.766000 4.047000 9.813000 ( 9.820000)
f-104857600.bin complete 0.609000 3.156000 3.765000 ( 3.807000)
------------------------------------------------------- total: 26.780000sec

user system total real
f-100.bin simple 0.016000 0.000000 0.016000 ( 0.007000)
f-100.bin smart 0.000000 0.000000 0.000000 ( 0.008000)
f-100.bin complete 0.000000 0.000000 0.000000 ( 0.007000)
f-1048576.bin simple 0.093000 0.109000 0.202000 ( 0.207000)
f-1048576.bin smart 0.078000 0.016000 0.094000 ( 0.103000)
f-1048576.bin complete 0.000000 0.046000 0.046000 ( 0.037000)
f-104857600.bin simple 8.594000 4.125000 12.719000 ( 12.760000)
f-104857600.bin smart 6.219000 3.500000 9.719000 ( 9.721000)
f-104857600.bin complete 0.593000 3.125000 3.718000 ( 3.778000)
09:42:46 Temp$

Code is here http://gist.github.com/310932#file_bmx.rb

Cheers

robert
 
R

Roger Pack

I hate it when I put my foot in my mouth. After further testing, I'm
almost entirely sure this is just due to overhead, not a problem with
disk access.

Who would have thought looping 11*2**20 times would incur a performance
hit?

I believe that Rubinius has less overhead "hit time" -- as long as you
define everything as methods so it can JIT them.
GL!
-rp
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Members online

Forum statistics

Threads
473,769
Messages
2,569,582
Members
45,057
Latest member
KetoBeezACVGummies

Latest Threads

Top