From 069f32a8c452e7dbd4d10d4da2c142dd24bb5953 Mon Sep 17 00:00:00 2001 From: Brian Maissy Date: Mon, 12 Feb 2018 22:05:46 +0200 Subject: [PATCH 1/4] print captured logs before entering pdb --- _pytest/debugging.py | 5 +++++ changelog/3204.feature | 1 + testing/test_pdb.py | 16 ++++++++++++++++ 3 files changed, 22 insertions(+) create mode 100644 changelog/3204.feature diff --git a/_pytest/debugging.py b/_pytest/debugging.py index 43472f23b..d74cbe186 100644 --- a/_pytest/debugging.py +++ b/_pytest/debugging.py @@ -97,6 +97,11 @@ def _enter_pdb(node, excinfo, rep): tw.sep(">", "captured stderr") tw.line(captured_stderr) + captured_logs = rep.caplog + if len(captured_logs) > 0: + tw.sep(">", "captured logs") + tw.line(captured_logs) + tw.sep(">", "traceback") rep.toterminal(tw) tw.sep(">", "entering PDB") diff --git a/changelog/3204.feature b/changelog/3204.feature new file mode 100644 index 000000000..8ab129a12 --- /dev/null +++ b/changelog/3204.feature @@ -0,0 +1 @@ +Captured logs are printed before entering pdb. diff --git a/testing/test_pdb.py b/testing/test_pdb.py index d882c2cf6..f6d03d6bb 100644 --- a/testing/test_pdb.py +++ b/testing/test_pdb.py @@ -187,6 +187,22 @@ class TestPDB(object): assert "captured stderr" not in output self.flush(child) + def test_pdb_print_captured_logs(self, testdir): + p1 = testdir.makepyfile(""" + def test_1(): + import logging + logging.warn("get rekt") + assert False + """) + child = testdir.spawn_pytest("--pdb %s" % p1) + child.expect("captured logs") + child.expect("get rekt") + child.expect("(Pdb)") + child.sendeof() + rest = child.read().decode("utf8") + assert "1 failed" in rest + self.flush(child) + def test_pdb_interaction_exception(self, testdir): p1 = testdir.makepyfile(""" import pytest From 51ece00923885fa41107e7469d510cb2233406af Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Sun, 18 Feb 2018 12:42:25 +0100 Subject: [PATCH 2/4] Add captured-log support to --show-capture Fixes: #3233 --- _pytest/debugging.py | 22 ++++++++------------ _pytest/terminal.py | 14 ++++++------- changelog/1478.feature | 2 +- testing/test_pdb.py | 12 ++++++----- testing/test_terminal.py | 44 +++++++++++++++++++++++++++------------- 5 files changed, 54 insertions(+), 40 deletions(-) diff --git a/_pytest/debugging.py b/_pytest/debugging.py index d74cbe186..fada117e5 100644 --- a/_pytest/debugging.py +++ b/_pytest/debugging.py @@ -87,20 +87,16 @@ def _enter_pdb(node, excinfo, rep): tw = node.config.pluginmanager.getplugin("terminalreporter")._tw tw.line() - captured_stdout = rep.capstdout - if len(captured_stdout) > 0: - tw.sep(">", "captured stdout") - tw.line(captured_stdout) + showcapture = node.config.option.showcapture - captured_stderr = rep.capstderr - if len(captured_stderr) > 0: - tw.sep(">", "captured stderr") - tw.line(captured_stderr) - - captured_logs = rep.caplog - if len(captured_logs) > 0: - tw.sep(">", "captured logs") - tw.line(captured_logs) + for sectionname, content in (('stdout', rep.capstdout), + ('stderr', rep.capstderr), + ('log', rep.caplog)): + if showcapture in (sectionname, 'all') and content: + tw.sep(">", "captured " + sectionname) + if content[-1:] == "\n": + content = content[:-1] + tw.line(content) tw.sep(">", "traceback") rep.toterminal(tw) diff --git a/_pytest/terminal.py b/_pytest/terminal.py index 69d4ab8ad..55a632b22 100644 --- a/_pytest/terminal.py +++ b/_pytest/terminal.py @@ -44,9 +44,9 @@ def pytest_addoption(parser): help="traceback print mode (auto/long/short/line/native/no).") group._addoption('--show-capture', action="store", dest="showcapture", - choices=['no', 'stdout', 'stderr', 'both'], default='both', - help="Controls how captured stdout/stderr is shown on failed tests. " - "Default is 'both'.") + choices=['no', 'stdout', 'stderr', 'log', 'all'], default='all', + help="Controls how captured stdout/stderr/log is shown on failed tests. " + "Default is 'all'.") group._addoption('--fulltrace', '--full-trace', action="store_true", default=False, help="don't cut any tracebacks (default is to cut).") @@ -630,12 +630,12 @@ class TerminalReporter(object): def _outrep_summary(self, rep): rep.toterminal(self._tw) - if self.config.option.showcapture == 'no': + showcapture = self.config.option.showcapture + if showcapture == 'no': return for secname, content in rep.sections: - if self.config.option.showcapture != 'both': - if not (self.config.option.showcapture in secname): - continue + if showcapture != 'all' and showcapture not in secname: + continue self._tw.sep("-", secname) if content[-1:] == "\n": content = content[:-1] diff --git a/changelog/1478.feature b/changelog/1478.feature index de6bd3118..defc79b9b 100644 --- a/changelog/1478.feature +++ b/changelog/1478.feature @@ -1 +1 @@ -New ``--show-capture`` command-line option that allows to specify how to display captured output when tests fail: ``no``, ``stdout``, ``stderr`` or ``both`` (the default). \ No newline at end of file +New ``--show-capture`` command-line option that allows to specify how to display captured output when tests fail: ``no``, ``stdout``, ``stderr``, ``log`` or ``all`` (the default). diff --git a/testing/test_pdb.py b/testing/test_pdb.py index f6d03d6bb..fa3d86d31 100644 --- a/testing/test_pdb.py +++ b/testing/test_pdb.py @@ -187,16 +187,18 @@ class TestPDB(object): assert "captured stderr" not in output self.flush(child) - def test_pdb_print_captured_logs(self, testdir): + @pytest.mark.parametrize('showcapture', ['all', 'no', 'log']) + def test_pdb_print_captured_logs(self, testdir, showcapture): p1 = testdir.makepyfile(""" def test_1(): import logging - logging.warn("get rekt") + logging.warn("get " + "rekt") assert False """) - child = testdir.spawn_pytest("--pdb %s" % p1) - child.expect("captured logs") - child.expect("get rekt") + child = testdir.spawn_pytest("--show-capture=%s --pdb %s" % (showcapture, p1)) + if showcapture in ('all', 'log'): + child.expect("captured log") + child.expect("get rekt") child.expect("(Pdb)") child.sendeof() rest = child.read().decode("utf8") diff --git a/testing/test_terminal.py b/testing/test_terminal.py index f23dffe25..b3ea01709 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -851,31 +851,47 @@ def pytest_report_header(config, startdir): def test_show_capture(self, testdir): testdir.makepyfile(""" import sys + import logging def test_one(): sys.stdout.write('!This is stdout!') sys.stderr.write('!This is stderr!') + logging.warning('!This is a warning log msg!') assert False, 'Something failed' """) result = testdir.runpytest("--tb=short") - result.stdout.fnmatch_lines(["!This is stdout!"]) - result.stdout.fnmatch_lines(["!This is stderr!"]) + result.stdout.fnmatch_lines(["!This is stdout!", + "!This is stderr!", + "*WARNING*!This is a warning log msg!"]) - result = testdir.runpytest("--show-capture=both", "--tb=short") - result.stdout.fnmatch_lines(["!This is stdout!"]) - result.stdout.fnmatch_lines(["!This is stderr!"]) + result = testdir.runpytest("--show-capture=all", "--tb=short") + result.stdout.fnmatch_lines(["!This is stdout!", + "!This is stderr!", + "*WARNING*!This is a warning log msg!"]) - result = testdir.runpytest("--show-capture=stdout", "--tb=short") - assert "!This is stderr!" not in result.stdout.str() - assert "!This is stdout!" in result.stdout.str() + stdout = testdir.runpytest( + "--show-capture=stdout", "--tb=short").stdout.str() + assert "!This is stderr!" not in stdout + assert "!This is stdout!" in stdout + assert "!This is a warning log msg!" not in stdout - result = testdir.runpytest("--show-capture=stderr", "--tb=short") - assert "!This is stdout!" not in result.stdout.str() - assert "!This is stderr!" in result.stdout.str() + stdout = testdir.runpytest( + "--show-capture=stderr", "--tb=short").stdout.str() + assert "!This is stdout!" not in stdout + assert "!This is stderr!" in stdout + assert "!This is a warning log msg!" not in stdout - result = testdir.runpytest("--show-capture=no", "--tb=short") - assert "!This is stdout!" not in result.stdout.str() - assert "!This is stderr!" not in result.stdout.str() + stdout = testdir.runpytest( + "--show-capture=log", "--tb=short").stdout.str() + assert "!This is stdout!" not in stdout + assert "!This is stderr!" not in stdout + assert "!This is a warning log msg!" in stdout + + stdout = testdir.runpytest( + "--show-capture=no", "--tb=short").stdout.str() + assert "!This is stdout!" not in stdout + assert "!This is stderr!" not in stdout + assert "!This is a warning log msg!" not in stdout @pytest.mark.xfail("not hasattr(os, 'dup')") From ac7eb63a6b9899250ebd58f61f348ef69bf55875 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Sun, 18 Feb 2018 20:48:07 +0100 Subject: [PATCH 3/4] Remove --no-print-logs option This option is superseded by the --show-capture option. With --no-print-logs it was possible to only disable the reporting of captured logs, which is no longer possible with --show-capture. If --show-capture=no is used, no captured content (stdout, stderr and logs) is reported for failed tests. --- _pytest/logging.py | 13 ++------ doc/en/logging.rst | 22 ++----------- testing/logging/test_reporting.py | 54 ------------------------------- 3 files changed, 6 insertions(+), 83 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index d3ac81e65..b719f3a79 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -84,11 +84,6 @@ def pytest_addoption(parser): help='default value for ' + option) group.addoption(option, dest=dest, **kwargs) - add_option_ini( - '--no-print-logs', - dest='log_print', action='store_const', const=False, default=True, - type='bool', - help='disable printing caught logs on failed tests.') add_option_ini( '--log-level', dest='log_level', default=None, @@ -343,7 +338,6 @@ class LoggingPlugin(object): assert self._config.pluginmanager.get_plugin('terminalreporter') is None config.option.verbose = 1 - self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter(get_option_ini(config, 'log_format'), get_option_ini(config, 'log_date_format')) self.log_level = get_actual_log_level(config, 'log_level') @@ -394,10 +388,9 @@ class LoggingPlugin(object): if when == 'teardown': del item.catch_log_handlers - if self.print_logs: - # Add a captured log section to the report. - log = log_handler.stream.getvalue().strip() - item.add_report_section(when, 'log', log) + # Add a captured log section to the report. + log = log_handler.stream.getvalue().strip() + item.add_report_section(when, 'log', log) @pytest.hookimpl(hookwrapper=True) def pytest_runtest_setup(self, item): diff --git a/doc/en/logging.rst b/doc/en/logging.rst index 82119043b..ad59be83f 100644 --- a/doc/en/logging.rst +++ b/doc/en/logging.rst @@ -50,26 +50,10 @@ These options can also be customized through ``pytest.ini`` file: log_format = %(asctime)s %(levelname)s %(message)s log_date_format = %Y-%m-%d %H:%M:%S -Further it is possible to disable reporting logs on failed tests completely -with:: +Further it is possible to disable reporting of captured content (stdout, +stderr and logs) on failed tests completely with:: - pytest --no-print-logs - -Or in the ``pytest.ini`` file: - -.. code-block:: ini - - [pytest] - log_print = False - - -Shows failed tests in the normal manner as no logs were captured:: - - ----------------------- Captured stdout call ---------------------- - text going to stdout - ----------------------- Captured stderr call ---------------------- - text going to stderr - ==================== 2 failed in 0.02 seconds ===================== + pytest --show-capture=no caplog fixture diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py index f84f7e459..7f4c3f17d 100644 --- a/testing/logging/test_reporting.py +++ b/testing/logging/test_reporting.py @@ -91,60 +91,6 @@ def test_teardown_logging(testdir): '*text going to logger from teardown*']) -def test_disable_log_capturing(testdir): - testdir.makepyfile(''' - import sys - import logging - - logger = logging.getLogger(__name__) - - def test_foo(): - sys.stdout.write('text going to stdout') - logger.warning('catch me if you can!') - sys.stderr.write('text going to stderr') - assert False - ''') - result = testdir.runpytest('--no-print-logs') - print(result.stdout) - assert result.ret == 1 - result.stdout.fnmatch_lines(['*- Captured stdout call -*', - 'text going to stdout']) - result.stdout.fnmatch_lines(['*- Captured stderr call -*', - 'text going to stderr']) - with pytest.raises(pytest.fail.Exception): - result.stdout.fnmatch_lines(['*- Captured *log call -*']) - - -def test_disable_log_capturing_ini(testdir): - testdir.makeini( - ''' - [pytest] - log_print=False - ''' - ) - testdir.makepyfile(''' - import sys - import logging - - logger = logging.getLogger(__name__) - - def test_foo(): - sys.stdout.write('text going to stdout') - logger.warning('catch me if you can!') - sys.stderr.write('text going to stderr') - assert False - ''') - result = testdir.runpytest() - print(result.stdout) - assert result.ret == 1 - result.stdout.fnmatch_lines(['*- Captured stdout call -*', - 'text going to stdout']) - result.stdout.fnmatch_lines(['*- Captured stderr call -*', - 'text going to stderr']) - with pytest.raises(pytest.fail.Exception): - result.stdout.fnmatch_lines(['*- Captured *log call -*']) - - @pytest.mark.parametrize('enabled', [True, False]) def test_log_cli_enabled_disabled(testdir, enabled): msg = 'critical message logged by test' From acda6c46fb188514738bbb90f17279c11daa0510 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Mon, 19 Feb 2018 20:34:11 +0100 Subject: [PATCH 4/4] Partially revert "Remove --no-print-logs option" We'll deprecate --no-print-logs beginning with pytest-4.0. This reverts commit ac7eb63a6b9899250ebd58f61f348ef69bf55875. --- _pytest/logging.py | 13 ++++++-- testing/logging/test_reporting.py | 54 +++++++++++++++++++++++++++++++ 2 files changed, 64 insertions(+), 3 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index b719f3a79..d3ac81e65 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -84,6 +84,11 @@ def pytest_addoption(parser): help='default value for ' + option) group.addoption(option, dest=dest, **kwargs) + add_option_ini( + '--no-print-logs', + dest='log_print', action='store_const', const=False, default=True, + type='bool', + help='disable printing caught logs on failed tests.') add_option_ini( '--log-level', dest='log_level', default=None, @@ -338,6 +343,7 @@ class LoggingPlugin(object): assert self._config.pluginmanager.get_plugin('terminalreporter') is None config.option.verbose = 1 + self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter(get_option_ini(config, 'log_format'), get_option_ini(config, 'log_date_format')) self.log_level = get_actual_log_level(config, 'log_level') @@ -388,9 +394,10 @@ class LoggingPlugin(object): if when == 'teardown': del item.catch_log_handlers - # Add a captured log section to the report. - log = log_handler.stream.getvalue().strip() - item.add_report_section(when, 'log', log) + if self.print_logs: + # Add a captured log section to the report. + log = log_handler.stream.getvalue().strip() + item.add_report_section(when, 'log', log) @pytest.hookimpl(hookwrapper=True) def pytest_runtest_setup(self, item): diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py index 7f4c3f17d..f84f7e459 100644 --- a/testing/logging/test_reporting.py +++ b/testing/logging/test_reporting.py @@ -91,6 +91,60 @@ def test_teardown_logging(testdir): '*text going to logger from teardown*']) +def test_disable_log_capturing(testdir): + testdir.makepyfile(''' + import sys + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + sys.stdout.write('text going to stdout') + logger.warning('catch me if you can!') + sys.stderr.write('text going to stderr') + assert False + ''') + result = testdir.runpytest('--no-print-logs') + print(result.stdout) + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + +def test_disable_log_capturing_ini(testdir): + testdir.makeini( + ''' + [pytest] + log_print=False + ''' + ) + testdir.makepyfile(''' + import sys + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + sys.stdout.write('text going to stdout') + logger.warning('catch me if you can!') + sys.stderr.write('text going to stderr') + assert False + ''') + result = testdir.runpytest() + print(result.stdout) + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + @pytest.mark.parametrize('enabled', [True, False]) def test_log_cli_enabled_disabled(testdir, enabled): msg = 'critical message logged by test'