From 3b9fd3abd8b86afd02ecceb5645c69e873294081 Mon Sep 17 00:00:00 2001 From: holger krekel Date: Tue, 8 Nov 2011 17:20:56 +0000 Subject: [PATCH] introduce --durations=N showing slowest test executions --- CHANGELOG | 2 ++ _pytest/__init__.py | 2 +- _pytest/pytester.py | 9 ++++++- _pytest/runner.py | 36 +++++++++++++++++++++++++-- doc/announce/release-2.2.0.txt | 21 ++++++++++++++++ doc/example/simple.txt | 27 ++++++++++++++++++++ doc/index.txt | 1 + doc/usage.txt | 12 +++++++++ setup.py | 2 +- testing/acceptance_test.py | 45 ++++++++++++++++++++++++++++++++++ 10 files changed, 152 insertions(+), 5 deletions(-) create mode 100644 doc/announce/release-2.2.0.txt diff --git a/CHANGELOG b/CHANGELOG index bc4c0d6ae..80114ceb1 100644 --- a/CHANGELOG +++ b/CHANGELOG @@ -1,6 +1,8 @@ Changes between 2.1.3 and [next version] ---------------------------------------- +- new feature to help optimizing your tests: --durations=N option for + displaying N slowest test calls - fix and cleanup pytest's own test suite to not leak FDs - fix issue83: link to generated funcarg list - fix issue74: pyarg module names are now checked against imp.find_module false positives diff --git a/_pytest/__init__.py b/_pytest/__init__.py index 9a7071550..94e47a012 100644 --- a/_pytest/__init__.py +++ b/_pytest/__init__.py @@ -1,2 +1,2 @@ # -__version__ = '2.1.4.dev3' +__version__ = '2.2.0.dev1' diff --git a/_pytest/pytester.py b/_pytest/pytester.py index 060924edc..7ddb709d9 100644 --- a/_pytest/pytester.py +++ b/_pytest/pytester.py @@ -549,10 +549,17 @@ class ReportRecorder(object): def getreports(self, names="pytest_runtest_logreport pytest_collectreport"): return [x.report for x in self.getcalls(names)] - def matchreport(self, inamepart="", names="pytest_runtest_logreport pytest_collectreport", when=None): + def matchreport(self, inamepart="", + names="pytest_runtest_logreport pytest_collectreport", when=None): """ return a testreport whose dotted import path matches """ l = [] for rep in self.getreports(names=names): + try: + if not when and rep.when != "call" and rep.passed: + # setup/teardown passing reports - let's ignore those + continue + except AttributeError: + pass if when and getattr(rep, 'when', None) != when: continue if not inamepart or inamepart in rep.nodeid.split("::"): diff --git a/_pytest/runner.py b/_pytest/runner.py index fa56e1459..f0f676215 100644 --- a/_pytest/runner.py +++ b/_pytest/runner.py @@ -14,6 +14,38 @@ def pytest_namespace(): # # pytest plugin hooks +def pytest_addoption(parser): + group = parser.getgroup("terminal reporting", "reporting", after="general") + group.addoption('--durations', + action="store", type="int", dest="durations", default=None, metavar="N", + help="show N slowest setup/test durations (N=0 for all)."), + +def pytest_terminal_summary(terminalreporter): + durations = terminalreporter.config.option.durations + if durations is None: + return + tr = terminalreporter + duration2rep = {} + for key, replist in tr.stats.items(): + if key == "deselected": + continue + for rep in replist: + duration2rep[rep.duration] = rep + if not duration2rep: + return + d2 = duration2rep.items() + d2.sort() + d2.reverse() + if not durations: + tr.write_sep("=", "slowest test durations") + else: + tr.write_sep("=", "slowest %s test durations" % durations) + d2 = d2[:durations] + + for duration, rep in d2: + nodeid = rep.nodeid.replace("::()::", "::") + tr.write_line("%2.2f %s %s" % (duration, rep.when, nodeid)) + def pytest_sessionstart(session): session._setupstate = SetupState() @@ -185,13 +217,13 @@ class TestReport(BaseReport): #: a name -> value dictionary containing all keywords and #: markers associated with a test invocation. self.keywords = keywords - + #: test outcome, always one of "passed", "failed", "skipped". self.outcome = outcome #: None or a failure representation. self.longrepr = longrepr - + #: one of 'setup', 'call', 'teardown' to indicate runtest phase. self.when = when diff --git a/doc/announce/release-2.2.0.txt b/doc/announce/release-2.2.0.txt new file mode 100644 index 000000000..0b03beeaa --- /dev/null +++ b/doc/announce/release-2.2.0.txt @@ -0,0 +1,21 @@ +py.test 2.2.0: new test duration profiling and bug fixes +=========================================================================== + +pytest-2.2.0 is a backward compatible release of the popular +py.test testing tool. It introduces the new "--duration=N" option +showing the N slowest test execution or setup/teardown calls. The +release also contains a few fixes and some cleanup of pytest's own test +suite allowing it to run on a wider range of environments. + +For general information, see extensive docs with examples here: + + http://pytest.org/ + +If you want to install or upgrade pytest you might just type:: + + pip install -U pytest # or + easy_install -U pytest + +best, +holger krekel + diff --git a/doc/example/simple.txt b/doc/example/simple.txt index 5aae66511..15cf16c10 100644 --- a/doc/example/simple.txt +++ b/doc/example/simple.txt @@ -299,3 +299,30 @@ and nothing when run plainly:: collecting ... collected 0 items ============================= in 0.00 seconds ============================= + +profiling test duration +-------------------------- + +.. regendoc:wipe + +.. versionadded: 2.2 + +If you have a slow running large test suite you might want to find +out which tests are slowest. Let's make an artifical test suite:: + + # content of test_some_are_slow.py + + import time + + def test_funcfast(): + pass + + def test_funcslow1(): + time.sleep(0.1) + + def test_funcslow2(): + time.sleep(0.2) + +Now we can profile which test functions execute slowest:: + + $ py.test --durations=3 diff --git a/doc/index.txt b/doc/index.txt index d31c31753..817cc3436 100644 --- a/doc/index.txt +++ b/doc/index.txt @@ -25,6 +25,7 @@ Welcome to pytest! - **supports functional testing and complex test setups** + - (new in 2.2) :ref:`durations` - advanced :ref:`skip and xfail` - generic :ref:`marking and test selection ` - can :ref:`distribute tests to multiple CPUs ` through :ref:`xdist plugin ` diff --git a/doc/usage.txt b/doc/usage.txt index ce5c01577..9ea57a75d 100644 --- a/doc/usage.txt +++ b/doc/usage.txt @@ -98,6 +98,18 @@ can use a helper:: In previous versions you could only enter PDB tracing if you disable capturing on the command line via ``py.test -s``. +.. _durations: + +Profiling test execution duration +------------------------------------- + +.. versionadded: 2.2 + +To get a list of the slowest 10 test durations:: + + py.test --durations=10 + + Creating JUnitXML format files ---------------------------------------------------- diff --git a/setup.py b/setup.py index 09f1b0ff4..9f45274e4 100644 --- a/setup.py +++ b/setup.py @@ -24,7 +24,7 @@ def main(): name='pytest', description='py.test: simple powerful testing with Python', long_description = long_description, - version='2.1.4.dev3', + version='2.2.0.dev1', url='http://pytest.org', license='MIT license', platforms=['unix', 'linux', 'osx', 'cygwin', 'win32'], diff --git a/testing/acceptance_test.py b/testing/acceptance_test.py index 218a87529..55a6effd1 100644 --- a/testing/acceptance_test.py +++ b/testing/acceptance_test.py @@ -465,3 +465,48 @@ class TestInvocationVariants: "*1 failed*", ]) +def test_duration_test(testdir): + testdir.makepyfile(""" + import time + frag = 0.01 + def test_2(): + time.sleep(frag*2) + def test_1(): + time.sleep(frag) + def test_3(): + time.sleep(frag*3) + """) + result = testdir.runpytest("--durations=10") + assert result.ret == 0 + result.stdout.fnmatch_lines([ + "*durations*", + "*call*test_3*", + "*call*test_2*", + "*call*test_1*", + ]) + result = testdir.runpytest("--durations=2") + assert result.ret == 0 + result.stdout.fnmatch_lines([ + "*durations*", + "*call*test_3*", + "*call*test_2*", + ]) + assert "test_1" not in result.stdout.str() + result = testdir.runpytest("--durations=0") + assert result.ret == 0 + for x in "123": + for y in 'call',: #'setup', 'call', 'teardown': + l = [] + for line in result.stdout.lines: + if ("test_%s" % x) in line and y in line: + break + else: + raise AssertionError("not found %s %s" % (x,y)) + + result = testdir.runpytest("--durations=2", "-k test_1") + assert result.ret == 0 + result.stdout.fnmatch_lines([ + "*durations*", + "*call*test_1*", + ]) +