Python: Calling functions is really slow?

Question

I've got an Element class that has some functions, one like this:

def clean(self):
    self.dirty = False

I have 1024 elements, and I'm calling clean on each one of them in a while 1: loop.

If I stop calling the clean method, game framerate goes up from 76fps to 250 fps.

This is pretty disturbing. Do I really have to be THIS careful not to completely lag out my code?

Edit (here's the full code):

250 fps code

for layer in self.layers:
            elements = self.layers[layer]
            for element in elements:
                if element.getDirty():
                    element.update()
                    self.renderImage(element.getImage(), element.getRenderPos())

                    element.clean()

76fps code

for layer in self.layers:
            elements = self.layers[layer]
            for element in elements:
                if element.getDirty():
                    element.update()
                    self.renderImage(element.getImage(), element.getRenderPos())

                element.clean()

2Edit (Here's the profiling results):

Sat Feb  9 22:39:58 2013    stats.dat

         23060170 function calls (23049668 primitive calls) in 27.845 seconds

   Ordered by: internal time
   List reduced from 613 to 20 due to restriction <20>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
  3720076    5.971    0.000   12.048    0.000 element.py:47(clean)
      909    4.869    0.005   17.918    0.020 chipengine.py:30(updateElements)
  3742947    4.094    0.000    5.443    0.000 copy.py:67(copy)
     4101    3.972    0.001    3.972    0.001 engine.py:152(killScheduledElements)
    11773    1.321    0.000    1.321    0.000 {method 'blit' of 'pygame.Surface' objects}
        4    1.210    0.302    1.295    0.324 resourceloader.py:14(__init__)
  3720076    0.918    0.000    0.918    0.000 element.py:55(getDirty)
     1387    0.712    0.001    0.712    0.001 {built-in method flip}
  3742947    0.705    0.000    0.705    0.000 copy.py:102(_copy_immutable)
  3728284    0.683    0.000    0.683    0.000 {method 'copy' of 'pygame.Rect' objects}
  3743140    0.645    0.000    0.645    0.000 {method 'get' of 'dict' objects}
     5494    0.566    0.000    0.637    0.000 element.py:89(isBeclouded)
     2296    0.291    0.000    0.291    0.000 {built-in method get}
        1    0.267    0.267    0.267    0.267 {built-in method init}
     1387    0.244    0.000   25.714    0.019 engine.py:67(updateElements)
     2295    0.143    0.000    0.143    0.000 {method 'tick' of 'Clock' objects}
    11764    0.095    0.000    0.169    0.000 element.py:30(update)
  8214/17    0.062    0.000    4.455    0.262 engine.py:121(createElement)
       40    0.052    0.001    0.052    0.001 {built-in method load_extended}
    36656    0.046    0.000    0.067    0.000 element.py:117(isCollidingWith)

Doing anything in a `while 1` loop will cause lag. Have you tried calling a function at a set interval? — Waleed Khan, Feb 10 '13 at 03:09
Are you sure the fact that `self.dirty` is turning `False` isn't causing the slowdown? — icktoofay, Feb 10 '13 at 03:09
@waleedkhan Since this is a realtime game, I don't think that's going to work. — Name McChange, Feb 10 '13 at 03:09
@SuperDisk I'm not a game developer, but having made a couple games in the past, maxing out the CPU is never how I've seen it done. I imagine realtime games work just fine at 15ms intervals. — Waleed Khan, Feb 10 '13 at 03:14
@waleedkhan I have a mechanism in there for limiting it to 60 fps. Don't worry. I'm just taking off that restriction to find performance issues right now. — Name McChange, Feb 10 '13 at 03:16
Could you analyse how many times you're calling `self.renderImage`? — Alex L, Feb 10 '13 at 03:23
I'd also suggest running `cProfile` on your code - see http://stackoverflow.com/questions/582336/how-can-you-profile-a-python-script — Alex L, Feb 10 '13 at 03:24
@alexl I've already run cProfile. `renderImage` only gets called when elements are dirty, and if they are dirty, they are cleaned. So each element only gets rendered once. — Name McChange, Feb 10 '13 at 03:27
Strange - getDirty and clean are both called 3720076 times, yet one takes up 12 times as much time. — Liquid_Fire, Feb 10 '13 at 03:55

score 1 · Accepted Answer · answered Feb 10 '13 at 03:51

1

The profiling says that calling the clean method takes about 6 out of 28 seconds during the profiling. It also gets called 3.7 million times during that time.

That means that the loop you are showing must be the main loop of the software. That main loop also does only the following things:

Checks if the element is dirty.
If it is, it draws it.
Then cleans it.

Since most elements are not dirty (update() only gets called 11 thousand of these 3.7 million loops), the end result is that your main loop is now doing only one thing: Checking if the element is dirty, and then calling .clean() on it.

By only calling clean if the element is dirty, you have effectively cut the main loop in half.

Do I really have to be THIS careful not to completely lag out my code?

Yes. If you have a very tight loop that for the most time does nothing, then you have to make sure that this loop is in fact tight.

This is pretty disturbing.

No, it's a fundamental computing fact.

answered Feb 10 '13 at 03:51

Lennart Regebro

167,292
41
224
251

I think it's rather disturbing that merely setting a boolean 1024 times per loop can so drastically reduce the framerate! – Name McChange Feb 10 '13 at 03:54
@SuperDisk: But you are doing *nothing else*. You are removing 1757 settings of that boolean object attribute each frame. And that's all that loop does. There's nothing disturbing about that when you remove the only thing the loop does you speed it up a lot. Maybe it's experience with age, but I find it pretty obvious that you don't do anything in a main loop that is not absolutely required. Doesn't matter what language. – Lennart Regebro Feb 10 '13 at 03:58
Well, there's other stuff happening. That's just a chunk of the main software loop. But I suppose you're right. – Name McChange Feb 10 '13 at 04:04
@SuperDisk: According the profiling, no, there really isn't much other things happening. There might be a lot of other code, but it isn't being called as much. – Lennart Regebro Feb 10 '13 at 04:17
@SuperDisk: I think you'll find this interesting: http://blog.enthought.com/general/what-is-your-python-budget/ – Warren Weckesser Feb 10 '13 at 12:12

score 0 · Answer 2 · answered Feb 10 '13 at 07:45

(comment, but my stats are to low to "comment")

If you are calling element.getDirty() 3.7 million times and it's only dirty 11 thousand times, you should be keeping a dirty list, not polling every time.

That is, don't set the dirty flag, but add the dirty element to a dirty element list. It looks like you might need a dirty list for each layer.

Python: Calling functions is really slow?

2 Answers2