profiling unit tests
November 1st, 2004I run into this just yesterday, when tried to profile my unit tests.
Usually unit tests run in a fraction of a second. Sometimes though, most often because of some heavy-weight interface not being stubbed, they suddenly could take a several seconds. So I thought to myself: “It would be nice if I could a get report about which test methods ate most of the time”.
After struggling for half an hour with a profiler (hotshot or the old one, whatever, they both use pstats module) I give up. Sure enough, I could get an overall program statstics, even filter it by name of the function with a regexp, but there were no way to trace from the actual function (like socket.connect) to a test method that called it (like testReportServerStatus). Or at least, I didn’t find it. The latter is probably the case and the reason I was not able to find it is because pstats has a contrived API. I would say, almost a lack of it thereof. When called, it just prints to the screen what’s been told but have no way to just return accumulated statistical data lump, so I could play with it by myself.
But then another idea came to my mind. Why do I have to struggle with a profiler in the first place? I already have a framework (unittest, that is) which handles the task of runing the test methods. It should be simple to extend it to allow time measurement and report results, shouldn’t it? Well, it turned out more or less simple.
I had to extend both TestSuite class and TestRunner but it did worked. The only major problem I encountered is that TestSuite per se has no idea from which module a particular test has come. Luckily, I was already using my own function to gather test suites so it was simple to establish a module-to-suite mapping. Still, it prints only name of the modules not name of the actual test methods but at least it works. Any idea how to fix this is welcome, though.