Colin's Journal

Profiling Python code is difficult. Python comes with two different profilers, called “Profile” and “hotshot”. The hotshot profiler is written in C and is meant to introduce little overhead into the running of your application. Unfortunately it also produces extremely variable output, with the timings determined for a particular function call differing by as much as 400%. This means you can’t make an optimisation and then check with hotshot to determine whether the effect was good, bad, or indifferent. The older “Profile” profiler has a similar problem, but seems to record smaller variations in the times it records for function execution.

Running these profilers was still useful however, because I’ve managed to improve SimpleTAL performance by ~35%. The single biggest performance gain was also the easiest to implement, and involved removing two debug statements. Much to my surprise Python’s logging library introduces a heavy overhead, even when debug is turned off. SimpleTAL used to make a call to a Logger’s debug function for every TAL path evaluated, and despite the significant amount of work performed during the rest of the path evaluation, this debug call took most of the execution time.

The other changes I’ve made were also fairly small, and have improved things by another 10% or so. To make any further improvements I suspect that large scale changes to the TAL/TALES interaction would have to be made.

Posted in Uncategorized | Comments Off on Profiling Python