Skip to content

Tornado 4.5.3 hangs with openssl 1.1.1 and TLS 1.3 #2536

Closed
Closed
Tornado 4.5.3 hangs with openssl 1.1.1 and TLS 1.3#2536
Labels
iostream

Description

@bdrung
bdrung
opened on Nov 15, 2018

I want to package the Python 3 version of tornado 4.5.3 (the latest 4.x release) for Debian unstable, because salt does not work with tornado 5 yet. See https://github.com/saltstack/salt-jenkins/issues/995 for details.

I updated the test certificate and tweaked the source code to work with Python 3.7:

Sadly the a few test cases still fail on Debian unstable (they succeed on Ubuntu 18.04):

======================================================================
ERROR: test_inline_read_error (tornado.test.iostream_test.TestIOStreamSSL)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/test/iostream_test.py", line 556, in test_inline_read_error
    server.read_bytes(1, lambda data: None)
  File "/usr/lib/python3.7/unittest/case.py", line 203, in __exit__
    self._raiseFailure("{} not raised".format(exc_name))
  File "/usr/lib/python3.7/unittest/case.py", line 135, in _raiseFailure
    raise self.test_case.failureException(msg)
AssertionError: OSError not raised

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 558, in test_inline_read_error
    server.close()
  File "/tmp/building/package/tornado/iostream.py", line 444, in close
    self.close_fd()
  File "/tmp/building/package/tornado/iostream.py", line 1042, in close_fd
    self.socket.close()
  File "/usr/lib/python3.7/socket.py", line 420, in close
    self._real_close()
  File "/usr/lib/python3.7/ssl.py", line 1108, in _real_close
    super()._real_close()
  File "/usr/lib/python3.7/socket.py", line 414, in _real_close
    _ss.close(self)
OSError: [Errno 9] Bad file descriptor

======================================================================
ERROR: test_inline_read_error (tornado.test.iostream_test.TestIOStreamSSLContext)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/test/iostream_test.py", line 556, in test_inline_read_error
    server.read_bytes(1, lambda data: None)
  File "/usr/lib/python3.7/unittest/case.py", line 203, in __exit__
    self._raiseFailure("{} not raised".format(exc_name))
  File "/usr/lib/python3.7/unittest/case.py", line 135, in _raiseFailure
    raise self.test_case.failureException(msg)
AssertionError: OSError not raised

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 558, in test_inline_read_error
    server.close()
  File "/tmp/building/package/tornado/iostream.py", line 444, in close
    self.close_fd()
  File "/tmp/building/package/tornado/iostream.py", line 1042, in close_fd
    self.socket.close()
  File "/usr/lib/python3.7/socket.py", line 420, in close
    self._real_close()
  File "/usr/lib/python3.7/ssl.py", line 1108, in _real_close
    super()._real_close()
  File "/usr/lib/python3.7/socket.py", line 414, in _real_close
    _ss.close(self)
OSError: [Errno 9] Bad file descriptor

======================================================================
FAIL: test_read_until_close_after_close (tornado.test.iostream_test.TestIOStreamSSL)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 451, in test_read_until_close_after_close
    data = self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

======================================================================
FAIL: test_streaming_read_until_close_after_close (tornado.test.iostream_test.TestIOStreamSSL)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 481, in test_streaming_read_until_close_after_close
    data = self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

======================================================================
FAIL: test_write_zero_bytes (tornado.test.iostream_test.TestIOStreamSSL)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 220, in test_write_zero_bytes
    self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

======================================================================
FAIL: test_read_until_close_after_close (tornado.test.iostream_test.TestIOStreamSSLContext)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 451, in test_read_until_close_after_close
    data = self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

======================================================================
FAIL: test_streaming_read_until_close_after_close (tornado.test.iostream_test.TestIOStreamSSLContext)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 481, in test_streaming_read_until_close_after_close
    data = self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

======================================================================
FAIL: test_write_zero_bytes (tornado.test.iostream_test.TestIOStreamSSLContext)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/building/package/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/tmp/building/package/tornado/test/iostream_test.py", line 220, in test_write_zero_bytes
    self.wait()
  File "/tmp/building/package/tornado/testing.py", line 336, in wait
    self.__rethrow()
  File "/tmp/building/package/tornado/testing.py", line 272, in __rethrow
    raise_exc_info(failure)
  File "<string>", line 4, in raise_exc_info
  File "/tmp/building/package/tornado/testing.py", line 320, in timeout_func
    timeout)
AssertionError: Async operation timed out after 5 seconds

You can see the full build and test long here: https://salsa.debian.org/python-team/modules/python-tornado/-/jobs/77766 (you can ignore the test cases that fail with "Cannot assign requested address")

