Skip to content

test_asyncio test_start_tls_server_1 fails in AMD64 FreeBSD CURRENT buildbots #79212

Closed
Closed
test_asyncio test_start_tls_server_1 fails in AMD64 FreeBSD CURRENT buildbots#79212
Labels
3.7 (EOL)end of life3.8 (EOL)end of lifetestsTests in the Lib/test dirtopic-asynciotype-bugAn unexpected behavior, bug, or error

Description

@pablogsal
pablogsal
opened on Oct 20, 2018
BPO 35031
Nosy @terryjreedy, @vstinner, @tiran, @ned-deily, @asvetlov, @1st1, @pablogsal, @miss-islington, @openandclose
PRs
  • bpo-35031: Fix test_start_tls_server_1 on FreeBSD buildbots #10011
  • [3.7] bpo-35031: Fix test_start_tls_server_1 on FreeBSD buildbots (GH-10011) #10496
  • bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() #14148
  • [3.8] bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148) #14150
  • [3.7] bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148) #14151
  • bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS #14188
  • [3.8] bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188) #14191
  • [3.7] bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188) #14192
    		•

    Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
closed_at = <Date 2019-10-14.21:07:17.113>
created_at = <Date 2018-10-20.14:06:47.648>
labels = ['3.7', '3.8', 'type-bug', 'tests', 'expert-asyncio']
title = 'test_asyncio test_start_tls_server_1 fails in AMD64 FreeBSD CURRENT buildbots'
updated_at = <Date 2019-10-14.21:07:17.112>
user = 'https://github.com/pablogsal'

    bugs.python.org fields:

    activity = <Date 2019-10-14.21:07:17.112>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2019-10-14.21:07:17.113>
closer = 'vstinner'
components = ['Tests', 'asyncio']
creation = <Date 2018-10-20.14:06:47.648>
creator = 'pablogsal'
dependencies = []
files = []
hgrepos = []
issue_num = 35031
keywords = ['patch']
message_count = 24.0
messages = ['328138', '328143', '328145', '328148', '328157', '328163', '328833', '328835', '328837', '328839', '328871', '329785', '332756', '332764', '332803', '337234', '345831', '345832', '345837', '345839', '345961', '345967', '345973', '354654']
nosy_count = 9.0
nosy_names = ['terry.reedy', 'vstinner', 'christian.heimes', 'ned.deily', 'asvetlov', 'yselivanov', 'pablogsal', 'miss-islington', 'op368']
pr_nums = ['10011', '10496', '14148', '14150', '14151', '14188', '14191', '14192']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue35031'
versions = ['Python 3.6', 'Python 3.7', 'Python 3.8']

    Activity

    1. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

      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

    2. pablogsal
      added
      3.7 (EOL)end of life
      3.8 (EOL)end of life
      testsTests in the Lib/test dir
      topic-asyncio
      type-bugAn unexpected behavior, bug, or error
      on Oct 20, 2018
    3. pablogsal
      changed the title [-]test_asyncio test_start_tls_server_1 fails in[/-] [+]test_asyncio test_start_tls_server_1 fails in AMD64 FreeBSD CURRENT buildbots[/+] on Oct 20, 2018

    4. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

      Bisecting points to commit dbf1022 as the dirst bad commit:

      dbf1022 is the first bad commit
      commit dbf1022
      Author: Yury Selivanov <[email protected]>
      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

    5. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

      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.

    6. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

      Building and testing the parent of dbf1022 always succeeds.

    7. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

      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.

    8. pablogsal commented on Oct 20, 2018

      @pablogsal
      pablogsal
      on Oct 20, 2018
      MemberAuthor

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

    9. vstinner commented on Oct 29, 2018

      @vstinner
      vstinner
      on Oct 29, 2018
      Member

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

    10. pablogsal commented on Oct 29, 2018

      @pablogsal
      pablogsal
      on Oct 29, 2018
      MemberAuthor

      Someone needs to review PR10011

    11. vstinner commented on Oct 29, 2018

      @vstinner
      vstinner
      on Oct 29, 2018
      Member

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

    12. 2 remaining items

    13. miss-islington commented on Nov 13, 2018

      @miss-islington
      miss-islington
      on Nov 13, 2018
      Contributor

      New changeset 3f9fe53 by Miss Islington (bot) in branch '3.7':
      bpo-35031: Fix test_start_tls_server_1 on FreeBSD buildbots (GH-10011)
      3f9fe53

    14. terryjreedy commented on Dec 30, 2018

      @terryjreedy
      terryjreedy
      on Dec 30, 2018
      Member

      should this be closed?

    15. pablogsal commented on Dec 30, 2018

      @pablogsal
      pablogsal
      on Dec 30, 2018
      MemberAuthor

      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.

    16. ned-deily commented on Dec 31, 2018

      @ned-deily
      ned-deily
      on Dec 31, 2018
      Member

      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.

    17. openandclose commented on Mar 5, 2019

      @openandclose
      openandclosemannequin
      on Mar 5, 2019
      Mannequin

      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.

    18. vstinner commented on Jun 17, 2019

      @vstinner
      vstinner
      on Jun 17, 2019
      Member

      Commit f6a47f3 introduced a workaround on Windows and FreeBSD. It was removed by commit f0749da 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.

    19. vstinner commented on Jun 17, 2019

      @vstinner
      vstinner
      on Jun 17, 2019
      Member

      New changeset c034b78 by Victor Stinner in branch 'master':
      bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
      c034b78

    20. miss-islington commented on Jun 17, 2019

      @miss-islington
      miss-islington
      on Jun 17, 2019
      Contributor

      New changeset a5ddbfb by Miss Islington (bot) in branch '3.8':
      bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
      a5ddbfb

    21. miss-islington commented on Jun 17, 2019

      @miss-islington
      miss-islington
      on Jun 17, 2019
      Contributor

      New changeset 0040903 by Miss Islington (bot) in branch '3.7':
      bpo-35031, test_asycio: disable TLS 1.3 in test_start_tls_server_1() (GH-14148)
      0040903

    22. ned-deily commented on Jun 18, 2019

      @ned-deily
      ned-deily
      on Jun 18, 2019
      Member

      New changeset a514f78 by Ned Deily in branch 'master':
      bpo-35031: also disable TLS 1.3 for test_start_tls_server_1 on macOS (GH-14188)
      a514f78

    23. miss-islington commented on Jun 18, 2019

      @miss-islington
      miss-islington
      on Jun 18, 2019
      Contributor

      New changeset f49c85d 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)
      f49c85d

    24. ned-deily commented on Jun 18, 2019

      @ned-deily
      ned-deily
      on Jun 18, 2019
      Member

      New changeset c101d1a 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)
      c101d1a

    25. vstinner commented on Oct 14, 2019

      @vstinner
      vstinner
      on Oct 14, 2019
      Member

      It seems like the issue has been fixed.

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

    26. vstinner
      closed this as completedon Oct 14, 2019
    27. ezio-melotti
      transferred this issue fromon Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

    Metadata

    Metadata

    Assignees

    No one assigned

      Labels

      3.7 (EOL)end of life3.8 (EOL)end of lifetestsTests in the Lib/test dirtopic-asynciotype-bugAn unexpected behavior, bug, or error

      Projects

      No projects

        Milestone

        No milestone

        Relationships

        None yet

        Development

        No branches or pull requests

        Issue actions