Performance-debugging your scripts
Friday, 29. February 2008, 10:26:14
I just started playing around with Ruby, and it is an awesome language. It does have its cons, as do all tools, but the ease of scripting is very... I don't know, relaxing :-). My point being that Ruby is easy to learn. I've only used Ruby for what is approximately a full work day, but I'm already in love ![]()
Ruby offers you close to the power of a real language, but the ease of a scripting language. You get full access to the platform, like calling COM objects in IE or Office - so you should be able to read Excel sheets if you are running Windows and have Office installed.
So, getting to the point of this blog post. The assumption is that you have written a lot of methods, your own little library. Developers are running uphill to meet the requirements of management and there is no time to look at efficiency. At the end of the development cycle, developers are noticing the application is running slower than users would expect, so it is time to look at efficiency.
Let us assume you only have two functions, count(number) and subtract(number). The functions will count from 0 to 'number' and from 'number' to 0 respectively. Yay, how very useful...
def count number
number.times do
number += 1
end
end
def subtract number
number.times do
number -= 1
end
end
Ruby supports aliasing methods. This is the same as copying a method. In Javascript, you would do
somefunction = someotherfunction;. This method of performance testing can be done in any language that supports modifying or copying a method to another name. Let's alias our methods now, and add a global variable we'll keep some records in.
alias countOriginal count
alias subtractOriginal subtract
$gRec = [] # store the function running time in here
All the previous running code will still call count and subtract, so there is no difference to the apparent program flow. But now we can redefine how count and subtract work!
def count number
start = Time.now # store the start time
countOriginal number # call the original function
stop = Time.now # store the end time
# We should have very little overhead timing
# above and after the original function
$gRec.push ['count '+number.to_s, stop-start] # store time as seconds
end
# Do the same here
def subtract number
start = Time.now
subtractOriginal number
stop = Time.now
$gRec.push ['subtract '+number.to_s, stop-start]
end
Add this in a debug file and the methods you have redefined will now register the time they took in a global variable. I am not sure how Ruby handles array sizing though, so remember that resizing arrays can lead to some relative heavy overhead.
If your code is just slighly complex the timing will probably be wrong unless you specify an array of a certain size at the start. It is enough that foo() is calling bar(), and both functions are redefined. If the array must be resized when boo() is running, it will look like foo() took longer time to complete that it actually would have. This will give you statistical errors.
# Run the code and print out the timer results at the end
count(10000)
count(100000)
count(1000000)
subtract(10000)
subtract(100000)
subtract(1000000)
puts $gRec.inspect
This gives you the following output: [["count 10000", 0.0], ["count 100000", 0.047], ["count 1000000", 0.484], ["subtract 10000", 0.016], ["subtract 100000", 0.031], ["subtract 1000000", 0.469]]