Activity

  1. bdarnell commented on Nov 21, 2018

    @bdarnell
    bdarnell
    on Nov 21, 2018
    Member

    Hmm, I wonder what changed. Debian unstable had a python3-tornado package at version 4.5.3 until March of this year. I assume it passed its tests then.

    The test failures are all in SSL tests, and it looks like openssl 1.1 is in use. #2533 reports that openssl 1.1 appears to change exception behavior that might explain this.

  2. bdarnell commented on Nov 21, 2018

    @bdarnell
    bdarnell
    on Nov 21, 2018
    Member

    It doesn't look like openssl 1.1 is at fault (at least not alone). I built python 3.6 with openssl 1.1.0e (using this docker script) and the tests of Tornado 4.5.3 didn't break. There's something else going on here.

  3. bdrung commented on Dec 11, 2018

    @bdrung
    bdrung
    on Dec 11, 2018
    Author

    Can you test with Python 3.7 again?

  4. bdarnell commented on Dec 12, 2018

    @bdarnell
    bdarnell
    on Dec 12, 2018
    Member

    Works for me with my macports-based installation of python 3.7 (well, it doesn't completely work, but it doesn't get those "timed out after 5 seconds" errors).

    [bdarnell@rowlf ~]$ python3 -m venv /tmp/test
[bdarnell@rowlf ~]$ . /tmp/test/bin/activate
(test) [bdarnell@rowlf ~]$ pip install tornado==4.5.3
Collecting tornado==4.5.3
  Downloading https://files.pythonhosted.org/packages/e3/7b/e29ab3d51c8df66922fea216e2bddfcb6430fb29620e5165b16a216e0d3c/tornado-4.5.3.tar.gz (484kB)
    100% |████████████████████████████████| 491kB 6.6MB/s 
Installing collected packages: tornado
  Running setup.py install for tornado ... done
Successfully installed tornado-4.5.3
You are using pip version 10.0.1, however version 18.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
(test) [bdarnell@rowlf ~]$ python --version
Python 3.7.0
(test) [bdarnell@rowlf ~]$ python -m tornado.test
Traceback (most recent call last):
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/__main__.py", line 14, in <module>
    main()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/runtests.py", line 178, in main
    tornado.testing.main(**kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 732, in main
    unittest.main(defaultTest="all", argv=argv, **kwargs)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/main.py", line 100, in __init__
    self.parseArgs(argv)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/main.py", line 147, in parseArgs
    self.createTests()
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/main.py", line 159, in createTests
    self.module)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 220, in loadTestsFromNames
    suites = [self.loadTestsFromName(name, module) for name in names]
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 220, in <listcomp>
    suites = [self.loadTestsFromName(name, module) for name in names]
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 205, in loadTestsFromName
    test = obj()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/runtests.py", line 63, in all
    return unittest.defaultTestLoader.loadTestsFromNames(TEST_MODULES)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 220, in loadTestsFromNames
    suites = [self.loadTestsFromName(name, module) for name in names]
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 220, in <listcomp>
    suites = [self.loadTestsFromName(name, module) for name in names]
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 154, in loadTestsFromName
    module = __import__(module_name)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/asyncio_test.py", line 49
    ensure_future = asyncio.async
                                ^
SyntaxError: invalid syntax
(test) [bdarnell@rowlf ~]$ rm /tmp/test/lib/python3.7/site-packages/tornado/test/asyncio_test.py 
(test) [bdarnell@rowlf ~]$ python -m tornado.test
............E......................................................EEEEEssssssssssssssssssssssssssssssssss.........................................................................................................E.............................................................................................................................................................................................................................................................................................................................................................................................ss........ssss...................................................................E................................s......................................................................................................................................................................s..........................ssssssssssssss.......s.............................................................s..................................................................................................................................................................s...................................s..........................................................................................................................s........................................................................................
======================================================================
ERROR: asyncio_test (unittest.loader._FailedTest)
----------------------------------------------------------------------
ImportError: Failed to import test module: asyncio_test
Traceback (most recent call last):
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/unittest/loader.py", line 154, in loadTestsFromName
    module = __import__(module_name)
ModuleNotFoundError: No module named 'tornado.test.asyncio_test'


