Profiling PARPG

= Profiling PARPG =

Introduction
Starting with a quote by Donald Knuth: ''“We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil. Yet we should not pass up our opportunities in that critical 3%.A good programmer will not be lulled into complacency by such reasoning, he will be wise to look carefully at the critical code; but only after that code has been identified”''

In order to optimize our application in a performance meaning of the word, it means that at a certain point in time we need to pinpoint exact locations where lots of resources are wasted, this process is called profiling. During profiling a dynamic analysis of the application is conducted and the result is a breakdown which shows where resources are spent.

However profiling in itself can be tricky business since profiling is something related to the Heisenberg uncertainty principle. Basicly that by profiling you typically alter the state of the system. Profiling can happen by code annotation, or by runtime analysis, but none of these come for free, so profiling often results in the application running several times slower than normally.

Next to this we should keep in mind that in this context we even have an extra problem since we're writing a Python frontend to a C++ backend. Which means that a Python-only solution or a C/C++-only solution will not be sufficient. As a result I will present on this page several suggestions on how profiling can be done, and which tools we can use. However who wants to perform profiling will need to make some decisions on the most ideal solution for the problem under investigation.

Profiling Python
See for example this document on python.org explains how to profile python applications. On a .deb based system on would install the package python-profiler. Next the easiest step to profile is simply by calling This will execute PARPG and when this is finished it will should you a listing with several timing information and made calls. This will by default sort the output on the function name (which is basicly nonsense). In order to sort on a different table (typically you will be interested in the total number of calls or the total time spent in one function to find the oddities). In order to accomplish this you can use the -s paramter so we could use these to accomplish this:

An alternative approach would be to to modify the main function in run.py, for example in the following way: In this case you can make of the pstats module to do some data mining of your own (within Python), or for example to save the profiling output to a file and postprocess it in a standalone application. (Note: you can pass multiple keys to sort on, however this doesn't work that well for timing information, since time information is stored more precise than displayed a stats.sort_stat('tim', 'cal') will give unexpected results).

This approach is great for finding bottlenecks which live inside the Python part of PARPG but unfortunately most of the time the output will resemble this one:

614729 function calls (612610 primitive calls) in 54.367 CPU seconds

Ordered by: internal time

ncalls tottime  percall  cumtime  percall filename:lineno(function) 1378  47.932    0.035   49.570    0.036 {_fife.Engine_pump} 1   1.398    1.398    1.398    1.398 {_fife.Engine_destroy} 4   0.336    0.084    1.332    0.333 xmlmap.py:226(parseInstances) 421   0.251    0.001    0.251    0.001 {_fife.Label_setWidth} 1953   0.188    0.000    0.188    0.000 {_fife.Camera_getMatchingInstances} 1   0.183    0.183    0.183    0.183 {_fife.Engine_init} 34501   0.174    0.000    0.214    0.000 fife.py:14(_swig_setattr_nondynamic) 34501   0.161    0.000    0.375    0.000 fife.py:27(_swig_setattr) 69053   0.149    0.000    0.149    0.000 {built-in method get} 221   0.142    0.001    0.651    0.003 xmlanimation.py:40(do_load_resource)

Which learns us that the application is spending most of its time within FIFE (_fife.Engine_pump is the heartbeat which make FIFE render a new frame. So at this point cProfile is only capable of pointing to FIFE.