Possible regression of pdb suppressing output

[foxx]

Hey guys, /cc @nicoddemus

Approx two years ago I submitted a patch for --pdb to stop suppressing output, seen here;
#1223

I can see the PR was merged and the appropriate test is present in master;

pytest/testing/test_pdb.py

Line 150 in 5c6d773

child = testdir.spawn_pytest("--pdb %s" % p1)

But when trying to use this myself, it doesn't seem to work, as seen below.

Any thoughts why this would pass unit tests, but wouldn't work in latest release?

user@c5595a22fd91:~/src/wtf$ cat test_all.py
def test_all():
    print('getrekt')
    assert False

user@c5595a22fd91:~/src/wtf$ pytest --pdb test_all.py
============================================================================================================ test session starts =============================================================================================================
platform linux -- Python 3.6.3, pytest-3.3.1, py-1.5.2, pluggy-0.6.0 -- /usr/bin/python3
cachedir: ../.cache
rootdir: /home/user/src, inifile: pytest.ini
collected 1 item
run-last-failure: run all (no recorded failures)

test_all.py::test_all FAILED                                                                                                                                                                                                           [100%]
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> traceback >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Traceback (most recent call last):
  File "/home/user/src/wtf/test_all.py", line 3, in test_all
    assert False
AssertionError: assert False
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> entering PDB >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
> /home/user/src/wtf/test_all.py(3)test_all()
-> assert False

[pytestbot]

GitMate.io thinks the contributor most likely able to help you is @nicoddemus.

[brianmaissy]

I started debugging this, and I don't yet know why the behavior broke, but I know why the test still passes. The test expects to find the text "getrekt" in the output:

child.expect("getrekt")

It indeed exists, just not as a result of the print statement, rather in the traceback of the assertion failure:

    def test_all():
        print("getrekt")
>       assert False
E       assert False

A possible solution is to update the print in the test to the following:

print("get\\x20rekt") (doubly escaped because it's a string inside a code string)

... and the regex to the following:

child.expect("get rekt")

Now the test does indeed fail, but passes if I add -s to the command line.

[brianmaissy]

I found the problem, but from the looks of the code it appears to be intentional. The reports, including the captured call stdout, are explicitly not printed when pdb has been shown.

pytest/_pytest/terminal.py

Lines 534 to 539 in 0899727

	def getreports(self, name):
	values = []
	for x in self.stats.get(name, []):
	if not hasattr(x, '_pdbshown'):
	values.append(x)
	return values

I looked over your original PR, and it doesn't look like the correct way to do what you wanted. I'm guessing it happened to work at the time but subsequent changes (understandably) broke it.

[foxx]

Hey @brianmaissy thanks for looking into this, glad to know I'm not going crazy! Curious, any idea why they are forcibly removed? Is there a flag which will enable them to be outputted? In the event of pdb being triggered, it's surely important to be able to see the context of why it's been triggered, even if it's an optional flag?

[brianmaissy]

I would be inclined to agree, but I'm very new to the code, hopefully someone who knows the history of this issue can give some insight into the rationale. @nicoddemus, @RonnyPfannschmidt ?

[nicoddemus]

Hey guys sorry for the delay, this got lost in my TODO list.

git blame of the code @brianmaissy quoted shows that it was introduced in 4fa7a2e as part of #128, but I think the handling of stdout when entering pdb is handled by _pytest/debugging.py.

When set_trace() is called, this code stops capturing but seems to thrown away:

pytest/_pytest/debugging.py

Lines 54 to 58 in 3bc7ced

	if cls._pluginmanager is not None:
	capman = cls._pluginmanager.getplugin("capturemanager")
	if capman:
	capman.suspend_global_capture(in_=True)
	tw = _pytest.config.create_terminal_writer(cls._config)

PdbInvoke, which handles the --usepdb option, apparently does the right thing:

pytest/_pytest/debugging.py

Lines 65 to 79 in 3bc7ced

	class PdbInvoke:
	def pytest_exception_interact(self, node, call, report):
	capman = node.config.pluginmanager.getplugin("capturemanager")
	if capman:
	out, err = capman.suspend_global_capture(in_=True)
	sys.stdout.write(out)
	sys.stdout.write(err)
	_enter_pdb(node, call.excinfo, report)
	def pytest_internalerror(self, excrepr, excinfo):
	for line in str(excrepr).split("\n"):
	sys.stderr.write("INTERNALERROR> %s\n" % line)
	sys.stderr.flush()
	tb = _postmortem_traceback(excinfo)
	post_mortem(tb)

I'm not entirely sure how this all work together and I have to leave for now, but perhaps someone can test if changing pytestPDB to write the captured output like PdbInvoke fixes things.

[brianmaissy]

In the test in question, we are entering through pytest_exception_interact.

The output is indeed getting captured, and not thrown away. The problem is that it is saved in the test report (in pytest_runtest_makereport, runner.py line 306), and then never printed (because of the code I attached above).

If I comment out the if in the code I posted, it prints the output. So I think it's working "properly" in the sense that we intentionally don't print the report, which would contain the output.

But in this case it does seem relevant to print the output before entering the debugger. The question is how do we get at the output which was already saved into the test report?

Maybe adding the lines:

tw.sep(">", "Captured stdout")
tw.line(rep.capstdout)

on line 89 of debugging.py, in _enter_pdb?

[nicoddemus]

@brianmaissy I didn't take a good look at the code, but your suggestion seems reasonable.