pytest-xdist icon indicating copy to clipboard operation
pytest-xdist copied to clipboard

Published 20 hours ago • verified publisher icon pytest-dev

Internal error when slave crashed during test

Open enkore opened this issue 8 years ago • 6 comments

This happens rarely when the slave receives a signal. Doesn't seem to have anything to do with a specific test, but just randomly. It's possible that this is an interaction with pytest-timeout, which causes a crash in pytest_runtest_protocol.

When this happens, the state of the session seems to become corrupted, as the master does not note a failed test and continues on, reporting no errors, and executing only a small subset of all tests.

A full log is available at: https://travis-ci.org/borgbackup/borg/jobs/260118022

platform linux -- Python 3.5.3, pytest-3.2.0, py-1.4.34, pluggy-0.4.0 -- /home/travis/build/borgbackup/borg/.tox/py35/bin/python3.5
plugins: xdist-1.18.2, timeout-1.2.0, faulthandler-1.3.1, cov-2.5.1, benchmark-3.1.1

.tox/py35/lib/python3.5/site-packages/borg/testsuite/archive.py::test_key_length_msgpacked_items
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/main.py", line 110, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/main.py", line 146, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 745, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 339, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 334, in <lambda>
INTERNALERROR>     _MultiCall(methods, kwargs, hook.spec_opts).execute()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 613, in execute
INTERNALERROR>     return _wrapped_call(hook_impl.function(*args), self.execute)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 254, in _wrapped_call
INTERNALERROR>     return call_outcome.get_result()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 279, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 265, in __init__
INTERNALERROR>     self.result = func()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 614, in execute
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "<remote exec>", line 61, in pytest_runtestloop
INTERNALERROR>   File "<remote exec>", line 77, in run_tests
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 745, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 339, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 334, in <lambda>
INTERNALERROR>     _MultiCall(methods, kwargs, hook.spec_opts).execute()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 613, in execute
INTERNALERROR>     return _wrapped_call(hook_impl.function(*args), self.execute)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 254, in _wrapped_call
INTERNALERROR>     return call_outcome.get_result()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 279, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 265, in __init__
INTERNALERROR>     self.result = func()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 613, in execute
INTERNALERROR>     return _wrapped_call(hook_impl.function(*args), self.execute)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 245, in _wrapped_call
INTERNALERROR>     next(wrap_controller)   # first yield
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/pytest_timeout.py", line 76, in pytest_runtest_protocol
INTERNALERROR>     timeout_setup(item)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/pytest_timeout.py", line 115, in timeout_setup
INTERNALERROR>     signal.signal(signal.SIGALRM, handler)
INTERNALERROR>   File "/opt/python/3.5.3/lib/python3.5/signal.py", line 47, in signal
INTERNALERROR>     handler = _signal.signal(_enum_to_int(signalnum), _enum_to_int(handler))
INTERNALERROR> ValueError: signal only works in main thread

INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/main.py", line 110, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/main.py", line 146, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 745, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 339, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 334, in <lambda>
INTERNALERROR>     _MultiCall(methods, kwargs, hook.spec_opts).execute()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 613, in execute
INTERNALERROR>     return _wrapped_call(hook_impl.function(*args), self.execute)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 250, in _wrapped_call
INTERNALERROR>     wrap_controller.send(call_outcome)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 279, in get_result
INTERNALERROR>     raise ex[1].with_traceback(ex[2])
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 265, in __init__
INTERNALERROR>     self.result = func()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/_pytest/vendored_packages/pluggy.py", line 614, in execute
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/xdist/dsession.py", line 539, in pytest_runtestloop
INTERNALERROR>     self.loop_once()
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/xdist/dsession.py", line 558, in loop_once
INTERNALERROR>     call(**kwargs)
INTERNALERROR>   File "/home/travis/build/borgbackup/borg/.tox/py35/lib/python3.5/site-packages/xdist/dsession.py", line 596, in slave_slavefinished
INTERNALERROR>     assert not crashitem, (crashitem, node)
INTERNALERROR> AssertionError: ('.tox/py35/lib/python3.5/site-packages/borg/testsuite/archive.py::ArchiveTimestampTestCase::test_with_microseconds', <SlaveController gw1>)
INTERNALERROR> assert not '.tox/py35/lib/python3.5/site-packages/borg/testsuite/archive.py::ArchiveTimestampTestCase::test_with_microseconds'

enkore avatar Aug 05 '17 13:08 enkore

this does sound like an integration issue with pytest-timeout, its unlikely i can investigate this myself timely soon

