hookwrappers can't modify the in-flight exception without skipping later hookwrapper teardowns

[oremanj]

Suppose you want to write a pytest plugin that transforms some exceptions in a test into different exceptions. As I understand it, this can be done with a hookwrapper, something like this:

@pytest.hookimpl(hookwrapper=True)
def pytest_pyfunc_call():
    outcome = yield
    if isinstance(outcome.excinfo[1], ValueError):
        raise KeyError("example") from outcome.excinfo[1]

And this works great, as long as you only have one such wrapper. But if you have two, then raising an exception in the "inner" one will skip the teardown portion of the "outer" one. A complete example:

$ head *.py
==> conftest.py <==
pytest_plugins = ["plugin1", "plugin2"]

==> plugin1.py <==
import pytest

@pytest.hookimpl(hookwrapper=True, tryfirst=True)
def pytest_pyfunc_call():
    print("before 1")
    yield
    print("after 1")

==> plugin2.py <==
import pytest

@pytest.hookimpl(hookwrapper=True)
def pytest_pyfunc_call():
    print("before 2")
    result = yield
    print("after 2")
    if isinstance(result.excinfo[1], ValueError):
        raise KeyError("added in 2") from result.excinfo[1]

==> test.py <==
def test_foo():
    raise ValueError("in test")

$ pytest test.py
[... snip some frames from pytest/pluggy internals ...]
    def test_foo():
>       raise ValueError("in test")
E       ValueError: in test

t.py:2: ValueError

The above exception was the direct cause of the following exception:

    @pytest.hookimpl(hookwrapper=True)
    def pytest_pyfunc_call():
        print("before 2")
        result = yield
        print("after 2")
        if isinstance(result.excinfo[1], ValueError):
>           raise KeyError("added in 2") from result.excinfo[1]
E           KeyError: 'added in 2'

plugin2.py:9: KeyError
---- Captured stdout call ----
before 1
before 2
after 2
==== 1 failed in 0.08 seconds ====

Notably missing from the "Captured stdout call": after 1.

I encountered this when trying to use pytest_runtest_call as the wrapper; _pytest.logging uses a pytest_runtest_call wrapper to add the captured logging to the test report, so logging would mysteriously fail to be captured.

A workaround is possible by assigning to result._excinfo instead of re-raising, but it would be nice to have a supported mechanism for this so as not to need to reach into internals.

This issue was seen with pytest 4.3.1 and pluggy 0.9.0 on Linux. I'm not immediately able to test with a newer version, but the relevant code (pluggy.callers._multicall) doesn't seem to have changed recently.

[Zac-HD]

We should definitely fix this if it's still present in Pytest 5!

[RonnyPfannschmidt]

moved this to pluggy as its clearly a pluggy issue (imho), we might need to have a tracking one in pytest for pinning later on

[maciej-lech]

Hi,

I have encountered the same problem, despite the fact that raising from teardown never seemed to be a good idea for me :)

What is the desired solution for this?

1. Should excinfo be overridden by the last (or maybe first) raised exception from teardown? It doesn't seem to be right as in case of call, the execution stops on first error.
2. Should pluggy swallow all teardown exceptions? Never good for troubleshooting ;)

What do you think?

Best regards, Maciej

[maxnikulin]

I think I have a pure pluggy example (no pytest involved) demonstrating that after exception tear down functions are called through garbage collector instead of hook runner

from __future__ import print_function
import pluggy
import sys

hookspec = pluggy.HookspecMarker('pluxample')
hookimpl = pluggy.HookimplMarker('pluxample')


class PluxampleSpec(object):
    @hookspec
    def call():
        pass


class OuterHookWrapper:
    @hookimpl(hookwrapper=True)
    def call(self):
        print('OuterHookWrapper prepare')
        try:
            yield
        finally:
            print('OuterHookWrapper **cleanup**')


class HookWithFailingCleanup:
    @hookimpl(hookwrapper=True)
    def call(self):
        print('HookWithFailingCleanup prepare')
        yield
        print('HookWithFailingCleanup throw')
        raise RuntimeError('HookWithFailingCleanup Failed!')


class FunHook:
    @hookimpl
    def call(self):
        print('FunHook')
        return 10

def main(early):
    print('main begin')
    pm = pluggy.PluginManager('pluxample')
    pm.add_hookspecs(PluxampleSpec)
    pm.register(FunHook())
    pm.register(HookWithFailingCleanup())
    pm.register(OuterHookWrapper())
    exit = 1
    try:
        result = pm.hook.call()
        print('main result %r' % (result,))
        exit = 0
    except Exception as ex:
        print('main exception **handler**: %r' % (ex,))
        # It is important where exit is called
        if early:
            print('exit failure')
            sys.exit(exit)

    print('exit %s' % ('success' if exit == 0 else 'failure',))
    sys.exit(exit)

if __name__ == '__main__':
    if len(sys.argv) == 2:
        if sys.argv[1] == 'early':
            main(early=True)
        elif sys.argv[1] == 'late':
            main(early=False)
    else:
        print('Usage:\n    %s { early | late }' % sys.argv[0])

Expectation is that OuterHookWrapper cleanup should be executed before main exception handler however with pyhton-3.8 and early argument output is

main begin
OuterHookWrapper prepare
HookWithFailingCleanup prepare
FunHook
HookWithFailingCleanup throw
main exception **handler**: RuntimeError('HookWithFailingCleanup Failed!')
exit failure
OuterHookWrapper **cleanup**

with late argument order of last lines is

...
HookWithFailingCleanup throw
main exception **handler**: RuntimeError('HookWithFailingCleanup Failed!')
OuterHookWrapper **cleanup**
exit failure

I suspect is that the problem cause is around https://github.com/pytest-dev/pluggy/blob/30a2f7c691c32e7ceb29ce52063773c21d3a2a0e/src/pluggy/callers.py#L205 where only StopIteration exception is caught

[bluetech]

PR #389 provides a way to handle this (provided new-style wrappers are used)