Tests fail with Python 3.8.11 and 3.9.6

[frispete]

Hi,

I'm preparing a distribution package of pyp for openSUSE, but noticed, that it is failing with some strange error on Python 3.8.11 and 3.9.6:

[    8s] + py.test-3.9 -v
[    8s] ============================= test session starts ==============================
[    8s] platform linux -- Python 3.9.6, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- /usr/bin/python3.9
[    8s] cachedir: .pytest_cache
[    8s] rootdir: /home/abuild/rpmbuild/BUILD/pyp-0.3.3
[    8s] collecting ... collected 33 items
[    8s] 
[    8s] tests/test_find_names.py::test_basic PASSED                              [  3%]
[    8s] tests/test_find_names.py::test_builtins PASSED                           [  6%]
[    8s] tests/test_find_names.py::test_loops PASSED                              [  9%]
[    8s] tests/test_find_names.py::test_weird_assignments PASSED                  [ 12%]
[    8s] tests/test_find_names.py::test_more_control_flow PASSED                  [ 15%]
[    8s] tests/test_find_names.py::test_import PASSED                             [ 18%]
[    8s] tests/test_find_names.py::test_walrus PASSED                             [ 21%]
[    8s] tests/test_find_names.py::test_comprehensions PASSED                     [ 24%]
[    8s] tests/test_find_names.py::test_args PASSED                               [ 27%]
[    8s] tests/test_find_names.py::test_definitions PASSED                        [ 30%]
[    8s] tests/test_find_names.py::test_scope PASSED                              [ 33%]
[    8s] tests/test_find_names.py::test_scope_failures XFAIL (do not currentl...) [ 36%]
[    8s] tests/test_find_names.py::test_del XFAIL (do not currently support d...) [ 39%]
[    8s] tests/test_pyp.py::test_examples PASSED                                  [ 42%]
[    8s] tests/test_pyp.py::test_magic_variable_failures PASSED                   [ 45%]
[    8s] tests/test_pyp.py::test_user_error PASSED                                [ 48%]
[    8s] tests/test_pyp.py::test_tracebacks FAILED                                [ 51%]
[    8s] tests/test_pyp.py::test_explain PASSED                                   [ 54%]
[    8s] tests/test_pyp.py::test_disable_automatic_print PASSED                   [ 57%]
[    8s] tests/test_pyp.py::test_automatic_print_inside_statement PASSED          [ 60%]
[    8s] tests/test_pyp.py::test_pypprint_basic PASSED                            [ 63%]
[    8s] tests/test_pyp.py::test_get_valid_name PASSED                            [ 66%]
[    8s] tests/test_pyp.py::test_wildcard_import PASSED                           [ 69%]
[    8s] tests/test_pyp.py::test_config_imports PASSED                            [ 72%]
[    8s] tests/test_pyp.py::test_config_invalid PASSED                            [ 75%]
[    8s] tests/test_pyp.py::test_config_shebang PASSED                            [ 78%]
[    8s] tests/test_pyp.py::test_config_lazy_wildcard_import PASSED               [ 81%]
[    8s] tests/test_pyp.py::test_config_scope PASSED                              [ 84%]
[    8s] tests/test_pyp.py::test_config_shadow PASSED                             [ 87%]
[    8s] tests/test_pyp.py::test_config_recursive PASSED                          [ 90%]
[    8s] tests/test_pyp.py::test_config_conditional PASSED                        [ 93%]
[    8s] tests/test_pyp.py::test_config_conditional_current_shortcoming XFAIL     [ 96%]
[    8s] tests/test_pyp.py::test_config_end_to_end PASSED                         [100%]
[    8s] 
[    8s] =================================== FAILURES ===================================
[    8s] _______________________________ test_tracebacks ________________________________
[    8s] 
[    8s]     def test_tracebacks():
[    8s]         # If our sins against traceback implementation details come back to haunt us, and we can't
[    8s]         # reconstruct a traceback, check that we still output something reasonable
[    8s]         TBE = traceback.TracebackException
[    8s]         with patch("traceback.TracebackException") as mock_tb:
[    8s]             count = 0
[    8s]     
[    8s]             def effect(*args, **kwargs):
[    8s]                 nonlocal count
[    8s]                 if count == 0:
[    8s]                     assert args[0] == ZeroDivisionError
[    8s]                     count += 1
[    8s]                     raise Exception
[    8s]                 return TBE(*args, **kwargs)
[    8s]     
[    8s]             mock_tb.side_effect = effect
[    8s]             pattern = re.compile("Code raised.*ZeroDivisionError", re.DOTALL)
[    8s]             with pytest.raises(pyp.PypError, match=pattern) as e:
[    8s]                 run_pyp("pyp '1 / 0'")
[    8s]             # Make sure that the test works and we couldn't actually reconstruct a traceback
[    8s]             assert "Possible" not in e.value.args[0]
[    8s]     
[    8s]         # Check the entire output, end to end
[    8s]         pyp_error = run_cmd("pyp 'def f(): 1/0' 'f()'", check=False)
[    8s]         message = lambda x, y: (  # noqa
[    8s]             "error: Code raised the following exception, consider using --explain to investigate:\n\n"
[    8s]             "Possible reconstructed traceback (most recent call last):\n"
[    8s]             '  File "<pyp>", in <module>\n'
[    8s]             "    output = f()\n"
[    8s]             '  File "<pyp>", in f\n'
[    8s]             f"    {x}1 / 0{y}\n"
[    8s]             "ZeroDivisionError: division by zero\n"
[    8s]         )
[    8s] >       assert pyp_error == message("(", ")") or pyp_error == message("", "")
[    8s] E       assert ('error: Code ...ion by zero\n' == 'error: Code ...ion by zero\n'
[    8s] E           error: Code raised the following exception, consider using --explain to investigate:
[    8s] E           
[    8s] E           Possible reconstructed traceback (most recent call last):
[    8s] E         + Traceback (most recent call last):
[    8s] E             File "<pyp>", in <module>
[    8s] E               output = f()
[    8s] E             File "<pyp>", in f...
[    8s] E         
[    8s] E         ...Full output truncated (5 lines hidden), use '-vv' to show or 'error: Code ...ion by zero\n' == 'error: Code ...ion by zero\n'
[    8s] E           error: Code raised the following exception, consider using --explain to investigate:
[    8s] E           
[    8s] E           Possible reconstructed traceback (most recent call last):
[    8s] E         + Traceback (most recent call last):
[    8s] E             File "<pyp>", in <module>
[    8s] E               output = f()
[    8s] E             File "<pyp>", in f...
[    8s] E         
[    8s] E         ...Full output truncated (3 lines hidden), use '-vv' to show)
[    8s] 
[    8s] tests/test_pyp.py:209: AssertionError
[    8s] =========================== short test summary info ============================
[    8s] FAILED tests/test_pyp.py::test_tracebacks - assert ('error: Code ...ion by ze...
[    8s] =================== 1 failed, 29 passed, 3 xfailed in 0.32s ====================
[    8s] error: Bad exit status from /var/tmp/rpm-tmp.uU6mEp (%check)

To me, it looks, like the expected message from the traceback changed. I couldn't locate anything related to this in the non released commits. Sorry for not providing a PR this time.

Here's the package home: https://build.opensuse.org/package/live_build_log/home:frispete:python/python-pyp/openSUSE_Tumbleweed/x86_64

Excluding test_tracebacks succeeds, as being done in: https://build.opensuse.org/package/live_build_log/home:frispete:Tumbleweed/python-pyp/openSUSE_Tumbleweed/x86_64

[hauntsaninja]

Thanks for reporting, will look into this!

Okay, I think I've tracked this down.

First, some context. pyp works by generating some Python code and running exec. Unfortunately, this results in lousy errors if any occur, so pyp attempts to reconstruct a traceback into the generated code. The way pyp does this unfortunately relies on some CPython implementation details. pyp has fallbacks if CPython changes something, so things should still be okay for users, but test_tracebacks tests this behaviour thoroughly so that I find out if things do break.

1) A change in a CPython micro version (bpo-42482, 3.9 backport here: https://github.com/python/cpython/pull/23578, 3.8 backport here: https://github.com/python/cpython/pull/23579) 2) The change in CPython changes pyp's behaviour at latest release (0.3.3). However, it appears I had the foresight to reduce pyp's reliance on the relevant CPython implementation details in 7c9370a, so the CPython change does not have any affect on pyp's behaviour on master. This change is unreleased.

So I think the fix is to simply make a release :-) Could you confirm that latest master works for you?

There's a final complication to this, which you may or may not have encountered, which is pyp's tests sometimes run pyp in a subprocess. If you have pyp's last release installed globally and you incorrectly set up your dev env (e.g. don't install the local pyp or don't use tox), the subprocesses could end up running the wrong pyp and you get unexpected results.

[hauntsaninja]

I made a new release (0.3.4) that I think fixed this. Please re-open if you find this is still an issue. Thanks again for reporting!

[frispete]

Thanks for creating this nice tool @hauntsaninja.

Just a note, that might be of (certain) interest for you: the package has been accepted to the official distribution: https://build.opensuse.org/package/show/devel:languages:python/python-pyp https://build.opensuse.org/package/show/openSUSE:Factory:Staging:adi:13/python-pyp

The former link shows, that the build succeeds within a nice matrix of different python versions of official distributions. The latter is showing the preparation for the next TW release, where it is built for 3 different interpreters: 3.6, 3.8 and 3.9. That boils down to be available by the act of typing zypper in python38-pyp, when released.

Currently I'm in the course of reprogramming my brain stem to type pyp more often in my shell battles :wink:

[hauntsaninja]

Awesome, thank you! :-)