can anyone confirm if the timeout plugin is the source of the issue?

RonnyPfannschmidt avatar Aug 05 '17 15:08 RonnyPfannschmidt

The upper trace is a known pytest-timeout bug: https://bitbucket.org/pytest-dev/pytest-timeout/issues/8/internalerror-valueerror-signal-only-works

But I'd say xdist should be able to deal with exceptions raised in pytest_xxx hooks; or at least should abort the test session in this case — it shouldn't return 0 and report no failures.

—

I noticed that it actually does return 1 (error), but it doesn't report the failure (== 26 passed, 1 skipped in 22.34 seconds ==).

enkore avatar Aug 05 '17 15:08 enkore

thanks for verifying the details

RonnyPfannschmidt avatar Aug 05 '17 15:08 RonnyPfannschmidt

Hi,
I am running into similar issue, not sure what is causing. My Jenkins job is crashing with same log.

Need help on that.

thank you, Cauvery.

cauvery avatar Apr 10 '20 06:04 cauvery

I encounter this issue with the following list of plugins:

plugins: asyncio-0.14.0, forked-1.3.0, drop-dup-tests-0.3.0, mock-3.2.0, timeout-1.4.2, xdist-1.34.0

alexeiz avatar Aug 07 '20 21:08 alexeiz

As mentioned in #539, this also happens without other plugins apparently. Trying to reproduce https://github.com/pytest-dev/pytest/issues/13207, I get:

$ pytest -n 2 -k "not { skips }"
============================= test session starts ==============================
platform linux -- Python 3.13.1, pytest-8.3.4, pluggy-1.5.0
rootdir: /home/florian/tmp/13207
plugins: xdist-3.6.1
2 workers [1 item]      
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/_pytest/main.py", line 283, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>                          ~~~~^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/_pytest/main.py", line 337, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>     ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_hooks.py", line 513, in __call__
INTERNALERROR>     return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
INTERNALERROR>            ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_manager.py", line 120, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_callers.py", line 139, in _multicall
INTERNALERROR>     raise exception.with_traceback(exception.__traceback__)
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_callers.py", line 122, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ~~~~~~~~~~~~~~^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/_pytest/logging.py", line 803, in pytest_runtestloop
INTERNALERROR>     return (yield)  # Run all the tests.
INTERNALERROR>             ^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_callers.py", line 122, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ~~~~~~~~~~~~~~^^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/_pytest/terminal.py", line 673, in pytest_runtestloop
INTERNALERROR>     result = yield
INTERNALERROR>              ^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/pluggy/_callers.py", line 103, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/xdist/dsession.py", line 138, in pytest_runtestloop
INTERNALERROR>     self.loop_once()
INTERNALERROR>     ~~~~~~~~~~~~~~^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/xdist/dsession.py", line 163, in loop_once
INTERNALERROR>     call(**kwargs)
INTERNALERROR>     ~~~~^^^^^^^^^^
INTERNALERROR>   File "/home/florian/tmp/13207/.venv/lib/python3.13/site-packages/xdist/dsession.py", line 217, in worker_workerfinished
INTERNALERROR>     assert not crashitem, (crashitem, node)
INTERNALERROR> AssertionError: ('test_xdist.py::test_foo', <WorkerController gw1>)
INTERNALERROR> assert not 'test_xdist.py::test_foo'

============================ no tests ran in 0.18s =============================

The reporter of that issue seems to see a slightly different stacktrace (which I can't reproduce):

[...]
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/dsession.py", line 138, in pytest_runtestloop
INTERNALERROR>     self.loop_once()
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/dsession.py", line 163, in loop_once
INTERNALERROR>     call(**kwargs)
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/dsession.py", line 306, in worker_collectionfinish
INTERNALERROR>     self.sched.schedule()
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/scheduler/load.py", line 295, in schedule
INTERNALERROR>     self._send_tests(node, node_chunksize)
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/scheduler/load.py", line 307, in _send_tests
INTERNALERROR>     node.send_runtest_some(tests_per_node)
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/workermanage.py", line 355, in send_runtest_some
INTERNALERROR>     self.sendcommand("runtests", indices=indices)
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/xdist/workermanage.py", line 374, in sendcommand
INTERNALERROR>     self.channel.send((name, kwargs))
INTERNALERROR>   File "$PREFIX/lib/python3.12/site-packages/execnet/gateway_base.py", line 911, in send
INTERNALERROR>     raise OSError(f"cannot send to {self!r}")
INTERNALERROR> OSError: cannot send to <Channel id=3 closed>

The-Compiler avatar Feb 09 '25 12:02 The-Compiler