SystemError during AST parsing (recursion depth mismatch)

[timegrid]

Sorry in advance for this mess, it's just a weird bug and i could not further boil it down.

Description

In certain cases, the ast.parse() line in _pytest/_code/source.py:get_statementrange_ast() triggers the following SystemError (probably trying to parse itself):

INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/main.py", line 270, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>                          ^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/main.py", line 324, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_hooks.py", line 265, in __call__
INTERNALERROR>     return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_manager.py", line 80, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 60, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_result.py", line 60, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 39, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/main.py", line 349, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_hooks.py", line 265, in __call__
INTERNALERROR>     return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_manager.py", line 80, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 60, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_result.py", line 60, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 39, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/runner.py", line 112, in pytest_runtest_protocol
INTERNALERROR>     runtestprotocol(item, nextitem=nextitem)
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/runner.py", line 131, in runtestprotocol
INTERNALERROR>     reports.append(call_and_report(item, "call", log))
INTERNALERROR>                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/runner.py", line 222, in call_and_report
INTERNALERROR>     report: TestReport = hook.pytest_runtest_makereport(item=item, call=call)
INTERNALERROR>                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_hooks.py", line 265, in __call__
INTERNALERROR>     return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_manager.py", line 80, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 55, in _multicall
INTERNALERROR>     gen.send(outcome)
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/skipping.py", line 265, in pytest_runtest_makereport
INTERNALERROR>     rep = outcome.get_result()
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_result.py", line 60, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/pluggy/_callers.py", line 39, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/runner.py", line 366, in pytest_runtest_makereport
INTERNALERROR>     return TestReport.from_item_and_call(item, call)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/reports.py", line 349, in from_item_and_call
INTERNALERROR>     longrepr = item.repr_failure(excinfo)
INTERNALERROR>                ^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/python.py", line 1823, in repr_failure
INTERNALERROR>     return self._repr_failure_py(excinfo, style=style)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/nodes.py", line 484, in _repr_failure_py
INTERNALERROR>     return excinfo.getrepr(
INTERNALERROR>            ^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 669, in getrepr
INTERNALERROR>     return fmt.repr_excinfo(self)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 944, in repr_excinfo
INTERNALERROR>     reprtraceback = self.repr_traceback(excinfo_)
INTERNALERROR>                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 871, in repr_traceback
INTERNALERROR>     reprentry = self.repr_traceback_entry(entry, einfo)
INTERNALERROR>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 814, in repr_traceback_entry
INTERNALERROR>     source = self._getentrysource(entry)
INTERNALERROR>              ^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 722, in _getentrysource
INTERNALERROR>     source = entry.getsource(self.astcache)
INTERNALERROR>              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/code.py", line 263, in getsource
INTERNALERROR>     astnode, _, end = getstatementrange_ast(
INTERNALERROR>                       ^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/opt/venv/lib/python3.11/site-packages/_pytest/_code/source.py", line 185, in getstatementrange_ast
INTERNALERROR>     astnode = ast.parse(content, "source", "exec")
INTERNALERROR>               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/usr/lib/python3.11/ast.py", line 50, in parse
INTERNALERROR>     return compile(source, filename, mode, flags,
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR> SystemError: AST constructor recursion depth mismatch (before=117, after=178)

Setup

• environment is a docker container with the current debian:bookworm image
• platform linux -- Python 3.11.1, pytest-7.2.1, pluggy-1.0.0 -- /opt/venv/bin/python
• the tests are some webdriver tests starting a webtest.http.StoppableWsgi (WebTest==3.0.0, waitress==2.1.2) server and a selenium.webdriver.Remote (selenium==4.8.0) client
• the app is pyramid (pyramid==2.0.1) + sqlalchemy (SQLAlchemy==1.4.46) with sqlite database
• this happend during a 2py3 migration, the tests still use the old nose way with setUp/tearDown (all *.pyc cleaned)

Details

The error occurs during a

• webtest.http.StoppableWsgi.connect(), which calls
• waitress.wasyncore.dispatcher.bind(), which calls
• socket.bind(), which throws a
• <ExceptionInfo OSError(98, 'Address already in use') tblen=8>, which is processed in the
• ast.parse() line in [...]/site-packages/_pytest/_code/source.py:get_statementrange_ast(),
• which parses
  • my test files
  • the imported [...]/site-packages/webtest/http.py
  • the imported [...]/site-packages/waitress/server.py
• afterwards ast.parse(content, ...) is called not by get_statementrange_ast() itself (probably recursion? not sure how to introspect in the ast module itself), in the end parsing the traceback of pytest. printing the first parameter content of ast.parse(content, ...) results in (each line one call):
  • sqlalchemy related lines which also occur, when the error is not triggered:
    • fairy._reset(pool, transaction_was_reset)
    • pool._dialect.do_rollback(self)
    • dbapi_connection.rollback()
    • fairy._reset(pool, transaction_was_reset)
    • pool._dialect.do_rollback(self)
    • dbapi_connection.rollback()
    • self._dialect.do_terminate(connection)
    • self.do_close(dbapi_connection)
    • dbapi_connection.close()
  • and only if the error is triggered the lines of the traceback above
    • doit(config, session)
    • config.hook.pytest_runtestloop(session=session)
    • self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
    • self._inner_hookexec(hook_name, methods, kwargs, firstresult)
    • outcome.get_result()
    • raise ex[1].with_traceback(ex[2])
    • hook_impl.function(*args)
    • item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
    • self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
    • self._inner_hookexec(hook_name, methods, kwargs, firstresult)
    • outcome.get_result()
    • raise ex[1].with_traceback(ex[2])
    • hook_impl.function(*args)
    • runtestprotocol(item, nextitem=nextitem)
    • call_and_report(item, "call", log)
    • hook.pytest_runtest_makereport(item=item, call=call)
    • self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
    • self._inner_hookexec(hook_name, methods, kwargs, firstresult)
    • gen.send(outcome)
    • outcome.get_result()
    • raise ex[1].with_traceback(ex[2])
    • hook_impl.function(*args)
    • TestReport.from_item_and_call(item, call)
    • item.repr_failure(excinfo)
    • self._repr_failure_py(excinfo, style=style)
    • fmt.repr_excinfo(self)
    • self.repr_traceback(excinfo_)
    • self.repr_traceback_entry(entry, einfo)
    • self._getentrysource(entry)
    • entry.getsource(self.astcache)
    • ast.parse(content, "source", "exec")

During the return of ast.parse() the SystemError then occurs.

The error was gone after

• adjusting the tests to use the pytest syntax
• ensuring a free socket before the start of the webtest server
• configuring the sqlalchemy.engine with connect_args={"check_same_thread": False})

I recreated the version, in which the error occurs, and the check_same_thread=False seems enough to not trigger the error. The socket Exception is handled as intended then and the test just fails normally. I haven't manage to reproduce the error from scratch though, so i can't provide a minimal example. I also tried to reproduce in on my host (Archlinux, Python 3.10.9), but it did not work, so i thought it could be a docker bug and tried to reproduce it running with valgrind, as it first felt like some memory issue, but it was not reproducible as well then.

I guess, that ast.parse() is not intended to parse itself? Not sure though, why fixing the sqlalchemy errors also fixes the weird handling of the socket exception. And the sqlalchemy errors are handled fine, when the socket is free and the exception is not thrown.

Hope this helps to find some underlying issue.

[timegrid]

The error output of a run, in which the error is not triggered (socket is free):

========================================================================= 2 passed, 3 warnings in 15.66s ==========================================================================
Exception during reset or similar
Traceback (most recent call last):
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 763, in _finalize_fairy
    fairy._reset(pool, transaction_was_reset)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1038, in _reset
    pool._dialect.do_rollback(self)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 683, in do_rollback
    dbapi_connection.rollback()
sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140183957657280 and this is thread id 140184140681280.
Exception closing connection <sqlite3.Connection object at 0x7f7f2711d030>
Traceback (most recent call last):
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 763, in _finalize_fairy
    fairy._reset(pool, transaction_was_reset)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1038, in _reset
    pool._dialect.do_rollback(self)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 683, in do_rollback
    dbapi_connection.rollback()
sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140183957657280 and this is thread id 140184140681280.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 260, in _close_connection
    self._dialect.do_terminate(connection)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 689, in do_terminate
    self.do_close(dbapi_connection)
  File "/opt/venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 692, in do_close
    dbapi_connection.close()
sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140183957657280 and this is thread id 140184140681280.

[Zac-HD]

I don't think there's anything we can do here without the ability to reproduce this. Can you share a minimal reproducing example?

[timegrid]

Not sure, which ingredient made a difference (could be e.g. docker or python version), but the bug isn't reproducible anymore now, so I'll close this ticket. Thanks anyway and sorry for the noise

[Dreamsorcerer]

Seeing this in a PR. Don't have a minimal reproducer, but if you want to try and take a look at our PR, it seems to reproduce reliably in CI, only on Python 3.11:
aio-libs/aiohttp#7308
https://github.com/aio-libs/aiohttp/actions/runs/5170772709/jobs/9314099327?pr=7308

[Dreamsorcerer]

The odd thing is that the first test seems to pass, while the second causes this error. The only difference between the tests is await asyncio.sleep vs time.sleep.

[romuald]

I'm having the same issue here with different library (but, currently unable to make a minimal reproducible version)

• asynchrounous tests
• (no SQLALchemy )
• lxml

When lxml raises a lxml.etree.SyntaxError inside our parser, the bug will trigger

The error only occurs when more than one test fails with the same error, a single test will properly fail with the expected SyntaxError (of bad XML)

edit raising a RuntimeError in our parser every time will lead to the same error. So this has nothing to do with lxml

The error occurs inside an asynchronous fixture, still cannot make a minimal example

edit 2 switching to python 3.12 (3.12.0b4) somehow fixes the issue

[bluetech]

Seems like python/cpython#113035 should fix it which means the next Python point releases - 3.11.8, 3.12.2, 3.13. If this still happens with these releases, we can reopen.