How use Profiling, a Quick Guide

Ruby
21

Victor S. wrote:

From: Dave B.
Sent: Friday, May 26, 2006 9:45 AM

Can you call it “profiling” rather than “profile”?

Thanks. And again, sorry for my English.

No problem with your English, profile is fine as a verb. It’s just
mildly confusing because profile is often used in computing as a noun,
so if you see “profile”, you assume it’s talking about a profile
rather than to profile.

Cheers,
Dave

22

2006/5/25, Victor S. [email protected]:

Note that a similar thing can be achieved with set_trace_func

Drawbacks of set_trace_func was discussed in the original topic here:
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/ruby-talk/192294

Yes, but the other solution is more intrusive and will break if the
method is redefined. If the sole purpose is counting of invocations
than I’d personally prefer the approach with set_trace_func. Just my
0.02EUR…

Kind regards

robert

23

“Boy!” I thought. “Now THIS sounds like a thread I want to read!”

The aforementioned “I” in this case being a hobbyist programmer
using/learning Ruby 1.8.4 on OSX 10.3 (w/Developer Tools installed, of
course)…

On May 23, 2006, at 15:10, John C. wrote:

  • Always benchmark first, profile and optimize later. Otherwise you
    don’t
    know whether it was worth it. (Hint: Often the tweaks aren’t worth
    it, or
    make things worse)

OK, that makes sense. Not that I have any idea how to benchmark my
programs, but I’ll keep reading…

  • Look at the top most items in the profile list. Usually they are
    standard library functions. Silly things like [] or +…
    Ask your self, "What could be calling these thing so often?
    Can I make it do it less often? eg. Cache the result etc.)

Er, the profile list? Push “Where do I find/how do I generate a
‘profile list’?” onto the question_stack

  • Scan down the list for the first few user written methods. Usually
    the one
    that you spent the most time in has the most fat to trim.

I understand that. Yay!
comprehension_counter = 1

  • Scan the list for the routine that took the longest (as opposed
    to the most time spent in it.) Try get that one to just do less.

I don’t understand this. Took the longest != most time spent in it? But
what if it does the most work? If I make it do less, don’t I have to
make something else do more?
question_stack << “huh? [Parse Error]”

  • Use strace, see what the system is doing at an OS level. I once
    improved another persons program (professional in production) by a
    factor of 40, yes FORTY times, by noting it was doing an lseek on
    every
    record read and changing that to an mmap.

question_stack << “[Error: File ‘strace’ Not Found]”

  • Always look out for surprises. The best moment in an optimizers
    life is
    when you look at something and say “WTF! Why is that routine
    taking so
    long!?”

class Fixnum
def increment
self = self + 1
end
end

comprehension_counter.increment

  • Large number of calls to .size and .length and .count_objects
    methods are a
    clue some nidjit somewhere is doing something really N^2 stupid
    like…
    for( i=0; i < container.count_objects(); i++) {
    }

question_stack << “What exactly is stupid about that? And what’s the
smart alternative? [Error: Unknown Language] [Error: C Allergy
Triggered] [Trap: C Antihistamine Enabled]”

  • Use top, vmstat, times as well.
    Large usertime means optimize program.
    Large system time means you really hammering the system calls (that
    was a clue in the lseek case I mentioned above)
    Large real time small user and system means you are waiting for
    input from user / disk / network /…? Find out what.
    Watch the page in page out stats. Watch the swap in swap out stats.
    If you are paging or swapping, time to switch to memory consumption
    optimization!

question_stack << “My ‘top’ doesn’t have ‘usertime’, ‘system time’ or
‘realtime’ values. Is this only for special kinds of top? [Error:
Potential OS-specific or otherwise specialized tools]”

question_stack << “[Error: File ‘vmstat’ Not Found]”

question_stack << “[Error: File ‘times’ Not Found]”

question_stack << “I found them, but if I use them, what are they going
to tell me, and what kind of actions would I want to take in response?
[Error: Documentation Not Found]”

Fatal Error: Question Stack Overflow

Fatal Error: Clue Underrun. Initial Clue supply inadequate. Increase
Clues and re-run.

Fatal Error: Nuby Page Fault Fatal Error: Nuby Chapter Fault Fatal
Error: Nuby Volume Fault Fatal Error: San Andreas Fault Fatal Error:
Nobody’s Fault. Please contact your system administrator to resolve the
problem. If you are the System A., I guess you’re screwed.
Ha. Ha.

24

From: Dave H. [mailto:[email protected]]
Sent: Thursday, June 01, 2006 10:35 PM

To: ruby-talk ML
Subject: Re: How use Profiling, a Quick Guide.

Fatal Error: Nuby Page Fault Fatal Error: Nuby Chapter Fault Fatal
Error: Nuby Volume Fault Fatal Error: San Andreas Fault Fatal Error:
Nobody’s Fault. Please contact your system administrator to resolve the
problem. If you are the System A., I guess you’re screwed.
Ha. Ha.

Most of your questions would go away after reading that:
http://ruby-doc.org/stdlib/libdoc/benchmark/rdoc/index.html
http://ruby-doc.org/docs/ProgrammingRuby/html/trouble.html#UC

V.

25

On Jun 1, 2006, at 13:17, Sam R. wrote:

Er, the profile list? Push “Where do I find/how do I generate a
‘profile list’?” onto the question_stack

‘profile’, in the std lib

Alas, you have still underestimated how clueless I am. ‘the std lib’?
Is that a Ruby standard library? A Unix standard library? And if I find
this library, what do I do with it? How would I invoke profile-omancy?

question_stack << “[Error: File ‘strace’ Not Found]”

ktrace on BSD systems