======================================================================
ERROR: test_call_with_both (tornado.test.concurrent_test.RunOnExecutorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 230, in __next__
    return next(self.__wrapped)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 433, in test_call_with_both
    o = Object(io_loop=self.io_loop)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 427, in __init__
    self.__executor = futures.thread.ThreadPoolExecutor(1)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/concurrent/futures/__init__.py", line 52, in __getattr__
    raise AttributeError(f"module {__name__} has no attribute {name}")
AttributeError: module concurrent.futures has no attribute thread

======================================================================
ERROR: test_call_with_executor (tornado.test.concurrent_test.RunOnExecutorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 230, in __next__
    return next(self.__wrapped)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 418, in test_call_with_executor
    o = Object(io_loop=self.io_loop)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 412, in __init__
    self.__executor = futures.thread.ThreadPoolExecutor(1)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/concurrent/futures/__init__.py", line 52, in __getattr__
    raise AttributeError(f"module {__name__} has no attribute {name}")
AttributeError: module concurrent.futures has no attribute thread

======================================================================
ERROR: test_call_with_io_loop (tornado.test.concurrent_test.RunOnExecutorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 230, in __next__
    return next(self.__wrapped)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 403, in test_call_with_io_loop
    o = Object(io_loop=self.io_loop)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 397, in __init__
    self.executor = futures.thread.ThreadPoolExecutor(1)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/concurrent/futures/__init__.py", line 52, in __getattr__
    raise AttributeError(f"module {__name__} has no attribute {name}")
AttributeError: module concurrent.futures has no attribute thread

======================================================================
ERROR: test_call_with_no_args (tornado.test.concurrent_test.RunOnExecutorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 230, in __next__
    return next(self.__wrapped)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 388, in test_call_with_no_args
    o = Object(io_loop=self.io_loop)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 382, in __init__
    self.executor = futures.thread.ThreadPoolExecutor(1)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/concurrent/futures/__init__.py", line 52, in __getattr__
    raise AttributeError(f"module {__name__} has no attribute {name}")
AttributeError: module concurrent.futures has no attribute thread

======================================================================
ERROR: test_no_calling (tornado.test.concurrent_test.RunOnExecutorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 230, in __next__
    return next(self.__wrapped)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 373, in test_no_calling
    o = Object(io_loop=self.io_loop)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/concurrent_test.py", line 367, in __init__
    self.executor = futures.thread.ThreadPoolExecutor(1)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/concurrent/futures/__init__.py", line 52, in __getattr__
    raise AttributeError(f"module {__name__} has no attribute {name}")
AttributeError: module concurrent.futures has no attribute thread

======================================================================
ERROR: test_iterator_async_await (tornado.test.gen_test.WaitIteratorTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 1063, in run
    yielded = self.gen.throw(*exc_info)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 210, in throw
    return self.__wrapped.throw(tp, *rest)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/gen_test.py", line 1428, in test_iterator_async_await
    yield namespace['f']()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "<string>", line 6, in _wrap_awaitable
  File "<string>", line 6, in f
TypeError: 'async for' received an object from __aiter__ that does not implement __anext__: Future

======================================================================
ERROR: test_async_for (tornado.test.queues_test.QueueGetTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 136, in __call__
    result = self.orig_method(*args, **kwargs)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/testing.py", line 529, in post_coroutine
    timeout=timeout)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/ioloop.py", line 458, in run_sync
    return future_cell[0].result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 1063, in run
    yielded = self.gen.throw(*exc_info)
  File "/opt/local/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/types.py", line 210, in throw
    return self.__wrapped.throw(tp, *rest)
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/test/queues_test.py", line 174, in test_async_for
    results = yield namespace['f']()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/private/tmp/test/lib/python3.7/site-packages/tornado/gen.py", line 307, in wrapper
    yielded = next(result)
  File "<string>", line 6, in _wrap_awaitable
  File "<string>", line 4, in f
TypeError: 'async for' received an object from __aiter__ that does not implement __anext__: Future

----------------------------------------------------------------------
Ran 1395 tests in 12.874s

FAILED (errors=8, skipped=61)
Some tests were skipped because: curl client accepts invalid headers,
needs fix, no testable future imports, non-windows platform, pycares
module not present, pycurl module not present, twisted module not
present
[E 181211 21:10:48 testing:737] FAIL

  5. bdrung commented on Dec 13, 2018

    @bdrung
    bdrung
    on Dec 13, 2018
    Author

    The tests succeed on Debian 9 (stretch) and Ubuntu 18.04 (bionic), but they fail on Debian unstable, Ubuntu 18.10 (cosmic) and Ubuntu 19.04 (disco).

    Build logs

    Ubuntu 18.04 (bionic): https://launchpadlibrarian.net/401407619/buildlog_ubuntu-bionic-amd64.python-tornado4_4.5.3-2~wip20181213+tests~ubuntu18.04.1~ppa1_BUILDING.txt.gz
    Ubuntu 18.10 (cosmic): https://launchpadlibrarian.net/401407395/buildlog_ubuntu-cosmic-amd64.python-tornado4_4.5.3-2~wip20181213+tests~ubuntu18.10.1~ppa1_BUILDING.txt.gz
    Ubuntu 19.04 (disco): https://launchpadlibrarian.net/401407363/buildlog_ubuntu-disco-amd64.python-tornado4_4.5.3-2~wip20181213+tests~ubuntu19.04.1~ppa1_BUILDING.txt.gz

  6. bdarnell commented on Dec 15, 2018

    @bdarnell
    bdarnell
    on Dec 15, 2018
    Member

    OK, I can reproduce this now: it appears that the key is openssl version 1.1.1 (not 1.1.0e, which I had tried, or 1.1.0g in bionic). If I build Python 3.7 with openssl 1.1.1a, the Tornado 4.5.3 tests fail with the 5-second timeout errors. Those errors don't occur with Tornado 5.0.0.

    I don't think there were any changes specific to SSL in 5.0, although substantial parts of the relevant code in iostream.py was rewritten for performance. Openssl 1.1.1 claims to be a drop-in replacement for 1.1.0 and I don't see anything obviously relevant in the release notes (it's possible that the offending change was actually in one of the later 1.1.0 releases; I haven't tried 1.1.0h or 1.1.0i)

  7. bdarnell commented on Dec 15, 2018

    @bdarnell
    bdarnell
    on Dec 15, 2018
    Member

    Ah wait, there's this:

    https://github.com/openssl/openssl/blob/6e94b5aecd619afd25e3dc25902952b1b3194edf/CHANGES#L236

    Although that comment specifically refers to blocking IO and it looks like python has set this flag by default for a long time.

    Or there's openssl/openssl#7327, suggesting that when TLS 1.3 is used the pattern of messages is different in ways that could potentially confuse socket reading loops. And indeed, adding ctx.maximum_version = ssl.TLSVersion.TLSv1_2 wherever an SSLContext is created eliminates the timeouts.

    So I think that's the answer for now: disable TLS 1.3 when using Tornado 4.5 with openssl 1.1.1. Since this is apparently already fixed in 5.0+, I'm not going to personally investigate further on the old release branch (but I'd welcome a patch if there are folks out there who still can't upgrade to 5.x but also can't pin their openssl to a similar vintage).

  8. bdrung commented on Dec 17, 2018

    @bdrung
    bdrung
    on Dec 17, 2018
    Author

    It would be great to use TLS 1.3 with tornado 4, because TLS 1.3 would improve the security. Could you point me to the code part where to look for finding the relevant commit to cherry-pick it?

  9. bdrung
    added 2 commits that reference this issue on Dec 18, 2018

    Skip failing openssl 1.1.1 tests (for now)

    d76eb58

    Skip failing openssl 1.1.1 tests (for now)

    cfa930f

  10. bdrung commented on Dec 18, 2018

    @bdrung
    bdrung
    on Dec 18, 2018
    Author

    There is one salt state unittest (unit.utils.test_event.TestAsyncEventPublisher.test_event_subscription) that fails with exactly this failure.

  11. bdarnell commented on Dec 19, 2018

    @bdarnell
    bdarnell
    on Dec 19, 2018
    Member

    Could you point me to the code part where to look for finding the relevant commit to cherry-pick it?

    There were a lot of changes to iostream.py between 4.5 and 5.0. It could be an unexpected side effect of some of the new zero-copy fast paths introduced in #2169 or #2251. Or there were some SSL-related changes in #2167 and #2177.

  12. bdrung commented on Dec 20, 2018

    @bdrung
    bdrung
    on Dec 20, 2018
    Author

    I tested the two SSL-related changes in #2167 and #2177. They made no difference. Also the patch from #2169 didn't change anything. #2251 does not apply and is not trivially adaptable.

  13. bdarnell
    added
    iostream
    on Jan 1, 2019

  14. 18 remaining items

  15. bdrung
    added a commit that references this issue on Jun 22, 2020

    Skip failing openssl 1.1.1 tests (for now)

    653b2c7
  16. eugene2candy
    added a commit that references this issue on Apr 10, 2021

    PR (#1)

    6b03411
  17. bdrung
    added a commit that references this issue on Apr 26, 2021

    Skip failing openssl 1.1.1 tests (for now)

    89b8519
  18. jeyrce
    added a commit that references this issue on Aug 25, 2021

    test: Disable TLS 1.3 in one test

    98e5c8e

  19. bdarnell commented on Aug 28, 2022

    @bdarnell
    bdarnell
    on Aug 28, 2022
    Member

    Closing this as obsolete since it seems to only apply to Tornado 4.x.

  20. bdarnell
    closed this as completedon Aug 28, 2022
  21. gtrainavicius
    added a commit that references this issue on Feb 13, 2024

    Skip failing openssl 1.1.1 tests (for now)

    5beacc5
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

    iostream

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions