Nose is a fantastic testing framework. What surprises me though, is that there’s no out of the box plugin to time tests to see which tests are the slowest, and most likely, problematic. After all, unit tests are supposed to be wicked fast. I googled, but nothing really came up except an insightful google-groups post.
I figured, what the hey, might as well just write a simple nose plugin to time the tests. I modeled it slightly off the xunit nose plugin. With the xunit plugin as a guiding example, I thought it was pretty trivial to write a nose plugin, definitely a testament to the great design chosen by nose.
Here’s the plugin below:
"""This plugin provides test timings to identify which tests might betaking the most. From this information, it might be useful to coupleindividual tests nose's `--with-profile` option to profile problematictests.
This plugin is heavily influenced by nose's `xunit` plugin.
Add this command to the way you execute nose::
--with-test-timer
After all tests are executed, they will be sorted in ascending order.
(c) 2011 - Mahmoud Abdelkader (http://github.com/mahmoudimus)
LICENSE: DO WHAT THE FUCK YOU WANT TO PUBLIC LICENSE Version 2, December 2004
Copyright (C) 2004 Sam Hocevar <sam@hocevar.net>
Everyone is permitted to copy and distribute verbatim or modified copies of this license document, and changing it is allowed as long as the name is changed.
DO WHAT THE FUCK YOU WANT TO PUBLIC LICENSE TERMS AND CONDITIONS FOR COPYING, DISTRIBUTION AND MODIFICATION
0. You just DO WHAT THE FUCK YOU WANT TO.
"""
import operatorfrom time import time
import nosefrom nose.plugins.base import Plugin
class TestTimer(Plugin): """This plugin provides test timings
"""
name = 'test-timer' score = 1
def _timeTaken(self): if hasattr(self, '_timer'): taken = time() - self._timer else: # test died before it ran (probably error in setup()) # or success/failure added before test started probably # due to custom TestResult munging taken = 0.0 return taken
def options(self, parser, env): """Sets additional command line options.""" super(TestTimer, self).options(parser, env)
def configure(self, options, config): """Configures the test timer plugin.""" super(TestTimer, self).configure(options, config) self.config = config self._timed_tests = {}
def startTest(self, test): """Initializes a timer before starting a test.""" self._timer = time()
def report(self, stream): """Report the test times""" if not self.enabled: return d = sorted(self._timed_tests.iteritems(), key=operator.itemgetter(1)) for test, time_taken in d: stream.writeln("%s: %0.4f" % (test, time_taken))
def _register_time(self, test): self._timed_tests[test.id()] = self._timeTaken()
def addError(self, test, err, capt=None): self._register_time(test)
def addFailure(self, test, err, capt=None, tb_info=None): self._register_time(test)
def addSuccess(self, test, capt=None): self._register_time(test)
if __name__ == '__main__': nose.main(addplugins=[TestTimer()])
Something cool about nose was that you don’t have to install a plugin package-wide using setuptools, but you can actually just dynamically add it during run-time. All you have to do is:
import nose
from yourplugin import YourPlugin
if __name__ == '__main__':
nose.main(addplugins=[YourPlugin()])
This way, you can just execute your tests as normal, like so:
python nose-testtimers.py --with-test-timer -sv --debug=sqlalchemy.engine
and you get a nice little output of test times 