What do you do when you have several thousand lines of code and around a hundred script files, and you want to know what is causing your game to run slowly?
In my case, it was quite easy. Instead of having lots of:
Always (every frame)->Python
logic setups, I have lots of:
Always (first frame)->Python
setups whereby on the first frame, it registers itself to a scheduler. The scheduler then provides a single point from which 99% of the games code is run.
The scheduler can be as simple as:
events = list()
def register(function, args=None):
if args is None:
args = list()
events.append((function, args))
def run():
for event in events:
event[0](event[1])
or can be as complicated as you like (mine is ~150 lines, and supports registering functions to be run at arbitrary intervals etc. etc.)
If this is the way things are done, then profiling your entire game is as simple as using the cProfile module, and changing the scedhuler to include a profile object, and to run the functions inside the cProfile profiler, and then displaying them somehow.
import cProfile
events = list()
profiler = cProfile.Profile()
def register(function, args=None):
if args is None:
args = list()
events.append((function, args))
def run_profiled():
profiler.runcall(run) # <-- This
def print_stats():
profiler.print_stats(1)
def run():
for event in events:
event[0](event[1])
Note that the profiler is quite slow, so performance may not be as good while profiling.
Upon calling print_stats, you will get a result like:
7331805 function calls in 13.289 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
19768 5.084 0.000 6.096 0.000 meshfx.py:54(update)
2 3.413 1.706 3.413 1.706 {built-in method GameLogic.LibLoad}
3716384 0.674 0.000 0.674 0.000 {method 'setXYZ' of 'KX_VertexProxy' objects}
72179 0.438 0.000 0.438 0.000 {method 'rayCast' of 'KX_GameObject' objects}
2478 0.244 0.000 0.275 0.000 camera.py:29(update)
9884 0.234 0.000 0.430 0.000 engine.py:29(_update)
5882 0.231 0.000 0.408 0.000 projectiles.py:46(ai)
70832 0.208 0.000 13.030 0.000 scheduler.py:77(__call__)
538160 0.183 0.000 0.183 0.000 {built-in method builtins.min}
61878 0.176 0.000 0.254 0.000 tools.py:7(get_polar)
512853 0.150 0.000 0.150 0.000 {built-in method builtins.max}
3481 0.141 0.000 13.288 0.004 scheduler.py:24(update_noprofile)
31800 0.116 0.000 0.313 0.000 medium.py:39(combine_vecs)
113930 0.098 0.000 0.117 0.000 scheduler.py:101(time_until_next_run)
9884 0.089 0.000 1.809 0.000 ai.py:65(_update)
7950 0.080 0.000 1.532 0.000 medium.py:120(update)
Which tells you how long each function took to run.