Profiler Part II: Poor Man’s Code Coverage

The only feedback I’ve gotten so far about the IronPython Profiler is that it would be nice not to have to specify a command-line option to use it. Imagine that you’ve got a REPL open and are in the middle of some interactive development – something at which I think Python excels. You’ve spent a fair amount of time setting up data and code, but now there’s something that’s running slowly that you’d like to analyze. Restarting your REPL means having to repeat all that setup work.

Sometimes, we even listen

As a result of this feedback, we’ve added a new EnableProfiler method to the clr module. clr.EnableProfiler(True) will enable profiling, and clr.EnableProfiler(False) will disable it again.

Of course, IronPython is a compiler, and the calls to capture profiler data are compiled right into your code. You can’t just throw a switch to turn on profiling without actually forcing the code in question to be recompiled. This can be done by doing a reload() on the module that contains the code. Naturally, all the standard caveats for reload apply. In particular, any references to the old code from other modules and from instantiated objects don’t get automatically updated.

Not Nearly as Naked

While making this change, it occurred to me that we could get function-level code coverage for free simply by looking for functions that had been compiled but not called at the end of a test run. This required a small change to the code that is run when you call clr.GetProfilerData(). Previously, this function only returned records for methods which had actually been called. This is how it continues to behave when no parameters are used. But when you call clr.GetProfilerData(True), you get all compiled methods – even those that were never used.

Armed with this change, here’s how I modified the test runner for a project I’m working on:

def _trySetupCoverage():
    for i in xrange(1, len(sys.argv)):
        arg = sys.argv[i]
        if arg.startswith('--coverage='):
            import clr
            coverage_file = arg[11:]
            del sys.argv[i]
            return coverage_file
    return None

def _tryFinishCoverage(coverage_file):
    if coverage_file is None:
    hits, misses = {}, {}
    for p in clr.GetProfilerData(True):
        # Assume no module name contains a colon
        end = p.Name.find(':')
        if end < 0 or not p.Name.startswith('module '):
        module = p.Name[7:end]
        if p.Calls > 0:
            hits[module] = hits.get(module, 0) + 1
            misses[module] = misses.get(module, 0) + 1
    with open(coverage_file, 'w') as f:
        modules = hits.keys()
        for mod in modules:
            h = hits.get(mod, 0)
            m = misses.get(mod, 0)
            total = h + m
            if total > 0:
                # Write module, covered functions, total functions, percentage
                # TODO: Log functions that lack coverage
                f.write('%s\t%d\t%d\t%.1f\n' % (mod, h, total, 100.0 * h / total))

if __name__ == "__main__":
    coverage = _trySetupCoverage()
    RunAllTests(None, None, None)

This code could be trivially modified so that an exception is thrown if coverage drops below a certain percentage. If the tests were being run as part of a checkin gate, it would then prevent code from being added to source control unless it was at least superficially under test.

I call this “poor man’s code coverage” because it was cheaply obtained and is not very sophisticated. It won’t tell us anything, for instance, if a module has not been imported at all.  Nonetheless, it’s a potentially useful addition to the box of tools that’s available for IronPython.

These changes were made after IronPython 2.6 Alpha 1 was released, so if you want to play with them you’ll need to grab a recent source drop – one not earlier than Change Set 49035.


As always, your feedback could influence any further development in this direction.

Comments (3)

  1. Thank you for submitting this cool story – Trackback from DotNetShoutout

  2. curth says:

    Dino tells me that I’m totally wrong about sys.setrecursionlimit — so I got rid of that line from the text :(.