https://buildbot.python.org/all/#/builders/168/builds/91
https://buildbot.python.org/all/#/builders/172/builds/41
https://buildbot.python.org/all/#/builders/173/builds/51

CURRENT-amd64% ./python -m test test_asyncio -m test_start_tls_server_1
Run tests sequentially
0:00:00 load avg: 3.36 [1/1] test_asyncio

Stderr:
/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py:497: DeprecationWarning: The loop argument is deprecated and scheduled for removal in Python 3.10.
  await asyncio.wait_for(
/usr/home/pablo/cpython/Lib/asyncio/sslproto.py:321: ResourceWarning: unclosed transport <asyncio.sslproto._SSLProtocolTransport object at 0x802db68f0>
  warnings.warn(f"unclosed transport {self!r}", ResourceWarning,
Unhandled error in exception handler
context: {'message': 'Future exception was never retrieved', 'exception': ConnectionResetError(54, 'Connection reset by peer'), 'future': <Future finished exception=ConnectionResetError(54, 'Connection reset by peer')>}
Traceback (most recent call last):
  File "/usr/home/pablo/cpython/Lib/test/libregrtest/runtest.py", line 179, in runtest_inner
    test_runner()
  File "/usr/home/pablo/cpython/Lib/test/libregrtest/runtest.py", line 175, in test_runner
    support.run_unittest(tests)
  File "/usr/home/pablo/cpython/Lib/test/support/__init__.py", line 2001, in run_unittest
    _run_suite(suite)
  File "/usr/home/pablo/cpython/Lib/test/support/__init__.py", line 1920, in _run_suite
    raise TestFailed(err)
test.support.TestFailed: Traceback (most recent call last):
  File "/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py", line 504, in test_start_tls_server_1
    self.loop.run_until_complete(run_main())
  File "/usr/home/pablo/cpython/Lib/asyncio/base_events.py", line 582, in run_until_complete
    return future.result()
  File "/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py", line 497, in run_main
    await asyncio.wait_for(
  File "/usr/home/pablo/cpython/Lib/asyncio/tasks.py", line 457, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

Stderr:
/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py:497: DeprecationWarning: The loop argument is deprecated and scheduled for removal in Python 3.10.
  await asyncio.wait_for(
/usr/home/pablo/cpython/Lib/asyncio/sslproto.py:321: ResourceWarning: unclosed transport <asyncio.sslproto._SSLProtocolTransport object at 0x802db68f0>
  warnings.warn(f"unclosed transport {self!r}", ResourceWarning,


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/home/pablo/cpython/Lib/asyncio/base_events.py", line 1647, in call_exception_handler
    self._exception_handler(self, context)
  File "/usr/home/pablo/cpython/Lib/test/test_asyncio/functional.py", line 22, in loop_exception_handler
    self.loop.default_exception_handler(context)
AttributeError: 'NoneType' object has no attribute 'default_exception_handler'
/usr/home/pablo/cpython/Lib/test/support/__init__.py:1550: ResourceWarning: unclosed <socket.socket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 25746)>
  gc.collect()
test test_asyncio failed -- Traceback (most recent call last):
  File "/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py", line 504, in test_start_tls_server_1
    self.loop.run_until_complete(run_main())
  File "/usr/home/pablo/cpython/Lib/asyncio/base_events.py", line 582, in run_until_complete
    return future.result()
  File "/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py", line 497, in run_main
    await asyncio.wait_for(
  File "/usr/home/pablo/cpython/Lib/asyncio/tasks.py", line 457, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

Stderr:
/usr/home/pablo/cpython/Lib/test/test_asyncio/test_sslproto.py:497: DeprecationWarning: The loop argument is deprecated and scheduled for removal in Python 3.10.
  await asyncio.wait_for(
/usr/home/pablo/cpython/Lib/asyncio/sslproto.py:321: ResourceWarning: unclosed transport <asyncio.sslproto._SSLProtocolTransport object at 0x802db68f0>
  warnings.warn(f"unclosed transport {self!r}", ResourceWarning,

test_asyncio failed in 1 min 749 ms

== Tests result: FAILURE ==

1 test failed:
    test_asyncio

Total duration: 1 min 800 ms
Tests result: FAILURE

Bisecting points to commit dbf102271fcc316f353c7e0a283811b661d128f2 as the dirst bad commit:

dbf102271fcc316f353c7e0a283811b661d128f2 is the first bad commit
commit dbf102271fcc316f353c7e0a283811b661d128f2
Author: Yury Selivanov <yury@magic.io>
Date:   Mon May 28 14:31:28 2018 -0400

    bpo-33654: Support BufferedProtocol in set_protocol() and start_tls() (GH-7130)

    In this commit:

    * Support BufferedProtocol in set_protocol() and start_tls()
    * Fix proactor to cancel readers reliably
    * Update tests to be compatible with OpenSSL 1.1.1
    * Clarify BufferedProtocol docs
    * Bump TLS tests timeouts to 60 seconds; eliminate possible race from start_serving
    * Rewrite test_start_tls_server_1

I think something is going on with the buildbot itself or the test has some race condition because that commit has been built before multiple times with no error. I am investigating in the buildbot itself.

Building and testing the parent of dbf102271fcc316f353c7e0a283811b661d128f2 always succeeds.

It seems that the problem is that the ServerProto of test_start_tls_server_1 never receives a call to eof_received(). Weirdly enough it seems that if the HELLO_MSG is large enough (1024 * 1024), then the test always succeed. If we deactivate tls in the test, the test succeeds with any message lenght.

Re-adding client_context.options |= ssl.OP_NO_TLSv1_3 makes the test pass again.

Any progress on this issue? It's still failing:
https://buildbot.python.org/all/#/builders/168/builds/143

Someone needs to review PR10011

note: Roundup sent me comments as email notifications in the backward order, that's funny to see Pablo's answer before my question :-)

> note: Roundup sent me comments as email notifications in the backward order, that's funny to see Pablo's answer before my question :-)

Maybe I just answered faster than the speed of light ;)

New changeset f6a47f3e316cede2a07a1f74a509f6d80ab8fef0 by Pablo Galindo in branch 'master':
bpo-35031: Fix test_start_tls_server_1 on FreeBSD buildbots (GH-10011)
https://github.com/python/cpython/commit/f6a47f3e316cede2a07a1f74a509f6d80ab8fef0

New changeset 3f9fe53c98978955fea4e36456c784694e6458a8 by Miss Islington (bot) in branch '3.7':
bpo-35031: Fix test_start_tls_server_1 on FreeBSD buildbots (GH-10011)
https://github.com/python/cpython/commit/3f9fe53c98978955fea4e36456c784694e6458a8

should this be closed?

I think is missing a manual backport to 3.6, but now that we are in security fixes only I am not sure of what to do.

If the failure has regularly shown up on 3.6 FreeBSD buildbots in the past, I would accept a backport of the test change to 3.6.

Am I wrong with something?
But test_start_tls_server_1 in newly made cpython fails on my plain intel linux personal PC.

If I comment out the FreeBSD conditional (to apply ssl.OP_NO_TLSv1_3), 
the test passes.

If I change HELLO_MSG to 1*1024*1024 (msg328157),
the test passes.

I reported the details in https://bugs.python.org/issue35998#msg336986 and the following.

Commit f6a47f3e316cede2a07a1f74a509f6d80ab8fef0 introduced a workaround on Windows and FreeBSD. It was removed by commit f0749da9a535375f05a2015e8960e8ae54877349 in bpo-35998... but then Windows restarted to fail:
https://bugs.python.org/issue35998#msg345644

So I wrote PR 14148 to reintroduce the workaround until someone finds time to have a look.

Note: this issue is open since October 2018.

New changeset c034b7824f5a7c50f2946ab3931633200e31d903 by Victor Stinner in branch 'master':
bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
https://github.com/python/cpython/commit/c034b7824f5a7c50f2946ab3931633200e31d903

New changeset a5ddbfbf50715e3d4b90ad367ed6827c6cbcc52f by Miss Islington (bot) in branch '3.8':
bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
https://github.com/python/cpython/commit/a5ddbfbf50715e3d4b90ad367ed6827c6cbcc52f

New changeset 0040903bbae043225499babae23649d896ea2eec by Miss Islington (bot) in branch '3.7':
bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
https://github.com/python/cpython/commit/0040903bbae043225499babae23649d896ea2eec

New changeset a514f782b822bd7bca7c8d78be7bd53bc25c1908 by Ned Deily in branch 'master':
bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188)
https://github.com/python/cpython/commit/a514f782b822bd7bca7c8d78be7bd53bc25c1908

New changeset f49c85d0cb098ba75191a9e272d149ed6466dfb7 by Miss Islington (bot) in branch '3.8':
bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188)
https://github.com/python/cpython/commit/f49c85d0cb098ba75191a9e272d149ed6466dfb7

New changeset c101d1a88a8e0b0cec479307b4e0ae6866958a49 by Ned Deily (Miss Islington (bot)) in branch '3.7':
bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188) (GH-14192)
https://github.com/python/cpython/commit/c101d1a88a8e0b0cec479307b4e0ae6866958a49

It seems like the issue has been fixed.

See also bpo-35998 for a similar issue on other platforms.

stage: patch review -> resolved