[Tutor] total newbie [profiling example]

[Danny Yoo]

On Wed, 11 May 2005, Michael Cole wrote:

> What I noticed while testing the program is that the ball moves fairly
> slowly, I tried incrementing the ball's speed (dx and dy) but it still
> seemed to move pretty slow no matter how much I increased its speed. I
> went ahead and played out the game, destroying bricks (sprites, 128 of
> them). As the number of remaining bricks decreased the ball's speed
> increased, dramatically.

Hi Michael,

It's hard to say what's going on without reading code and running
profiling tests.  Do you mind posting the URL up somewhere?  One of us can
then review the code and see if we can help you pinpoint the performance
issue.


> dealing with such a small number of objects? or is this something
> particular about pygame's handling of sprites? and, if this is something
> intrinsic to python, can anything be done to speed it up? I realize
> python is an intrepeted language but this seems almost useless for any
> decent number of objects....

It may or may not have anything to do with Python itself: it's possible
that there is a time sink somewhere that can be easily fixed, or perhaps
there's something fundamentally wrong.  But I really don't like to guess.
*grin*


Let us take a look at the code; we'll be in a better position to do some
analysis if we have something we can measure.  One of us will probably run
the program through a "profiler":

    http://docs.python.org/lib/profile.html

to identify the "hot" spots in the program, and then we can work from
there.  It looks like there are things in the pygame code repository that
may also be relevant to profiling:

    http://www.pygame.org/pcr/profiler/



As an example of what we might do, say that someone comes up with the
following program:

######
## Adds two numbers together

def add(x, y):
    while x != 0:
        x = x - 1
        y = y + 1
    return y
######

Ok, ok, this is a totally unrealistic example, but bear with me.  *grin*

It's obvious to us that there's a severe performance issue with the
function above, but pretend for a moment that we had no clue that add()
was written in such a silly way, and imagine that we were using this in
the middle of a larger program, and wouldn't know what was going on.
Let's make the artificial problem a little less artificial:

######
def add(x, y):
    while x != 0:
        x = x - 1
        y = y + 1
    return y

def f():
    return add(10**7, 10**7)

def g():
    print f(), f()

if __name__ == '__main__':
    main()
######

Something like that.  It's still artificial, but oh well.  So we have a
few functions that call each other, and let's pretend that it's not
immmediately obvious that add() is broken.  *grin*


If someone comes to us and says "This program goes slow, and I don't know
why", then what can we do?  We can run a "profiler", which will give us a
good chance at figuring out what's wrong:

######
>>> import profile
>>> profile.run('g()')
20000000 20000000
         7 function calls in 9.480 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    9.430    4.715    9.430    4.715 <stdin>:1(add)
        2    0.000    0.000    9.430    4.715 <stdin>:1(f)
        1    0.000    0.000    9.430    9.430 <stdin>:1(g)
        1    0.000    0.000    9.430    9.430 <string>:1(?)
        1    0.050    0.050    9.480    9.480 profile:0(g())
        0    0.000             0.000          profile:0(profiler)
######


Ok, so there's a big "blip" in the total time "tottime" that add() uses:
out of the 9.480 CPU seconds that the whole program takes up, 9.43 of
those seconds is in add()!


So we are now more sure that add() implementation is evil.  And if we
switch it to something realistic:

######
>>> def add(x, y):
...     return x + y
...
>>> profile.run('g()')
20000000 20000000
         7 function calls in 0.010 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    0.000    0.000    0.000    0.000 <stdin>:1(add)
        2    0.000    0.000    0.000    0.000 <stdin>:1(f)
        1    0.010    0.010    0.010    0.010 <stdin>:1(g)
        1    0.000    0.000    0.010    0.010 <string>:1(?)
        1    0.000    0.000    0.010    0.010 profile:0(g())
        0    0.000             0.000          profile:0(profiler)
######

then the numbers relax, and we can be happy.


Whenever we have performance issues with our programs, we should use a
profiler, since it cuts down on guessing why programs go slow.  It's
better to know that certain sections of programs go slow, so we can focus
our attention like a laser.

So try to profile the program first; if you need help, again, post a URL
to your game, and I'm sure folks here will be happy to help profile and
pinpoint performance issues for you.



Best of wishes!