Oo! My command line liked that much better. The man page even has
examples. Whether or not I can figure out what it’s telling me, and if
so, what I’m supposed to do about it, remains to be seen, but it’s
certainly a start.

for( i=0; i < max; i++) {
}

container.each…

OK, so “container.each” is presumably the smart alternative, and what
I’d instinctively use anyway, but I don’t understand what it is about
“for( i=0; i < max; i++)” that makes it “really n^2 stupid.” (If n, or
N, = 1, then that wouldn’t be all that stupid, but the use of the term
“nidjit” leads me to guess n is likely to be at least the age of said
nidjit, or some other suitably > 1 value. :slight_smile:

26

On Fri, Jun 02, 2006 at 04:35:28AM +0900, Dave H. wrote:

  • Look at the top most items in the profile list. Usually they are
    standard library functions. Silly things like [] or +…
    Ask your self, "What could be calling these thing so often?
    Can I make it do it less often? eg. Cache the result etc.)

Er, the profile list? Push “Where do I find/how do I generate a
‘profile list’?” onto the question_stack

‘profile’, in the std lib

question_stack << “[Error: File ‘strace’ Not Found]”

ktrace on BSD systems

  • Large number of calls to .size and .length and .count_objects
    methods are a
    clue some nidjit somewhere is doing something really N^2 stupid
    like…
    for( i=0; i < container.count_objects(); i++) {
    }

question_stack << "What exactly is stupid about that? And what’s the
smart alternative?
max=container.count_objects()
for( i=0; i < max; i++) {
}

container.each…

Sam

27

From: Dave H. [mailto:[email protected]]
Sent: Thursday, June 01, 2006 11:36 PM

for( i=0; i < max; i++) {
}

container.each…

OK, so “container.each” is presumably the smart alternative, and what
I’d instinctively use anyway, but I don’t understand what it is about
“for( i=0; i < max; i++)” that makes it “really n^2 stupid.”

The point was: if you use some value repeatedly, it is generally smarter
to
pre-calculate it.

Example:

def get_some_value
#some long calculation
end

(1…100).each{|i| puts i * get_some_value}

The above code would call get_some_value 100 times. If it rans slowly
and
would return 100 same values, the much more smarter way would be

v = get_some_value
(1…100).each{|i| puts i * v}

V.

28

On Jun 1, 2006, at 13:47, Victor S. wrote:

smart alternative?
The point was: if you use some value repeatedly, it is generally
smarter to
pre-calculate it.

{brief scratching of head}

Oh! So BOTH of Sam’s examples were ‘non-stupid’ rewrites of the initial
code. I completely failed to recognize the ‘for’ loop as being Ruby
code in the first place. Does Ruby really have an ++ operator? I missed
that somehow. Damn. As embarrassingly illustrated by the fact that I
coded my own “.increment” operator in the initial message instead of
using it.

my_clues++

29

On Jun 1, 2006, at 14:07, Logan C. wrote:

On Jun 1, 2006, at 4:55 PM, Dave H. wrote:

Ruby does not have an increment operator (++). It does have #succ but
that is not in place.

Aha. So it wasn’t Ruby code, and my initial confusion was justified.
Well, at least I understand it now. :slight_smile:

as far as your increment goes:
[snip]
-:13: Can’t change the value of self
self = self + 1
^

Dang.

[thinks]

Nope. Can’t figure this one out. Time to start a new thread.

30

From: Dave H. [mailto:[email protected]]
Sent: Thursday, June 01, 2006 11:55 PM

code. I completely failed to recognize the ‘for’ loop as being Ruby
code in the first place.
No, it was something C-like.

Does Ruby really have an ++ operator?
Nope. You can use +=1 instead.

V.

31

On Jun 1, 2006, at 13:35, Dave H. wrote:

Alas, you have still underestimated how clueless I am. ‘the std lib’?
Is that a Ruby standard library? A Unix standard library? And if I
find this library, what do I do with it? How would I invoke
profile-omancy?

In case anybody else was wondering the same thing, the answer can be
found, among other places, in “Programming Ruby” aka the Pickaxe
manual, and starts with putting

require 'profile'

in your Ruby code. I’ll just go write a quick script to print “RTFM”
1000 times now…

32

On Jun 1, 2006, at 4:55 PM, Dave H. wrote:

Oh! So BOTH of Sam’s examples were ‘non-stupid’ rewrites of the
initial code. I completely failed to recognize the ‘for’ loop as
being Ruby code in the first place. Does Ruby really have an ++
operator? I missed that somehow. Damn. As embarrassingly
illustrated by the fact that I coded my own “.increment” operator
in the initial message instead of using it.

Ruby does not have an increment operator (++). It does have #succ but
that is not in place.

as far as your increment goes:

% cat increment.rb
class Fixnum
def increment
self = self + 1
end
end

a = 1
a.increment

% ruby increment.rb
-:13: Can’t change the value of self
self = self + 1
^

33

On Jun 1, 2006, at 13:25, Victor S. wrote:

Most of your questions would go away after reading that:
http://ruby-doc.org/stdlib/libdoc/benchmark/rdoc/index.html

Hmm. OK, that explains how to benchmark, and I think explains what the
“std lib” is…

vmstat - Wikipedia

Hmm again. The example shows a “CPU” column with subcolumns of “cs”
“us” “sy” “id” and “wa”, which I might guess include “us” for user and
“sy” for system. It doesn’t say, and apparently my Unix doesn’t have
it.

Still, that makes the real question “How come I don’t have vmstat?”
and that’s a question for some other forum.

Programming Ruby: The Pragmatic Programmer's Guide

Well, now, that’s just embarrassing. RTFM, indeed.
Pop “Where do I find/how do I generate a ‘profile list’?” off
question_stack

Thank you very much, Victor.