I'm testing a function that writes to a logfile (it doesn't matter that it writes to a logfile specifically, it could be doing anything, it's just what gave rise to this question)
Something like this:
def do_stuff():
with open('/tmp/mylogs.txt', 'a') as f:
f.write(str(time.time()))
f.write(' stuff done! \n')
return 42
And I can test it a bit like this:
def test_doing_stuff(watch_logs):
assert do_stuff() == 42
assert do_stuff() == 43
For debugging purposes, when a test fails, I want to be able to print out the new contens of the logs -- I can make a fixture a bit like this:
@pytest.fixture()
def watch_logs(request):
with open('/tmp/mylogs.txt') as f:
log_before = f.read()
def get_new_logs():
with open('/tmp/mylogs.txt') as f:
log_after = f.read()
return log_after.replace(log_before, '')
return get_new_logs
Great - now I can check the log contents at any point in my tests:
def test_doing_stuff(watch_logs):
assert do_stuff() == 42
print(watch_logs())
assert do_stuff() == 43
print(watch_logs())
Hm - ah, but that second print isn't going to work, it's after the test failure.
What if my test fixture just always printed the logs out at the end of the test? Then pytest's stdout capture would show it to me when it fails, but not when it passes!
@pytest.fixture()
def watch_logs(request):
with open('/tmp/mylogs.txt') as f:
log_before = f.read()
def get_new_logs():
with open('/tmp/mylogs.txt') as f:
log_after = f.read()
return log_after.replace(log_before, '')
def print_new_logs():
print('~' * 20 + ' logs ' + '~' * 20)
print(get_new_logs())
print('~' * 50)
request.addfinalizer(print_new_logs)
return get_new_logs
Oh, but that doesn't work because pytests's log capture isn't happening during test finalizers.
So the question is: how can I make a test finalizer that can print stuff?
Here's an ultra-minimal gist without the (irrelevant) writing-to-a-logfile stuff: https://gist.github.com/hjwp/5154ec40a476a5c01ba6
Thanks to help from Holger himself (thanks @hpk42!), I've got something that works. Only slightly magic/hacky.
The solution is to use a py.test hook called
pytest_pyfunc_call
, alongside a decorator calledhookwrapper
. They give me a way to hook in some code both before and after the test runs, but also without being affected by the stdout hijacking.We define a new function in conftest.py:
And now, if pytest spots any test which uses the
watch_logs
fixture, it will print its output after the test runs.Full example: https://gist.github.com/hjwp/4294f0acbef5345a7d46