Why cProfile module doesn't work with unittest?

Viewed 7033

I would to use cProfile module to profile my unit tests. But when I run

python -mcProfile mytest.py

I got 'Ran 0 tests in 0.000s'. Here is the source code of mytest.py

import unittest

class TestBasic(unittest.TestCase):
    def testFoo(self):
        assert True == True

if __name__ == '__main__':
    unittest.main()

I've tested with other more complex unittests as well. Always got 'Ran 0 tests' if I run it with cProfile. Please help.

UPDATE: My OS is MacOS 10.7 with built-in python 2.7. The same code works properly on ubuntu.

3 Answers

You have to initialize the cProfiler in the Constructor of the test, and use the profile data in destructor -- I use it like that:

from pstats import Stats
import unittest

class TestSplayTree(unittest.TestCase):
    """a simple test"""

    def setUp(self):
        """init each test"""
        self.testtree = SplayTree (1000000)
        self.pr = cProfile.Profile()
        self.pr.enable()
        print "\n<<<---"

    def tearDown(self):
        """finish any test"""
        p = Stats (self.pr)
        p.strip_dirs()
        p.sort_stats ('cumtime')
        p.print_stats ()
        print "\n--->>>"

    def xtest1 (self):
        pass

In case that a test waits for input, one needs to call self.pr.disable() before that call, and re-enable it afterwards.

If you prefer pytest the method names are a bit different:

import cProfile
import time

class TestProfile:
    """ test to illustrate cProfile usage """

    def setup_class(self):
        self.pr = cProfile.Profile()
        self.pr.enable()

    def teardown_class(self):
        self.pr.disable()
        self.pr.print_stats(sort="tottime")

    def test_sleep(self):
        time.sleep(2)

Specifying the module explicitly fixed this for me. That is, replacing...

    unittest.main()

...(which tried to auto-discover what tests it should be running) with...

    unittest.main(module='mytest')  # if in 'mytest.py', or as appropriate for your filename/module

...allowed proper profiling as python -m cProfile mytest.py.

I'm not sure why, but explicitly creating and running a test suite seems to work. I added time.sleep(2) to show something definitive in the stats.

import time
import unittest

class TestBasic(unittest.TestCase):
    def testFoo(self):
        time.sleep(2)
        assert True == True

if __name__ == '__main__':
    suite = unittest.TestLoader().loadTestsFromTestCase(TestBasic)
    unittest.TextTestRunner(verbosity=2).run(suite)

Running in bash, only keeping the first 10 lines, we can see {time.sleep} was the longest running call:

~ $ python -m cProfile -s tottime so.py | head -n10
testFoo (__main__.TestBasic) ... ok

----------------------------------------------------------------------
Ran 1 test in 2.003s

OK
         1084 function calls (1072 primitive calls) in 2.015 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    2.003    2.003    2.003    2.003 {time.sleep}
        1    0.002    0.002    0.003    0.003 case.py:1(<module>)
        1    0.002    0.002    0.003    0.003 collections.py:11(<module>)
        1    0.001    0.001    2.015    2.015 so.py:1(<module>)
        1    0.001    0.001    0.010    0.010 __init__.py:45(<module>)
Related