This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

Author vstinner
Recipients vstinner
Date 2022-03-24.07:42:07
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1648107728.15.0.548883065453.issue47106@roundup.psfhosted.org>
In-reply-to
Content
test_shutdown_cleanly() of test_asyncio failed on x86 Gentoo Non-Debug with X 3.x with a timeout of 10 seconds:
https://buildbot.python.org/all/#/builders/58/builds/1958

asyncio uses a default timeout of 60 seconds for a TLS handshake, but the test takes makes 6x shorter: use a timeout of 10 seconds, I'm not sure why.

To support slow buildbots, I would suggest to use *longer* timeout than the default, not *shorter* timeouts.

test_ssl uses various values for the TLS timeout:

* 1.0 second
* 10.0 seconds
* 40.0 seconds
* 60.0 seconds

Would it be possible to make these values more consistent?

You may want to use on of test.support timeout which has a value depending on regrtest --timeout parameter: on slow buildbots, these values are larger.

* LOOPBACK_TIMEOUT
* SHORT_TIMEOUT
* LONG_TIMEOUT
* INTERNET_TIMEOUT
* Documentation: https://docs.python.org/dev/library/test.html#test.support.LOOPBACK_TIMEOUT

I would recommend using SHORT_TIMEOUT.

x86 Gentoo Non-Debug with X 3.x uses "--timeout=2100" option:

"0:00:00 load avg: 2.89 Run tests in parallel using 2 child processes (timeout: 35 min, worker timeout: 40 min)"


Logs:

0:35:34 load avg: 3.13 Re-running test_asyncio in verbose mode (matching: test_shutdown_cleanly)
test_shutdown_cleanly (test.test_asyncio.test_ssl.TestSSL) ... Warning -- Uncaught thread exception: AssertionError
Exception in thread test-server:
Traceback (most recent call last):
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1706, in _run
    self._handle_client(conn)
    ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1717, in _handle_client
    self._prog(TestSocketWrapper(sock))
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1183, in server
    sock.unwrap()
    ^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/ssl.py", line 1321, in unwrap
    s = self._sslobj.shutdown()
        ^^^^^^^^^^^^^^^^^^^^^^^
TimeoutError: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/threading.py", line 1031, in _bootstrap_inner
    self.run()
    ^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1675, in run
    self._run()
    ^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1714, in _run
    self._test._abort_socket_test(ex)
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 163, in _abort_socket_test
    self.fail(ex)
    ^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/unittest/case.py", line 671, in fail
    raise self.failureException(msg)
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: The read operation timed out
ERROR

Stderr:
/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/threading.py:1033: ResourceWarning: unclosed <ssl.SSLSocket fd=9, family=2, type=1, proto=0, laddr=('127.0.0.1', 51261), raddr=('127.0.0.1', 50574)>
  self._invoke_excepthook(self)
ResourceWarning: Enable tracemalloc to get the object allocation traceback
/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/asyncio/selector_events.py:834: ResourceWarning: unclosed transport <_SelectorSocketTransport fd=27>
  _warn(f"unclosed transport {self!r}", ResourceWarning, source=self)
ResourceWarning: Enable tracemalloc to get the object allocation traceback

======================================================================
ERROR: test_shutdown_cleanly (test.test_asyncio.test_ssl.TestSSL)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/contextlib.py", line 155, in __exit__
    self.gen.throw(typ, value, traceback)
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 155, in _silence_eof_received_warning
    yield
    ^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1228, in test_shutdown_cleanly
    run(client)
    ^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1222, in run
    self.loop.run_until_complete(
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/asyncio/base_events.py", line 650, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1213, in _gather
    return await asyncio.gather(*tasks)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/test/test_asyncio/test_ssl.py", line 1191, in client
    reader, writer = await asyncio.open_connection(
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/asyncio/streams.py", line 47, in open_connection
    transport, _ = await loop.create_connection(
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/asyncio/base_events.py", line 1098, in create_connection
    transport, protocol = await self._create_connection_transport(
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/asyncio/base_events.py", line 1131, in _create_connection_transport
    await waiter
    ^^^^^^^^^^^^
ConnectionAbortedError: SSL handshake is taking longer than 10.0 seconds: aborting the connection

Stderr:
/buildbot/buildarea/cpython/3.x.ware-gentoo-x86.nondebug/build/Lib/threading.py:1033: ResourceWarning: unclosed <ssl.SSLSocket fd=9, family=2, type=1, proto=0, laddr=('127.0.0.1', 51261), raddr=('127.0.0.1', 50574)>
  self._invoke_excepthook(self)
ResourceWarning: Enable tracemalloc to get the object allocation traceback

----------------------------------------------------------------------
Ran 1 test in 16.068s

FAILED (errors=1)
test test_asyncio failed
1 test failed again:
    test_asyncio
History
Date User Action Args
2022-03-24 07:42:08vstinnersetrecipients: + vstinner
2022-03-24 07:42:08vstinnersetmessageid: <1648107728.15.0.548883065453.issue47106@roundup.psfhosted.org>
2022-03-24 07:42:08vstinnerlinkissue47106 messages
2022-03-24 07:42:07vstinnercreate