search

pytest-dev / pytest-timeout

MIT License
213 stars 64 forks source link

Timeout with xdist causes worker crash and reported as error in html #137

Open AZ-201 opened 2 years ago

AZ-201 commented 2 years ago

Hello! Is this worker crash fully fixed in 2.1.0? I am still having this problem using pytest-xdist==2.5.0 and pytest-timeout==2.1.0
env

plugins: html-3.1.1, parallel-0.1.1, metadata-1.11.0, timeout-2.1.0, forked-1.4.0, xdist-2.5.0, assume-2.4.3
timeout: 60.0s
timeout method: thread
timeout func_only: False

stacks

+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++

~~~~~~~~~~~~~~~~~~~~~ Stack of <unknown> (139896081934080) ~~~~~~~~~~~~~~~~~~~~~
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 285, in _perform_spawn
    reply.run()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 220, in run
    self._result = func(*args, **kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 967, in _thread_receiver
    msg = Message.from_io(io)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 432, in from_io
    header = io.read(9)  # type 1, channel 4, payload 4
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 400, in read
    data = self._read(numbytes - len(buf))

~~~~~~~~~~~~~~~~~~~~ Stack of MainThread (139896100013888) ~~~~~~~~~~~~~~~~~~~~~
  File "<string>", line 1, in <module>
  File "<string>", line 8, in <module>
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 1554, in serve
    WorkerGateway(io=io, id=id, _startcount=2).serve()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 1060, in serve
    self._execpool.integrate_as_primary_thread()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 267, in integrate_as_primary_thread
    self._perform_spawn(reply)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 285, in _perform_spawn
    reply.run()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 220, in run
    self._result = func(*args, **kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/execnet/gateway_base.py", line 1084, in executetask
    do_exec(co, loc)  # noqa
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/xdist/remote.py", line 291, in <module>
    config.hook.pytest_cmdline_main(config=config)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 87, in <lambda>
    firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/main.py", line 316, in pytest_cmdline_main
    return wrap_session(config, _main)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/main.py", line 269, in wrap_session
    session.exitstatus = doit(config, session) or 0
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/main.py", line 323, in _main
    config.hook.pytest_runtestloop(session=session)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 87, in <lambda>
    firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/xdist/remote.py", line 91, in pytest_runtestloop
    self.run_one_test(torun)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/xdist/remote.py", line 110, in run_one_test
    self.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 87, in <lambda>
    firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 109, in pytest_runtest_protocol
    runtestprotocol(item, nextitem=nextitem)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 126, in runtestprotocol
    reports.append(call_and_report(item, "call", log))
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 215, in call_and_report
    call = call_runtest_hook(item, when, **kwds)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 255, in call_runtest_hook
    lambda: ihook(item=item, **kwds), when=when, reraise=reraise
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 311, in from_call
    result: Optional[TResult] = func()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 255, in <lambda>
    lambda: ihook(item=item, **kwds), when=when, reraise=reraise
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 87, in <lambda>
    firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/runner.py", line 162, in pytest_runtest_call
    item.runtest()
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/python.py", line 1641, in runtest
    self.ihook.pytest_pyfunc_call(pyfuncitem=self)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/hooks.py", line 286, in __call__
    return self._hookexec(self, self.get_hookimpls(), kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 93, in _hookexec
    return self._inner_hookexec(hook, methods, kwargs)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/manager.py", line 87, in <lambda>
    firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/pluggy/callers.py", line 187, in _multicall
    res = hook_impl.function(*args)
  File "/home/name/test/var/.tox/py37/lib/python3.7/site-packages/_pytest/python.py", line 183, in pytest_pyfunc_call
    result = testfunction(**testargs)
  File "/home/name/test/e2e/cases/outer/test_machine.py", line 43, in test_zero
    time.sleep(60)

+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++

[gw11] node down: Not properly terminated
[gw11] [ 99%] FAILED e2e/cases/outer/test_machine.py::Testfile::test_zero[xxxxxxxxx] 

replacing crashed worker gw11
[gw12] linux Python 3.7.3 cwd: /home/name/test                                                           
[gw12] Python 3.7.3 (default, Jan 22 2021, 20:04:44)  -- [GCC 8.3.0]                                              
gw0 [858] / gw1 [858] / gw2 [858] / gw3 [858] / gw4 [858] / gw5 [858] / gw6 [858] / gw12 [858] / gw8 [858] / gw9 [858]
e2e/cases/outer/test_machine.py::Testfile::test_1kb[xxxxxxxx] 
[gw12] [100%] PASSED e2e/cases/outer/test_machine.py::Testfile::test_1kb[xxxxxxx]

Originally posted by @AZ-201 in https://github.com/pytest-dev/pytest-timeout/issues/88#issuecomment-1188540109

AZ-201 commented 2 years ago

Here is a simple reproduce test_suite 

import time
import pytest

class TestTimeOut(object):

    @pytest.mark.parametrize("arg", [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20])
    def test_timeout(self, arg):
        print(arg)
        time.sleep(6)
        assert True

env 

Python 3.7.3
Linux xxx 4.19.0-17-amd64 #1 SMP Debian 4.19.194-3 (2021-07-18) x86_64 GNU/Linux
tox version 3.24.5

requirements(not all necessary) 

attrs==21.2.0
certifi==2021.5.30
chardet==4.0.0
idna==2.10
iniconfig==1.1.1
Jinja2==3.0.1
MarkupSafe==2.0.1
packaging==20.9
pluggy==0.13.1
py==1.10.0
pycurl==7.43.0.6
pyparsing==2.4.7
pytest==6.2.4
pytest-html==3.1.1
pytest-metadata==1.11.0
requests==2.25.1
toml==0.10.2
urllib3==1.26.6
jsonpath==0.82
pytest-xdist==2.5.0
pytest-timeout==2.0.0
pytest-parallel
six==1.16.0
pytest-assume==2.4.3
PyMySQL==1.0.2
paramiko==2.7.2
pytest-rerunfailures==10.2

cmd: pytest -v test_timeout.py --timeout=5 --timeout-method=thread -n 10 --dist no --html=./report.html --self-contained-html

AZ-201 commented 2 years ago

The log printed in terminal shows that 

[gw29] node down: Not properly terminated

and result was failed, but in the html file generated by pytest-html==3.1.1, it was error.

<input checked="true" class="filter" data-test-result="failed" disabled="true" hidden="true" name="filter_checkbox" onChange="filterTable(this)" type="checkbox"/><span class="failed">0 failed</span>, <input checked="true" class="filter" data-test-result="error" hidden="true" name="filter_checkbox" onChange="filterTable(this)" type="checkbox"/><span class="error">21 errors</span>,
AZ-201 commented 2 years ago

Any update on this issue?

sikmir commented 1 year ago

+1 The same problem.

valsky4 commented 1 year ago