I was recently working on improving the performance of a Python-based application and thought it would be useful to profile my code. My intuition was telling me that the problem was in a certain area of the code, but I wanted hard numbers to back up this intuition before I went to the trouble of doing a rewrite. Unfortunately, neither the CLR Profiler nor the profiling support in Visual Studio are very effective when used with IronPython, as they weren’t really created for environments where code is dynamically compiled at runtime.
But Tomáš had written a profiler for IronRuby nearly half a year ago, so I thought I’d port this to IronPython, where it’s now experimentally available in IronPython 2.6 Alpha 1.
The way Tomáš’ profiler works is pretty straightforward. At the start of every method we compile, a snapshot is taken of the current time. Another is taken at the end of the method and the difference is stored for later retrieval. The only tricky thing about it is trying to update the statistics in a manner that’s both thread-safe and has minimal effect on performance.
I’ve modified it a bit from the original, though, and added some fun features. In particular, it now tracks the number of calls made to each method and also keeps separate counters for the amount of time spent exclusively inside the method versus the duration spent inclusively in both this method and in any methods it calls.
Additionally, I’ve added counters to track calls made from Python code into statically-compiled .NET code.
Saturday, April 11, 2009
Curt Hagenlocher (core IronPython developer) has a blog entry outlining a new profiling tool for IronPython which is included in IronPython 2.6 Alpha 1. With Harry Pierson's debugger we're almost spoiled for tools now!