Profiling information is obtained by calling the module cProfile and by injecting specific code. The two most interesting methods to profile are flush and compile. The most important number from the profiling information is the amount of function calls, and reducing it results in noticeable speedups. Here is an example on the method compile:
import Build def ncomp(self): import cProfile, pstats cProfile.run('import Build; Build.bld.rep_compile()', 'profi.txt') p = pstats.Stats('profi.txt') p.sort_stats('time').print_stats(150) Build.bld.rep_compile = Build.bld.compile Build.bld.compile = ncomp
Here the output obtained on a benchmark build created as explained in the previous section:
Sun Nov 9 19:22:59 2008 prof.txt 959695 function calls (917845 primitive calls) in 3.195 CPU seconds Ordered by: internal time List reduced from 187 to 10 due to restriction 10 ncalls tottime percall cumtime percall filename:lineno(function) 1 0.531 0.531 0.531 0.531 {cPickle.dump} 73950/42150 0.223 0.000 0.276 0.000 Environment.py:66(__getitem__) 5000 0.215 0.000 0.321 0.000 Task.py:770(compute_sig_implicit_deps) 204434 0.180 0.000 0.180 0.000 {method 'update' of '_hashlib.HASH' objects} 5050 0.170 0.000 0.551 0.000 Task.py:706(sig_vars) 10000 0.144 0.000 0.301 0.000 Utils.py:98(h_file) 25255/15205 0.113 0.000 0.152 0.000 Node.py:329(abspath) 15050 0.107 0.000 0.342 0.000 Task.py:481(unique_id) 15301 0.102 0.000 0.102 0.000 Environment.py:50(variant) 132062 0.097 0.000 0.097 0.000 {method 'get' of 'dict' objects}
From the profile information, it appears that the hot spots are, in order:
In practice, the time taken by these methods is not significant enough to justify code changes. Also, profiling must be carried out on builds which last at least several seconds.