Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SystemError: 'finally' pops bad exception with python 3.7 (master branch) #2674

Closed
tacaswell opened this issue Aug 10, 2017 · 8 comments
Closed

Comments

@tacaswell
Copy link

The Matplotlib (https://github.com/matplotlib/matplotlib) test suite is seeing errors like

SystemError: 'finally' pops bad exception

We see these both on travis (https://travis-ci.org/matplotlib/matplotlib/jobs/262907186 ) and I can reproduce locally.

Walking the stack in the debugger is all in pytest / py code and in the code path that handles exceptions.

Via debugging-write-to-a-file I am pretty sure that all of the matplotlib specific code is through and there is not an exception.

This may be a upstream python bug, but trying here first with the hope you will be able to help get a more minimal example.

@tacaswell
Copy link
Author

Ok, leaning more towards this being a cpython bug:

Applying the following patch

00:35 $ git diff
diff --git a/Python/ceval.c b/Python/ceval.c
index 9f732f56ba..bac90eaacb 100644
--- a/Python/ceval.c
+++ b/Python/ceval.c
@@ -2100,8 +2100,8 @@ _PyEval_EvalFrameDefault(PyFrameObject *f, int throwflag)
                 goto fast_block_end;
             }
             else if (status != Py_None) {
-                PyErr_SetString(PyExc_SystemError,
-                    "'finally' pops bad exception");
+                PyErr_SetObject(PyExc_SystemError,
+                    status);
                 Py_DECREF(status);
                 goto error;
             }

leads to

E           SystemError: <module 'matplotlib' from '/home/tcaswell/source/p/matplotlib/lib/matplotlib/__init__.py'>


being the thing that finally popped of the stack.

@RonnyPfannschmidt
Copy link
Member

does the error happen with --assert=plain ?

@tacaswell
Copy link
Author

tacaswell commented Aug 10, 2017

Yes, still happens with --assert=plain

It looks like there is a weird every-other pattern:

lib/matplotlib/tests/test_backend_pgf.py .E.E.E.E.E.E
lib/matplotlib/tests/test_backend_qt5.py .E.E.E.E.E.E.E.E.E.E.E.E.E

which if you add -v shows

lib/matplotlib/tests/test_backend_pgf.py::test_xelatex PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_xelatex ERROR
lib/matplotlib/tests/test_backend_pgf.py::test_pdflatex PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_pdflatex ERROR
lib/matplotlib/tests/test_backend_pgf.py::test_rcupdate PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_rcupdate ERROR
lib/matplotlib/tests/test_backend_pgf.py::test_pathclip PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_pathclip ERROR
lib/matplotlib/tests/test_backend_pgf.py::test_mixedmode PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_mixedmode ERROR
lib/matplotlib/tests/test_backend_pgf.py::test_bbox_inches PASSED
lib/matplotlib/tests/test_backend_pgf.py::test_bbox_inches ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_fig_close PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_fig_close ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[shift] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[shift] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[lower] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[lower] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[control] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[control] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[unicode_upper] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[unicode_upper] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[unicode_lower] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[unicode_lower] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[alt_control] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[alt_control] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[control_alt] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[control_alt] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[modifier_order] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[modifier_order] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[backspace] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[backspace] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[backspace_mod] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[backspace_mod] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[non_unicode_key] PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_correct_key[non_unicode_key] ERROR
lib/matplotlib/tests/test_backend_qt5.py::test_dpi_ratio_change PASSED
lib/matplotlib/tests/test_backend_qt5.py::test_dpi_ratio_change ERROR

so pytest seems to be reporting each test twice but finds them just once:

09:20 $ pytest -k pgf --collect-only
========================================================================================================================================================================================================= test session starts ==========================================================================================================================================================================================================
platform linux -- Python 3.7.0a0, pytest-3.1.2, py-1.4.34, pluggy-0.4.0
rootdir: /home/tcaswell/source/p/matplotlib, inifile: pytest.ini
plugins: xdist-1.17.1, cov-2.5.1
collected 6836 items / 1 skipped 
<Module 'lib/matplotlib/tests/test_backend_pgf.py'>
  <Function 'test_xelatex'>
  <Function 'test_pdflatex'>
  <Function 'test_rcupdate'>
  <Function 'test_pathclip'>
  <Function 'test_mixedmode'>
  <Function 'test_bbox_inches'>

======================================================================================================================================================================================================== 6830 tests deselected =========================================================================================================================================================================================================
============================================================================================================================================================================================== 1 skipped, 6830 deselected in 2.74 seconds ==============================================================================================================================================================================================

The tests that are failing have a surprising number of stacked marks

needs_xelatex = pytest.mark.skipif(not check_for('xelatex'),
                                   reason='xelatex + pgf is required')

# test compiling a figure to pdf with xelatex
@needs_xelatex
@pytest.mark.style('default')
@pytest.mark.backend('pgf')
def test_xelatex():
    rc_xelatex = {'font.family': 'serif',
                  'pgf.rcfonts': False}
    mpl.rcParams.update(rc_xelatex)
    create_figure()
    compare_figure('pgf_xelatex.pdf', tol=0)

plus an auto-use fixture (which is where the exception is actually being raised) coming from https://github.com/matplotlib/matplotlib/blob/master/lib/matplotlib/testing/conftest.py#L20

@pytest.fixture(autouse=True)
def mpl_test_settings(request):
    from matplotlib.testing.decorators import _do_cleanup

    # mpl code
    try:
        yield
    finally:
        # mpl code

and by write-to-file-debuggig I know that the yield is not raising and the mpl code in the finally runs through with outraising.

@nicoddemus
Copy link
Member

Thanks @tacaswell for reaching out.

so pytest seems to be reporting each test twice but finds them just once:

FWIW this is the normal behavior if the test call is passing, but the teardown step is failing. I guess that's what we are seeing there.

@nicoddemus
Copy link
Member

plus an auto-use fixture (which is where the exception is actually being raised) coming from

One shot would be to try to gather all code involved in one of the tests demonstrating the issue into a test function and call it directly outside pytest. This might help narrow down the issue.

@tacaswell
Copy link
Author

Should I try to mock up the effects of the fixture machinery, or just the code written top-to-bottom in a 'natural' style?

@nicoddemus
Copy link
Member

I would try top-to-bottom first, and if that fails at least move the auto-use portion to an iterator in case the yield keyword plays a part on it.

That last bit gave me another idea: change the autouse fixture in the suite to use addfinalizer instead of yield to see if it makes a difference.

@tacaswell
Copy link
Author

Definitely a cpython bug:

def import_in_finally_fail():
    try:
        print('yo')
    finally:
        import asyncio.queues as aq

It seems to be import xx.yy as z that triggers the bug

Thanks for putting up with my noise!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants